Bug#656196: Stalls happen with 3.0

To: Ben Hutchings <ben@decadent.org.uk>
Cc: 656196@bugs.debian.org
Subject: Bug#656196: Stalls happen with 3.0
From: Michael Below <mbelow@antithese.de>
Date: Thu, 16 Feb 2012 16:55:46 +0100
Message-id: <[🔎] 1329407746.3999.40.camel@ossietzky>
Reply-to: Michael Below <mbelow@antithese.de>, 656196@bugs.debian.org
In-reply-to: <[🔎] 20120214182345.GP12704@decadent.org.uk>
References: <[🔎] 1329240936.3877.71.camel@ossietzky> <[🔎] 20120214182345.GP12704@decadent.org.uk>

Am Dienstag, den 14.02.2012, 18:23 +0000 schrieb Ben Hutchings:
> On Tue, Feb 14, 2012 at 06:35:36PM +0100, Michael Below wrote:
> > The stall happens with 3.0.0-1-amd64 while it didn't happen with 2.6.39.
> > Anything else I can try?
> [...]
> 
> What about the current version, Linux 3.2?

Same problem, see attached syslog.

Feb 16 16:31:49 ossietzky spamd[10969]: Use of uninitialized value $selerr in concatenation (.) or string at /usr/share/perl5/Mail/SpamAssassin/SpamdForkScaling.pm line 332.
Feb 16 16:31:49 ossietzky spamd[10969]: prefork: select returned error on server filehandle: 
Feb 16 16:31:49 ossietzky spamd[10981]: prefork: sysread(8) failed after 300 secs at /usr/share/perl5/Mail/SpamAssassin/SpamdForkScaling.pm line 654.
Feb 16 16:31:49 ossietzky spamd[10980]: prefork: sysread(7) failed after 300 secs at /usr/share/perl5/Mail/SpamAssassin/SpamdForkScaling.pm line 654.
Feb 16 16:31:49 ossietzky spamd[10969]: prefork: child states: II
Feb 16 16:31:49 ossietzky rtkit-daemon[2287]: The canary thread is apparently starving. Taking action.
Feb 16 16:31:49 ossietzky spamd[10969]: prefork: child states: II
Feb 16 16:31:49 ossietzky rtkit-daemon[2287]: Demoting known real-time threads.
Feb 16 16:31:49 ossietzky rtkit-daemon[2287]: Successfully demoted thread 3453 of process 3453 (/usr/bin/pulseaudio).
Feb 16 16:31:49 ossietzky rtkit-daemon[2287]: Demoted 1 threads.
Feb 16 16:31:49 ossietzky spamd[10969]: spamd: handled cleanup of child pid [10981] due to SIGCHLD: exit 0
Feb 16 16:31:49 ossietzky spamd[10969]: spamd: server successfully spawned child process, pid 16521
Feb 16 16:31:49 ossietzky spamd[10969]: spamd: handled cleanup of child pid [10980] due to SIGCHLD: exit 0
Feb 16 16:31:49 ossietzky spamd[10969]: prefork: child states: I
Feb 16 16:31:49 ossietzky spamd[10969]: spamd: server successfully spawned child process, pid 16522
Feb 16 16:31:49 ossietzky spamd[10969]: prefork: child states: II
Feb 16 16:31:49 ossietzky kernel: [12630.053529] INFO: rcu_sched detected stall on CPU 3 (t=74991 jiffies)
Feb 16 16:31:50 ossietzky kernel: [12630.053529] sending NMI to all CPUs:
Feb 16 16:31:50 ossietzky kernel: [12630.053529] NMI backtrace for cpu 3
Feb 16 16:31:50 ossietzky kernel: [12630.053529] CPU 3 
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Modules linked in: powernow_k8 mperf cpufreq_conservative cpufreq_userspace cpufreq_powersave cpufreq_stats parport_pc ppdev lp parport binfmt_misc fuse smsc47b397 loop dm_crypt tpm_infineon arc4 snd_hda_codec_analog radeon ttm drm_kms_helper drm i2c_algo_bit power_supply rt73usb crc_itu_t snd_hda_intel snd_hda_codec rt2x00usb rt2x00lib snd_hwdep shpchp pci_hotplug snd_pcm_oss snd_mixer_oss snd_pcm mac80211 cfg80211 snd_seq_midi joydev snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc processor k10temp usbhid hid sp5100_tco usb_storage edac_core uas edac_mce_amd hp_wmi i2c_piix4 evdev i2c_core sparse_keymap pcspkr rfkill psmouse serio_raw button wmi thermal_sys tpm_tis tpm tpm_bios ext3 jbd mbcache dm_mod sr_mod sd_mod cdrom crc_t10dif ohci_hcd tg3 libphy floppy ahci libahci libata ehci_hcd scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 16 16:31:50 ossietzky kernel: [12630.053529] 
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Pid: 0, comm: swapper/3 Not tainted 3.2.0-1-amd64 #1 Hewlett-Packard HP Compaq dc5850 Microtower/3029h
Feb 16 16:31:50 ossietzky kernel: [12630.053529] RIP: 0010:[<ffffffff811afc59>]  [<ffffffff811afc59>] __const_udelay+0x17/0x20
Feb 16 16:31:50 ossietzky kernel: [12630.053529] RSP: 0018:ffff88006fd83d00  EFLAGS: 00000847
Feb 16 16:31:50 ossietzky kernel: [12630.053529] RAX: 00000000c31401c0 RBX: 0000000000002710 RCX: 0000000000000040
Feb 16 16:31:50 ossietzky kernel: [12630.053529] RDX: 0000000000273fbe RSI: 0000000000000200 RDI: 0000000000418958
Feb 16 16:31:50 ossietzky kernel: [12630.053529] RBP: ffffffff81621d00 R08: 0000000000000002 R09: 0000000000000001
Feb 16 16:31:50 ossietzky kernel: [12630.053529] R10: 7fffffffffffffff R11: 7fffffffffffffff R12: ffffffff81621e00
Feb 16 16:31:50 ossietzky kernel: [12630.053529] R13: ffff88006fd83e30 R14: 7fffffffffffffff R15: ffffffff8106ba90
Feb 16 16:31:50 ossietzky kernel: [12630.053529] FS:  00007f071c36c7a0(0000) GS:ffff88006fd80000(0000) knlGS:00000000f514cb70
Feb 16 16:31:50 ossietzky kernel: [12630.053529] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Feb 16 16:31:50 ossietzky kernel: [12630.053529] CR2: 00007f027476c7c0 CR3: 0000000069f8c000 CR4: 00000000000006e0
Feb 16 16:31:50 ossietzky kernel: [12630.053529] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053529] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Process swapper/3 (pid: 0, threadinfo ffff88006cc18000, task ffff88006cc14f40)
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Stack:
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  ffffffff810248c1 ffff88006fd8ebc0 ffffffff810953f8 0000000000000046
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  0000000000000093 ffffffff81011885 0000000000000003 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  0000000000000003 ffff88006fd83e30 7fffffffffffffff ffffffff8106ba90
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  <IRQ> 
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810248c1>] ? arch_trigger_all_cpu_backtrace+0x6c/0x7b
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810953f8>] ? __rcu_pending+0x82/0x337
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81011885>] ? arch_local_irq_save+0x5/0x13
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106ba90>] ? tick_nohz_handler+0xd0/0xd0
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810959da>] ? rcu_check_callbacks+0x90/0xcc
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810526f7>] ? update_process_times+0x31/0x63
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106bafa>] ? tick_sched_timer+0x6a/0x90
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81061e0e>] ? __run_hrtimer+0xac/0x135
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106253e>] ? hrtimer_interrupt+0xdb/0x195
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106af1b>] ? tick_do_broadcast.constprop.4+0x3f/0x85
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106b01d>] ? tick_handle_oneshot_broadcast+0xbc/0xfa
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8109501a>] ? __rcu_process_callbacks+0x72/0x2c0
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100fe5d>] ? timer_interrupt+0x15/0x1c
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8109053d>] ? handle_irq_event_percpu+0x50/0x180
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810135b2>] ? read_tsc+0x5/0x14
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81065a6b>] ? timekeeping_get_ns+0xd/0x2a
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810906a1>] ? handle_irq_event+0x34/0x53
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81092a9d>] ? handle_edge_irq+0xa2/0xc9
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100f835>] ? handle_irq+0x1d/0x21
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100f565>] ? do_IRQ+0x42/0x98
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff813409ee>] ? common_interrupt+0x6e/0x6e
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  <EOI> 
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8102b2c4>] ? native_safe_halt+0x2/0x3
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Code: 00 00 48 ff c8 75 fb 48 ff c8 c3 48 8b 05 a8 31 49 00 ff e0 65 48 8b 14 25 98 34 01 00 48 6b d2 3e 48 8d 04 bd 00 00 00 00 f7 e2 <48> 8d 7a 01 e9 d7 ff ff ff 48 69 ff c7 10 00 00 e9 d4 ff ff ff 
Feb 16 16:31:50 ossietzky kernel: [12630.053529] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  <IRQ>  [<ffffffff810248c1>] ? arch_trigger_all_cpu_backtrace+0x6c/0x7b
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810953f8>] ? __rcu_pending+0x82/0x337
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81011885>] ? arch_local_irq_save+0x5/0x13
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106ba90>] ? tick_nohz_handler+0xd0/0xd0
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810959da>] ? rcu_check_callbacks+0x90/0xcc
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810526f7>] ? update_process_times+0x31/0x63
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106bafa>] ? tick_sched_timer+0x6a/0x90
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81061e0e>] ? __run_hrtimer+0xac/0x135
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106253e>] ? hrtimer_interrupt+0xdb/0x195
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106af1b>] ? tick_do_broadcast.constprop.4+0x3f/0x85
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8106b01d>] ? tick_handle_oneshot_broadcast+0xbc/0xfa
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8109501a>] ? __rcu_process_callbacks+0x72/0x2c0
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100fe5d>] ? timer_interrupt+0x15/0x1c
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8109053d>] ? handle_irq_event_percpu+0x50/0x180
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810135b2>] ? read_tsc+0x5/0x14
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81065a6b>] ? timekeeping_get_ns+0xd/0x2a
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff810906a1>] ? handle_irq_event+0x34/0x53
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81092a9d>] ? handle_edge_irq+0xa2/0xc9
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100f835>] ? handle_irq+0x1d/0x21
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100f565>] ? do_IRQ+0x42/0x98
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff813409ee>] ? common_interrupt+0x6e/0x6e
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  <EOI>  [<ffffffff8102b2c4>] ? native_safe_halt+0x2/0x3
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.053529]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12630.052027] NMI backtrace for cpu 0
Feb 16 16:31:50 ossietzky kernel: [12630.052027] CPU 0 
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Modules linked in: powernow_k8 mperf cpufreq_conservative cpufreq_userspace cpufreq_powersave cpufreq_stats parport_pc ppdev lp parport binfmt_misc fuse smsc47b397 loop dm_crypt tpm_infineon arc4 snd_hda_codec_analog radeon ttm drm_kms_helper drm i2c_algo_bit power_supply rt73usb crc_itu_t snd_hda_intel snd_hda_codec rt2x00usb rt2x00lib snd_hwdep shpchp pci_hotplug snd_pcm_oss snd_mixer_oss snd_pcm mac80211 cfg80211 snd_seq_midi joydev snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc processor k10temp usbhid hid sp5100_tco usb_storage edac_core uas edac_mce_amd hp_wmi i2c_piix4 evdev i2c_core sparse_keymap pcspkr rfkill psmouse serio_raw button wmi thermal_sys tpm_tis tpm tpm_bios ext3 jbd mbcache dm_mod sr_mod sd_mod cdrom crc_t10dif ohci_hcd tg3 libphy floppy ahci libahci libata ehci_hcd scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 16 16:31:50 ossietzky kernel: [12630.052027] 
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Pid: 0, comm: swapper/0 Not tainted 3.2.0-1-amd64 #1 Hewlett-Packard HP Compaq dc5850 Microtower/3029h
Feb 16 16:31:50 ossietzky kernel: [12630.052027] RIP: 0010:[<ffffffff8102b2c4>]  [<ffffffff8102b2c4>] native_safe_halt+0x2/0x3
Feb 16 16:31:50 ossietzky kernel: [12630.052027] RSP: 0018:ffffffff81601ef0  EFLAGS: 00000246
Feb 16 16:31:50 ossietzky kernel: [12630.052027] RAX: 0000000000000000 RBX: ffffffff81600000 RCX: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052027] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffffffff81600000
Feb 16 16:31:50 ossietzky kernel: [12630.052027] RBP: ffffffff8168ca80 R08: 0000000000000000 R09: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052027] R10: 0000000000013540 R11: ffffffff81600000 R12: ffff88006ff7e7c0
Feb 16 16:31:50 ossietzky kernel: [12630.052027] R13: ffffffffffffffff R14: 000000000008c800 R15: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052027] FS:  00007f071c36c7a0(0000) GS:ffff88006fc00000(0000) knlGS:00000000f514cb70
Feb 16 16:31:50 ossietzky kernel: [12630.052027] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Feb 16 16:31:50 ossietzky kernel: [12630.052027] CR2: 00007fd6e054a000 CR3: 0000000069f8c000 CR4: 00000000000006f0
Feb 16 16:31:50 ossietzky kernel: [12630.052027] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052027] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Process swapper/0 (pid: 0, threadinfo ffffffff81600000, task ffffffff8160d020)
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Stack:
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  ffffffff8101448c 0000000000000000 ffffffff81014583 ffffffffffffffff
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  000000000008c800 0000000000000000 ffffffff8100d25f ffffffffffffffff
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  e50bbc13124ced8d 0000000000000000 0000000000000000 6db6db6db6db6db7
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Code: 89 e1 89 ee 48 c7 c7 6f 60 4c 81 31 c0 e8 16 ef 30 00 48 83 c4 18 89 d8 5b 5d 41 5c 41 5d c3 9c 58 c3 57 9d c3 fa c3 fb c3 fb f4 <c3> f4 c3 66 66 66 90 66 66 90 c3 66 66 66 90 66 66 90 c3 0f 06 
Feb 16 16:31:50 ossietzky kernel: [12630.052027] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Feb 16 16:31:50 ossietzky kernel: [12630.052027]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111
Feb 16 16:31:50 ossietzky kernel: [12630.052026] NMI backtrace for cpu 2
Feb 16 16:31:50 ossietzky kernel: [12630.052026] CPU 2 
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Modules linked in: powernow_k8 mperf cpufreq_conservative cpufreq_userspace cpufreq_powersave cpufreq_stats parport_pc ppdev lp parport binfmt_misc fuse smsc47b397 loop dm_crypt tpm_infineon arc4 snd_hda_codec_analog radeon ttm drm_kms_helper drm i2c_algo_bit power_supply rt73usb crc_itu_t snd_hda_intel snd_hda_codec rt2x00usb rt2x00lib snd_hwdep shpchp pci_hotplug snd_pcm_oss snd_mixer_oss snd_pcm mac80211 cfg80211 snd_seq_midi joydev snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc processor k10temp usbhid hid sp5100_tco usb_storage edac_core uas edac_mce_amd hp_wmi i2c_piix4 evdev i2c_core sparse_keymap pcspkr rfkill psmouse serio_raw button wmi thermal_sys tpm_tis tpm tpm_bios ext3 jbd mbcache dm_mod sr_mod sd_mod cdrom crc_t10dif ohci_hcd tg3 libphy floppy ahci libahci libata ehci_hcd scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 16 16:31:50 ossietzky kernel: [12630.052026] 
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Pid: 0, comm: swapper/2 Not tainted 3.2.0-1-amd64 #1 Hewlett-Packard HP Compaq dc5850 Microtower/3029h
Feb 16 16:31:50 ossietzky kernel: [12630.052026] RIP: 0010:[<ffffffff8102b2c4>]  [<ffffffff8102b2c4>] native_safe_halt+0x2/0x3
Feb 16 16:31:50 ossietzky kernel: [12630.052026] RSP: 0018:ffff88006cc05ed0  EFLAGS: 00000246
Feb 16 16:31:50 ossietzky kernel: [12630.052026] RAX: 0000000000000000 RBX: ffff88006cc04000 RCX: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff88006cc04000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] RBP: ffffffff8168ca80 R08: 0000000000000000 R09: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] R10: ffff8800033da7e0 R11: ffff88006cc04000 R12: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] FS:  00007f071c36c7a0(0000) GS:ffff88006fd00000(0000) knlGS:00000000f6036710
Feb 16 16:31:50 ossietzky kernel: [12630.052026] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Feb 16 16:31:50 ossietzky kernel: [12630.052026] CR2: 00007f4ecdc0a000 CR3: 0000000069f8c000 CR4: 00000000000006e0
Feb 16 16:31:50 ossietzky kernel: [12630.052026] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Process swapper/2 (pid: 0, threadinfo ffff88006cc04000, task ffff88006cc035e0)
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Stack:
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  ffffffff8101448c 0000000000000000 ffffffff81014583 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  0000000200000000 0000000000000000 ffffffff8100d25f 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  2fe496143c3ce6b7 00000000f3f2782d 0000000000000002 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Code: 89 e1 89 ee 48 c7 c7 6f 60 4c 81 31 c0 e8 16 ef 30 00 48 83 c4 18 89 d8 5b 5d 41 5c 41 5d c3 9c 58 c3 57 9d c3 fa c3 fb c3 fb f4 <c3> f4 c3 66 66 66 90 66 66 90 c3 66 66 66 90 66 66 90 c3 0f 06 
Feb 16 16:31:50 ossietzky kernel: [12630.052026] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.052026]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12630.053517] NMI backtrace for cpu 1
Feb 16 16:31:50 ossietzky kernel: [12630.053517] CPU 1 
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Modules linked in: powernow_k8 mperf cpufreq_conservative cpufreq_userspace cpufreq_powersave cpufreq_stats parport_pc ppdev lp parport binfmt_misc fuse smsc47b397 loop dm_crypt tpm_infineon arc4 snd_hda_codec_analog radeon ttm drm_kms_helper drm i2c_algo_bit power_supply rt73usb crc_itu_t snd_hda_intel snd_hda_codec rt2x00usb rt2x00lib snd_hwdep shpchp pci_hotplug snd_pcm_oss snd_mixer_oss snd_pcm mac80211 cfg80211 snd_seq_midi joydev snd_rawmidi snd_seq_midi_event snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc processor k10temp usbhid hid sp5100_tco usb_storage edac_core uas edac_mce_amd hp_wmi i2c_piix4 evdev i2c_core sparse_keymap pcspkr rfkill psmouse serio_raw button wmi thermal_sys tpm_tis tpm tpm_bios ext3 jbd mbcache dm_mod sr_mod sd_mod cdrom crc_t10dif ohci_hcd tg3 libphy floppy ahci libahci libata ehci_hcd scsi_mod usbcore usb_common [last unloaded: scsi_wait_scan]
Feb 16 16:31:50 ossietzky kernel: [12630.053517] 
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Pid: 0, comm: swapper/1 Not tainted 3.2.0-1-amd64 #1 Hewlett-Packard HP Compaq dc5850 Microtower/3029h
Feb 16 16:31:50 ossietzky kernel: [12630.053517] RIP: 0010:[<ffffffff8102b2c4>]  [<ffffffff8102b2c4>] native_safe_halt+0x2/0x3
Feb 16 16:31:50 ossietzky kernel: [12630.053517] RSP: 0018:ffff88006d7d1ed0  EFLAGS: 00000246
Feb 16 16:31:50 ossietzky kernel: [12630.053517] RAX: 0000000000000000 RBX: ffff88006d7d0000 RCX: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] RDX: 0000000000000046 RSI: 0000000000000003 RDI: ffff88006d7d0000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] RBP: ffffffff8168ca80 R08: 0000000000000000 R09: ffffffff8168ca80
Feb 16 16:31:50 ossietzky kernel: [12630.053517] R10: 0000000000000046 R11: ffff88006d7d0000 R12: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] FS:  00007f071c36c7a0(0000) GS:ffff88006fc80000(0000) knlGS:00000000f514cb70
Feb 16 16:31:50 ossietzky kernel: [12630.053517] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Feb 16 16:31:50 ossietzky kernel: [12630.053517] CR2: 00007f026c186b80 CR3: 0000000069f8c000 CR4: 00000000000006e0
Feb 16 16:31:50 ossietzky kernel: [12630.053517] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Process swapper/1 (pid: 0, threadinfo ffff88006d7d0000, task ffff88006d7c20c0)
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Stack:
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  ffffffff8101448c ffffffff8168ca80 ffffffff81014583 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  0000000100000000 0000000000000000 ffffffff8100d25f ffffffff8107073a
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  321b0da723b7887e 0000000000000282 0000000000000001 0000000000000000
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8107073a>] ? arch_local_irq_restore+0x2/0x8
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Code: 89 e1 89 ee 48 c7 c7 6f 60 4c 81 31 c0 e8 16 ef 30 00 48 83 c4 18 89 d8 5b 5d 41 5c 41 5d c3 9c 58 c3 57 9d c3 fa c3 fb c3 fb f4 <c3> f4 c3 66 66 66 90 66 66 90 c3 66 66 66 90 66 66 90 c3 0f 06 
Feb 16 16:31:50 ossietzky kernel: [12630.053517] Call Trace:
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8101448c>] ? default_idle+0x47/0x7f
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff81014583>] ? amd_e400_idle+0xbf/0xe4
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8100d25f>] ? cpu_idle+0xaf/0xf2
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff8107073a>] ? arch_local_irq_restore+0x2/0x8
Feb 16 16:31:50 ossietzky kernel: [12630.053517]  [<ffffffff81332cda>] ? start_secondary+0x1d5/0x1db
Feb 16 16:31:50 ossietzky kernel: [12930.013155] Clocksource tsc unstable (delta = 299966130397 ns)
Feb 16 16:31:50 ossietzky kernel: [12930.043092] Switching to clocksource hpet

Reply to:

Follow-Ups:
- Bug#656196: [2.6.39 -> 3.0 regression] kernel stalls every few days (rcu_sched_state detected stall on CPU x)
  - From: Jonathan Nieder <jrnieder@gmail.com>

References:
- Bug#656196: Stalls happen with 3.0
  - From: Michael Below <below@judiz.de>
- Bug#656196: Stalls happen with 3.0
  - From: Ben Hutchings <ben@decadent.org.uk>

Prev by Date: Bug#490694: Extra video card seems to be the problem
Next by Date: Bug#659948: [initramfs-tools] Fails to upgrade (Sid)
Previous by thread: Bug#656196: Stalls happen with 3.0
Next by thread: Bug#656196: [2.6.39 -> 3.0 regression] kernel stalls every few days (rcu_sched_state detected stall on CPU x)
Index(es):
- Date
- Thread