[Bug 1480235] Re: Ubuntu15.10: guests seems to hang while installing packages
vaishnavi
vaishnavi at linux.vnet.ibm.com
Wed Sep 9 08:19:32 UTC 2015
** Package changed: ubuntu => debian-installer (Ubuntu)
--
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to debian-installer in Ubuntu.
https://bugs.launchpad.net/bugs/1480235
Title:
Ubuntu15.10: guests seems to hang while installing packages
Status in debian-installer package in Ubuntu:
New
Bug description:
Problem Description
=========================
After Installation of Ubuntu guests,lucky05 and lucky06 seems to hang while configuring packages.
I am able to ping the machines but not able to telnet.
Machine is Ubuntu 15.10 guest,with 45 data disks from SVC storage.
While installation time for other guests also saw this error
I copied the dmesg to /tmp/before,before attempting 2nd time.Both times its happened.
Logs:
Ist attempt dmesg :
Jul 15 10:21:42 lucky06 kernel: [ 2.340074] systemd-journald[321]: Received request to flush runtime journal from PID 1
Jul 15 10:21:42 lucky06 kernel: [ 2.499087] audit: type=1400 audit(1436970063.795:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=453 comm="apparmor_parser"
Jul 15 10:21:42 lucky06 kernel: [ 2.499101] audit: type=1400 audit(1436970063.795:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=453 comm="apparmor_parser"
Jul 15 10:21:42 lucky06 kernel: [ 2.499110] audit: type=1400 audit(1436970063.795:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=453 comm="apparmor_parser"
Jul 15 10:21:42 lucky06 kernel: [ 2.499118] audit: type=1400 audit(1436970063.795:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=453 comm="apparmor_parser"
Jul 15 10:21:42 lucky06 kernel: [ 2.502113] audit: type=1400 audit(1436970063.799:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=453 comm="apparmor_parser"
Jul 15 10:21:42 lucky06 kernel: [ 2.540089] rtc-generic rtc-generic: rtc core: registered rtc-generic as rtc0
Jul 15 10:21:42 lucky06 kernel: [ 2.694235] Adding 2272192k swap on /dev/sdae3. Priority:-1 extents:1 across:2272192k FS
Jul 15 10:21:42 lucky06 kernel: [ 23.665333] INFO: rcu_sched self-detected stall on CPU { 7} (t=5251 jiffies g=-5 c=-6 q=28329)
Jul 15 10:21:42 lucky06 kernel: [ 23.665344] Task dump for CPU 7:
Jul 15 10:21:42 lucky06 kernel: [ 23.665346] systemd-udevd R running task 0 489 333 0x00040004
Jul 15 10:21:42 lucky06 kernel: [ 23.665350] Call Trace:
Jul 15 10:21:42 lucky06 kernel: [ 23.665358] [c0000000fe08f5b0] [c0000000000ee1c0] sched_show_task+0xe0/0x180 (unreliable)
Jul 15 10:21:42 lucky06 kernel: [ 23.665362] [c0000000fe08f620] [c00000000012cd88] rcu_dump_cpu_stacks+0xe8/0x160
Jul 15 10:21:42 lucky06 kernel: [ 23.665364] [c0000000fe08f670] [c000000000131914] rcu_check_callbacks+0x684/0x980
Jul 15 10:21:42 lucky06 kernel: [ 23.665366] [c0000000fe08f7b0] [c0000000001392f4] update_process_times+0x54/0xa0
Jul 15 10:21:42 lucky06 kernel: [ 23.665369] [c0000000fe08f7e0] [c00000000014fc88] tick_sched_handle.isra.15+0x48/0xe0
Jul 15 10:21:42 lucky06 kernel: [ 23.665371] [c0000000fe08f820] [c00000000014fd84] tick_sched_timer+0x64/0xd0
Jul 15 10:21:42 lucky06 kernel: [ 23.665372] [c0000000fe08f860] [c00000000013a718] __run_hrtimer+0xb8/0x2d0
Jul 15 10:21:42 lucky06 kernel: [ 23.665374] [c0000000fe08f8b0] [c00000000013acc8] hrtimer_interrupt+0x148/0x300
Jul 15 10:21:42 lucky06 kernel: [ 23.665377] [c0000000fe08f9a0] [c00000000001f27c] __timer_interrupt+0x8c/0x230
Jul 15 10:21:42 lucky06 kernel: [ 23.665378] [c0000000fe08f9f0] [c00000000001f930] timer_interrupt+0xa0/0xe0
Jul 15 10:21:42 lucky06 kernel: [ 23.665380] [c0000000fe08fa20] [c000000000002758] decrementer_common+0x158/0x180
Jul 15 10:21:42 lucky06 kernel: [ 23.665382] --- interrupt: 901 at ktime_get_ts64+0xf0/0x150
Jul 15 10:21:42 lucky06 kernel: [ 23.665382] LR = ktime_get_ts64+0x7c/0x150
Jul 15 10:21:42 lucky06 kernel: [ 23.665386] [c0000000fe08fd10] [c0000000fe08fd50] 0xc0000000fe08fd50 (unreliable)
Jul 15 10:21:42 lucky06 kernel: [ 23.665389] [c0000000fe08fd50] [c00000000031a66c] SyS_epoll_wait+0x19c/0x510
Jul 15 10:21:42 lucky06 kernel: [ 23.665391] [c0000000fe08fe30] [c000000000009258] system_call+0x38/0xd0
Jul 15 10:21:42 lucky06 kernel: [ 28.033332] NMI watchdog: BUG: soft lockup - CPU#7 stuck for 22s! [systemd-udevd:489]
Jul 15 10:21:42 lucky06 kernel: [ 28.033970] Modules linked in: rtc_generic autofs4 virtio_scsi
Jul 15 10:21:42 lucky06 kernel: [ 28.033976] CPU: 7 PID: 489 Comm: systemd-udevd Not tainted 4.0.0-4-generic #6-Ubuntu
Jul 15 10:21:42 lucky06 kernel: [ 28.033978] task: c0000001f8c3b900 ti: c0000000fe08c000 task.ti: c0000000fe08c000
Jul 15 10:21:42 lucky06 kernel: [ 28.033980] NIP: c000000000141dc0 LR: c000000000141d4c CTR: c00000000001eb60
Jul 15 10:21:42 lucky06 kernel: [ 28.033981] REGS: c0000000fe08fa90 TRAP: 0901 Not tainted (4.0.0-4-generic)
Jul 15 10:21:42 lucky06 kernel: [ 28.033982] MSR: 8000000000009033 <SF,EE,ME,IR,DR,RI,LE> CR: 28044484 XER: 20000000
Jul 15 10:21:42 lucky06 kernel: [ 28.033987] CFAR: c000000000141dd4 SOFTE: 1
Jul 15 10:21:42 lucky06 kernel: [ 28.033987] GPR00: c00000000031a66c c0000000fe08fd10 c000000001489300 ffffcaaf0eb927f1
Jul 15 10:21:42 lucky06 kernel: [ 28.033987] GPR04: 0000000000000018 ffffffffaa5993b2 0000000055a66c4f 0000000000000001
Jul 15 10:21:42 lucky06 kernel: [ 28.033987] GPR08: 000000003b9ac9ff 359d4b5720d743ef 00000000653d48cc 0000355102127eb3
Jul 15 10:21:42 lucky06 kernel: [ 28.033987] GPR12: c00000000001eb60 c00000000fb83f00
Jul 15 10:21:42 lucky06 kernel: [ 28.033996] NIP [c000000000141dc0] ktime_get_ts64+0xf0/0x150
Jul 15 10:21:42 lucky06 kernel: [ 28.033998] LR [c000000000141d4c] ktime_get_ts64+0x7c/0x150
Jul 15 10:21:42 lucky06 kernel: [ 28.033999] Call Trace:
Jul 15 10:21:42 lucky06 kernel: [ 28.034000] [c0000000fe08fd10] [c0000000fe08fd50] 0xc0000000fe08fd50 (unreliable)
Jul 15 10:21:42 lucky06 kernel: [ 28.034002] [c0000000fe08fd50] [c00000000031a66c] SyS_epoll_wait+0x19c/0x510
Jul 15 10:21:42 lucky06 kernel: [ 28.034004] [c0000000fe08fe30] [c000000000009258] system_call+0x38/0xd0
Jul 15 10:21:42 lucky06 kernel: [ 28.034005] Instruction dump:
Jul 15 10:21:42 lucky06 kernel: [ 28.034006] e8de0000 7d475214 7ce53214 7d4a2634 7d295214 39400000 7fa94040 409d002c
Jul 15 10:21:42 lucky06 kernel: [ 28.034009] 60000000 60000000 60000000 60420000 <3d29c465> 394a0001 39293600 794a0020
Jul 15 10:21:42 lucky06 irqbalance[929]: ...done.
Jul 15 10:21:42 lucky06 rsyslogd-2039: Could no open output pipe '/dev/xconsole': Permission denied [try http://www.rsyslog.com/e/2039 ]
Jul 15 10:21:43 lucky06 dbus[965]: [system] AppArmor D-Bus mediation is enabled
Jul 15 10:21:43 lucky06 systemd[1]: Started LSB: daemon to balance interrupts for SMP systems.
Jul 15 10:21:43 lucky06 systemd[1]: Started System Logging Service.
Jul 15 10:21:43 lucky06 accounts-daemon[930]: started daemon version 0.6.40
Jul 15 10:21:43 lucky06 systemd[1]: Started Accounts Service.
Jul 15 10:22:03 lucky06 kernel: [ 62.541329] INFO: rcu_sched self-detected stall on CPU { 4} (t=5251 jiffies g=2 c=1 q=5229)
Jul 15 10:22:03 lucky06 kernel: [ 62.541344] Task dump for CPU 4:
Jul 15 10:22:03 lucky06 kernel: [ 62.541346] sd-resolve R running task 0 419 1 0x00040004
Jul 15 10:22:03 lucky06 kernel: [ 62.541349] Call Trace:
Jul 15 10:22:03 lucky06 kernel: [ 62.541398] [c0000001f86db600] [c0000000000ee1c0] sched_show_task+0xe0/0x180 (unreliable)
Jul 15 10:22:03 lucky06 kernel: [ 62.541402] [c0000001f86db670] [c00000000012cd88] rcu_dump_cpu_stacks+0xe8/0x160
Jul 15 10:22:03 lucky06 kernel: [ 62.541404] [c0000001f86db6c0] [c000000000131914] rcu_check_callbacks+0x684/0x980
Jul 15 10:22:03 lucky06 kernel: [ 62.541406] [c0000001f86db800] [c0000000001392f4] update_process_times+0x54/0xa0
Jul 15 10:22:03 lucky06 kernel: [ 62.541408] [c0000001f86db830] [c00000000014fc88] tick_sched_handle.isra.15+0x48/0xe0
Jul 15 10:22:03 lucky06 kernel: [ 62.541410] [c0000001f86db870] [c00000000014fd84] tick_sched_timer+0x64/0xd0
Jul 15 10:22:03 lucky06 kernel: [ 62.541412] [c0000001f86db8b0] [c00000000013a718] __run_hrtimer+0xb8/0x2d0
Jul 15 10:22:03 lucky06 kernel: [ 62.541414] [c0000001f86db900] [c00000000013acc8] hrtimer_interrupt+0x148/0x300
Jul 15 10:22:03 lucky06 kernel: [ 62.541425] [c0000001f86db9f0] [c00000000001f27c] __timer_interrupt+0x8c/0x230
Jul 15 10:22:03 lucky06 kernel: [ 62.541426] [c0000001f86dba40] [c00000000001f930] timer_interrupt+0xa0/0xe0
Jul 15 10:22:03 lucky06 kernel: [ 62.541429] [c0000001f86dba70] [c000000000002758] decrementer_common+0x158/0x180
Jul 15 10:22:03 lucky06 kernel: [ 62.541431] --- interrupt: 901 at ktime_get_ts64+0xf0/0x150
Jul 15 10:22:03 lucky06 kernel: [ 62.541431] LR = ktime_get_ts64+0x7c/0x150
Jul 15 10:22:03 lucky06 kernel: [ 62.541459] [c0000001f86dbd60] [c0000001f86dbb10] 0xc0000001f86dbb10 (unreliable)
Jul 15 10:22:03 lucky06 kernel: [ 62.541469] [c0000001f86dbda0] [c0000000002d1678] poll_select_set_timeout+0x98/0xe0
Jul 15 10:22:03 lucky06 kernel: [ 62.541471] [c0000001f86dbde0] [c0000000002d2c5c] SyS_poll+0x8c/0x160
Jul 15 10:22:03 lucky06 kernel: [ 62.541473] [c0000001f86dbe30] [c000000000009258] system_call+0x38/0xd0
Jul 15 10:22:22 lucky06 dhclient: Listening on LPF/eth0/52:54:00:f8:9a:47
Jul 15 10:22:22 lucky06 dhclient: Sending on LPF/eth0/52:54:00:f8:9a:47
Jul 15 10:22:22 lucky06 dhclient: Sending on Socket/fallback
Jul 15 10:22:22 lucky06 dhclient: DHCPREQUEST of 9.3.123.97 on eth0 to 255.255.255.255 port 67 (xid=0x589ec567)
Jul 15 10:22:22 lucky06 dhclient: DHCPACK of 9.3.123.97 from 9.3.123.37
Jul 15 10:22:22 lucky06 ifup[863]: Listening on LPF/eth0/52:54:00:f8:9a:47
Jul 15 10:22:22 lucky06 ifup[863]: Sending on LPF/eth0/52:54:00:f8:9a:47
Jul 15 10:22:22 lucky06 ifup[863]: Sending on Socket/fallback
Jul 15 10:22:22 lucky06 ifup[863]: DHCPREQUEST of 9.3.123.97 on eth0 to 255.255.255.255 port 67 (xid=0x589ec567)
Jul 15 10:22:22 lucky06 ifup[863]: DHCPACK of 9.3.123.97 from 9.3.123.37
Jul 15 10:22:22 lucky06 dhclient: bound to 9.3.123.97 -- renewal in 11501 seconds.
Jul 15 10:22:22 lucky06 ifup[863]: bound to 9.3.123.97 -- renewal in 11501 seconds.
Jul 15 10:22:22 lucky06 systemd[1]: Started Login Service.
Jul 15 10:22:22 lucky06 ifquery[1083]: eth0=eth0
Jul 15 10:22:22 lucky06 systemd[1]: Started ifup for eth0.
Jul 15 10:22:22 lucky06 systemd[1]: Reached target Network.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Network.
Jul 15 10:22:22 lucky06 systemd[1]: Starting /etc/rc.local Compatibility...
Jul 15 10:22:22 lucky06 systemd[1]: Started /etc/rc.local Compatibility.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Terminate Plymouth Boot Screen...
Jul 15 10:22:22 lucky06 systemd[1]: Starting Wait for Plymouth Boot Screen to Quit...
Jul 15 10:22:22 lucky06 systemd[1]: Received SIGRTMIN+21 from PID 370 (plymouthd).
Jul 15 10:22:22 lucky06 systemd[1]: Started Terminate Plymouth Boot Screen.
Jul 15 10:22:22 lucky06 systemd[1]: Started Wait for Plymouth Boot Screen to Quit.
Jul 15 10:22:22 lucky06 systemd[1]: Started Getty on tty1.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Getty on tty1...
Jul 15 10:22:22 lucky06 systemd[1]: Started Serial Getty on hvc0.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Serial Getty on hvc0...
Jul 15 10:22:22 lucky06 systemd[1]: Reached target Login Prompts.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Login Prompts.
Jul 15 10:22:22 lucky06 systemd[1]: Reached target Multi-User System.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Multi-User System.
Jul 15 10:22:22 lucky06 systemd[1]: Reached target Graphical Interface.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Graphical Interface.
Jul 15 10:22:22 lucky06 systemd[1]: Started Stop ureadahead data collection 45s after completed startup.
Jul 15 10:22:22 lucky06 systemd[1]: Starting Update UTMP about System Runlevel Changes...
Jul 15 10:22:22 lucky06 systemd[1]: Started Update UTMP about System Runlevel Changes.
Jul 15 10:22:22 lucky06 systemd[1]: Startup finished in 1.988s (kernel) + 1min 19.419s (userspace) = 1min 21.407s.
Jul 15 10:22:28 lucky06 systemd[1]: Created slice user-0.slice.
Jul 15 10:22:28 lucky06 systemd[1]: Starting user-0.slice.
Jul 15 10:22:28 lucky06 systemd[1]: Starting User Manager for UID 0...
Jul 15 10:22:28 lucky06 systemd[1]: session-c1.scope: Cannot determine UID from slice user-0.slice
Jul 15 10:22:28 lucky06 systemd[1]: Started Session c1 of user root.
Jul 15 10:22:28 lucky06 systemd[1]: Starting Session c1 of user root.
Jul 15 10:22:28 lucky06 systemd[1111]: Reached target Timers.
Jul 15 10:22:28 lucky06 systemd[1111]: Starting Timers.
Jul 15 10:22:28 lucky06 systemd[1111]: Reached target Paths.
Jul 15 10:22:28 lucky06 systemd[1111]: Starting Paths.
Jul 15 10:22:28 lucky06 systemd[1111]: Reached target Sockets.
Jul 15 10:22:28 lucky06 systemd[1111]: Starting Sockets.
Jul 15 10:22:28 lucky06 systemd[1111]: Reached target Basic System.
Jul 15 10:22:28 lucky06 systemd[1111]: Starting Basic System.
Jul 15 10:22:28 lucky06 systemd[1111]: Reached target Default.
Jul 15 10:22:28 lucky06 systemd[1111]: Startup finished in 61ms.
Jul 15 10:22:28 lucky06 systemd[1111]: Starting Default.
Jul 15 10:22:28 lucky06 systemd[1]: Started User Manager for UID 0.
Jul 15 10:22:42 lucky06 systemd[1]: systemd-timesyncd.service: Watchdog timeout (limit 1min)!
Jul 15 10:22:42 lucky06 systemd[1]: systemd-timesyncd.service: Main process exited, code=killed, status=6/ABRT
Jul 15 10:22:42 lucky06 systemd[1]: systemd-timesyncd.service: Unit entered failed state.
Jul 15 10:22:42 lucky06 systemd[1]: systemd-timesyncd.service: Failed with result 'signal'.
Jul 15 10:22:42 lucky06 systemd[1]: systemd-timesyncd.service: Service has no hold-off time, scheduling restart.
Jul 15 10:22:42 lucky06 systemd[1]: Starting Network Time Synchronization...
Jul 15 10:22:43 lucky06 systemd[1]: Started Network Time Synchronization.
Jul 15 10:54:26 lucky06 systemd-timesyncd[1134]: Synchronized to time server 91.189.89.199:123 (ntp.ubuntu.com).
Jul 15 10:54:26 lucky06 systemd[1]: Time has been changed
Jul 15 10:54:26 lucky06 systemd[1111]: Time has been changed
root at lucky06:/var/log# date
Wed Jul 15 10:56:21 EDT 2015
root at lucky06:/var/log# dmesg >>/tmp/before
Unpacking linux-image-4.0.0-4-generic (4.0.0-4.7) over (4.0.0-4.6) ...
[ 535.697797] INFO: rcu_sched self-detected stall on CPU
[ 535.697806] INFO: rcu_sched self-detected stall on CPU { 6} (t=104668 jiffies g=18327 c=18326 q=14)
[ 535.697807] rcu_sched kthread starved for 104668 jiffies!
[ 535.698204] rcu_sched kthread starved for 104668 jiffies!
[ 583.148341] systemd[1]: systemd-timesyncd.service: Watchdog timeout (limit 1min)!
[ 603.148087] systemd[1]: systemd-logind.service: Watchdog timeout (limit 1min)!
[ 680.647044] systemd[1]: systemd-udevd.service: Watchdog timeout (limit 1min)!
[ 951.643493] systemd[1]: Failed to start udev Kernel Device Manager.
[ 1088.260897] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 87s! [swapper/6:0]
[ 1126.009766] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 87s! [swapper/6:0]
[ 1138.592722] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 87s! [swapper/6:0]
[ 1145.398273] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 21s! [swapper/6:0]
[ 1153.786374] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 21s! [swapper/6:0]
[ 1172.147279] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 87s! [swapper/6:0]
[ 1178.950479] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 21s! [swapper/6:0]
[ 1187.333167] NMI watchdog: BUG: soft lockup - CPU#6 stuck for 21s! [swapper/6:0]
Machine is available for debugging
== Comment: #2 - LEKSHMI C. PILLAI <lekshmi.cpillai at in.ibm.com> - 2015-07-16 02:01:45 ==
Hi
Today While installing Ubuntu 15.10 on other guest(lucky08) I saw same
kind of error
lqqqqqqqqqqqqqqqqqqqqqu Starting up the partitioner tqqqqqqqqqqqqqqqqqqqqqk
x x
x 65% x
x x
x Please wait... I watchdog: BUG: soft lockup - CPU#4 stuck for 25s! [swapper/4:0]
[ 808.130053] NMI watchdog: BUG: soft lockup - CPU#4 stuck for 35s! [swapper/4:0]
[ 948.130055] NMI watchdog: BUG: soft lockup - CPU#4 stuck for 38s! [swapper/4:0]
I am totally blocked with Ubuntu installations on Guests.
Please have a check
== Comment: # - LEKSHMI C. PILLAI <lekshmi.cpillai at in.ibm.com> - ==
Boot type (installer was booted from):
I tried cdrom method.Copying the images from website and loaded
Bootloader (netboot ony):
- grub
- yaboot
- PXELINUX
- Other (specify):
Bootloader protocol (netboot only):
- TFTP (in most cases)
- HTTP (optional, grub only)
- Unsure
Kernel cmdline used to launch install (if other than CDROM):
- List cmdline or attach full bootloader file, if available.
- HINT: You may be able to interrupt the bootloader at the menu
screen and get the bootloader to display the kernel cmdline.
Install repository type:
- CDROM
- Local network repository (specify URL):
- Internet mirror (specify URL):http://cdimage.ubuntu.com/ubuntu-server/daily/current/wily-server-ppc64el.iso
Was a response file used during install? (Yes/No):
* If Yes please attach the file
* If No please describe install steps
Point of failure:
5. Problem during post-install (stage 2) configuration or other problem seen after system reboot
While configuring the packages using apt-install
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/debian-installer/+bug/1480235/+subscriptions
More information about the foundations-bugs
mailing list