Hello, Everyone I just ran "yum update" and rebooted. Some time not long after that reboot, I started getting message like this: Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889]
I ran "grep -i "soft lockup"" with the following results:
[root@afolkey2 log]# grep -i "soft lockup" messages Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:11:50 afolkey2 kernel: [ 4154.123765] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:11:54 afolkey2 kernel: [ 4158.146632] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:12:26 afolkey2 kernel: [ 4190.104690] BUG: soft lockup - CPU#1 stuck for 23s! [httpd:1793] Dec 22 20:12:26 afolkey2 kernel: [ 4190.129677] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:12:54 afolkey2 kernel: [ 4218.089855] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:12:54 afolkey2 kernel: [ 4218.114842] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:13:22 afolkey2 kernel: [ 4246.075021] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:13:22 afolkey2 kernel: [ 4246.100008] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:13:50 afolkey2 kernel: [ 4274.060185] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:13:50 afolkey2 kernel: [ 4274.085171] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:14:18 afolkey2 kernel: [ 4302.045349] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:14:18 afolkey2 kernel: [ 4302.070335] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:14:46 afolkey2 kernel: [ 4330.030515] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:14:46 afolkey2 kernel: [ 4330.055500] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:15:26 afolkey2 kernel: [ 4370.009320] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:15:26 afolkey2 kernel: [ 4370.034307] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:15:54 afolkey2 kernel: [ 4397.994486] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793] Dec 22 20:15:54 afolkey2 kernel: [ 4398.019473] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889]
I rebooted into an older kernel and have not had any more of these messages popping up.
Eventually, my system became unresponsive and I had to reboot.
I am running Fedora 20 (fully updated) Installation method: fedup
Any ideas?
Steven P. Ulrick
On 23.12.2013 03:30, Steven P. Ulrick wrote:
Hello, Everyone I just ran "yum update" and rebooted. Some time not long after that reboot, I started getting message like this: Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889]
[...]
I rebooted into an older kernel and have not had any more of these messages popping up.
Eventually, my system became unresponsive and I had to reboot.
To clarify, does it happen with old or new kernel?
I am running Fedora 20 (fully updated) Installation method: fedup
Any ideas?
It looks like httpd is hanging somewhere doing something and kernel detects this. It might also be that your system is busy on doing I/O operations etc. and httpd process is blocked waiting for CPU time.
Mateusz Marzantowicz
On Mon, 23 Dec 2013 12:02:49 +0100 Mateusz Marzantowicz mmarzantowicz@osdf.com.pl wrote:
On 23.12.2013 03:30, Steven P. Ulrick wrote:
Hello, Everyone I just ran "yum update" and rebooted. Some time not long after that reboot, I started getting message like this: Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889]
[...]
I rebooted into an older kernel and have not had any more of these messages popping up.
Eventually, my system became unresponsive and I had to reboot.
To clarify, does it happen with old or new kernel?
New Kernel: kernel-3.12.5-302.fc20.x86_64
I am running Fedora 20 (fully updated) Installation method: fedup
Any ideas?
It looks like httpd is hanging somewhere doing something and kernel detects this. It might also be that your system is busy on doing I/O operations etc. and httpd process is blocked waiting for CPU time.
Guess I'll reboot into the new/problematic kernel and see if it happens again.
Steven P. Ulrick
On 23.12.2013, Steven P. Ulrick wrote:
Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:11:50 afolkey2 kernel: [ 4154.123765] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793]
It's the kernel watchdog bailing out. Do you run httpd within a virtual box?
On Mon, 23 Dec 2013 17:11:13 +0100 Heinz Diehl htd@fritha.org wrote:
On 23.12.2013, Steven P. Ulrick wrote:
Dec 22 20:11:26 afolkey2 kernel: [ 4130.161465] BUG: soft lockup - CPU#3 stuck for 22s! [httpd:1889] Dec 22 20:11:50 afolkey2 kernel: [ 4154.123765] BUG: soft lockup - CPU#1 stuck for 22s! [httpd:1793]
It's the kernel watchdog bailing out. Do you run httpd within a virtual box?
No. All non-virtual on this issue...
On Mon, 23 Dec 2013 23:57:09 +0100 Heinz Diehl htd@fritha.org wrote:
On 23.12.2013, Steven P. Ulrick wrote:
No. All non-virtual on this issue...
Ok. How high is the load when this happens?
Didn't check this when it was happening...
Is there a kernel which doesn't lead to these lockups?
Yes: kernel-3.11.10-301.fc20.x86_64
Right now I am FINALLY going to remember to reboot into the "offending" kernel and see if this happens again.
Steven P. Ulrick
On 24.12.2013, Steven P. Ulrick wrote:
Is there a kernel which doesn't lead to these lockups?
Yes: kernel-3.11.10-301.fc20.x86_64
Right now I am FINALLY going to remember to reboot into the "offending" kernel and see if this happens again.
If you can reproduce this with a vanilla 3.12.5/.6, you could suggest reporting it on either the Linux kernel mailing list or bugzilla.kernel.org.
If it turns out to be easily reproducible, you maybe could consider a "git bisect", too...
On 24.12.2013, Steven P. Ulrick wrote:
Right now I am FINALLY going to remember to reboot into the "offending" kernel and see if this happens again.
This one came up on LKML today, maybe it's related: https://lkml.org/lkml/2013/12/27/255
3.12.5-302.fc20.x86_64 x 2
------------[ cut here ]------------ WARNING: CPU: 3 PID: 17822 at drivers/usb/host/ehci-hcd.c:1027 ehci_endpoint_reset+0x101/0x110() clear_halt for a busy endpoint Call Trace: [<ffffffff81662d11>] dump_stack+0x45/0x56 [<ffffffff810691dd>] warn_slowpath_common+0x7d/0xa0 [<ffffffff8106924c>] warn_slowpath_fmt+0x4c/0x50 [<ffffffff8147a054>] ? usb_control_msg+0xd4/0x110 [<ffffffff81492ba1>] ehci_endpoint_reset+0x101/0x110 [<ffffffff81478ab5>] usb_hcd_reset_endpoint+0x25/0x70 [<ffffffff8147aac8>] usb_reset_endpoint+0x28/0x40 [<ffffffff8147ab4e>] usb_clear_halt+0x6e/0x80 [<ffffffff81485ccf>] usbdev_do_ioctl+0xbbf/0x1060 [<ffffffffa0582b57>] ? supdrvIOCtlFast+0x77/0xa0 [vboxdrv] [<ffffffff8148619e>] usbdev_ioctl+0xe/0x20 [<ffffffff811c0bbd>] do_vfs_ioctl+0x2dd/0x4b0 [<ffffffff811c0e11>] SyS_ioctl+0x81/0xa0 [<ffffffff81671d69>] system_call_fastpath+0x16/0x1b ---[ end trace 93ba77ce337e7f42 ]---
------------[ cut here ]------------ WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:264 dev_watchdog+0x266/0x270() NETDEV WATCHDOG: enp0s4f0u2c3i8 (cdc_ether): transmit queue 0 timed out Call Trace: <IRQ> [<ffffffff81662d11>] dump_stack+0x45/0x56 [<ffffffff810691dd>] warn_slowpath_common+0x7d/0xa0 [<ffffffff8106924c>] warn_slowpath_fmt+0x4c/0x50 [<ffffffff810818ba>] ? __queue_work+0x12a/0x310 [<ffffffff81585746>] dev_watchdog+0x266/0x270 [<ffffffff815854e0>] ? dev_graft_qdisc+0x80/0x80 [<ffffffff81074e26>] call_timer_fn+0x36/0x110 [<ffffffff815854e0>] ? dev_graft_qdisc+0x80/0x80 [<ffffffff810754ba>] run_timer_softirq+0x1ea/0x290 [<ffffffff8106e747>] __do_softirq+0xf7/0x240 [<ffffffff8167361c>] call_softirq+0x1c/0x30 [<ffffffff810146a5>] do_softirq+0x55/0x90 [<ffffffff8106ea25>] irq_exit+0xb5/0xc0 [<ffffffff81673fc5>] smp_apic_timer_interrupt+0x45/0x60 [<ffffffff8167295d>] apic_timer_interrupt+0x6d/0x80 <EOI> [<ffffffff8104e486>] ? native_safe_halt+0x6/0x10 [<ffffffff8101b0bf>] default_idle+0x1f/0xc0 [<ffffffff8101b1dd>] amd_e400_idle+0x7d/0x110 [<ffffffff8101b996>] arch_cpu_idle+0x26/0x30 [<ffffffff810b9765>] cpu_startup_entry+0xe5/0x280 [<ffffffff8103fb58>] start_secondary+0x218/0x2c0 ---[ end trace 554a9463b4511f31 ]---
poma
-
Heinz Diehl -
Mateusz Marzantowicz -
poma -
Steven P. Ulrick