Subject: debian 3.0.0-2-amd64 ACPI + Realtek rtl8169 - Hangs, NMI Backtraces

From: Armin Kazmi <[email-masked]>
Date: Wed, 02 Nov 2011 20:27:48 +0100

Hi guys,

I'm a bit lost and don't know how to track this issue down. Attached is a 
dmesg output with a rtl8169 card connected, iwlagndmesg with connected iwlagn 
device, the output of lspci, lsmod and the kernel config.

Currently the named kernel series seems to have a very strange behaviour when 
connected to a network. All further named issues don't happen at all, if there 
is no address bound to the device. However, if there is an address bound to 
the device and there is absolutely no user interaction for about 200 seconds 
(sometimes 500 seconds - I don't have a clue about the real pattern here) the 
kernel triggers NMI backtraces on all cores (2 in my case).

As an example here is a truncated dmesg only showing the backtrace for cpu 0
last lines of the backtrace shows some issues with acpi_idle_enter so this 
entire issue is likely ACPI related.

Also, it's worth mentioning.. there is absolutely nothing leaving the device 
until a user action occurs after the dump of the backtrace. E.g. SSH-ing on 
the target machine does not react at all, until I just move the mouse cursor 
on the affected machine.

There are similar issues with connections using the wireless network device 
(iwlagn), hiccups, hangs until a user action occurs, but with other dumps 
showing other errors as in the attachment "iwlagndmesg". E.g. when getting the 
dumps of the machine via scp, the machine did not react on the connection 
request at all until I moved the mouse again.

Besides "ro and quiet" there is no boot parameter set.

Please feel free to ask for more information you might need .

Regards

Armin Kazmi

------------------------

[ 2991.259780] INFO: rcu_sched_state detected stall on CPU 0 (t=15992 jiffies)
[ 2991.259784] sending NMI to all CPUs:
[ 2991.259788] NMI backtrace for cpu 0
[ 2991.259790] CPU 0 
[ 2991.259791] Modules linked in: parport_pc ppdev lp parport rfcomm bnep nfsd 
nfs lockd fscache auth_rpcgss nfs_acl sunrpc ext3 jbd loop firewire_sbp2 
snd_hda_codec_si3054 snd_hda_codec_realtek snd_hda_intel snd_hda_codec arc4 
btusb bluetooth snd_hwdep snd_pcm iwlagn sg snd_seq snd_timer snd_seq_device 
ir_lirc_codec lirc_dev nouveau mac80211 cfg80211 i2c_i801 ttm firewire_ohci 
sdhci_pci drm_kms_helper drm uhci_hcd sr_mod snd ir_sony_decoder i2c_algo_bit 
r8169 soundcore ehci_hcd usbcore cdrom snd_page_alloc joydev mii rfkill sdhci 
mmc_core i2c_core mxm_wmi firewire_core ir_jvc_decoder battery ac button 
processor video ir_rc6_decoder evdev crc_itu_t wmi ir_rc5_decoder rc_rc6_mce 
ir_nec_decoder pcspkr container ite_cir rc_core power_supply psmouse serio_raw 
ext4 mbcache jbd2 crc16 sd_mod crc_t10dif ata_generic thermal thermal_sys 
ata_piix libata scsi_mod
[ 2991.259854] 
[ 2991.259856] Pid: 0, comm: swapper Not tainted 3.0.0-2-amd64 #1 Clevo Co. 
M570RU/SANTA ROSA
[ 2991.259860] RIP: 0010:[<ffffffff811abe74>]  [<ffffffff811abe74>] __delay+0xb/0x11
[ 2991.259866] RSP: 0018:ffff88015fc03d08  EFLAGS: 00000092
[ 2991.259868] RAX: ffffffff811abec7 RBX: 0000000000002710 RCX: 0000000000000003
[ 2991.259870] RDX: 000000000025bfea RSI: 0000000000000200 RDI: 
000000000025bfeb
[ 2991.259872] RBP: ffffffff8161b800 R08: 0000000000000000 R09: 00000000fffffffe
[ 2991.259874] R10: 0000000000000000 R11: 0000000000000293 R12: ffffffff8161b900
[ 2991.259877] R13: ffff88015fc03e18 R14: 0000000000000001 R15: ffffffff8106d090
[ 2991.259879] FS:  0000000000000000(0000) GS:ffff88015fc00000(0000) 
knlGS:0000000000000000
[ 2991.259881] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 2991.259883] CR2: 00007fb1c26fd000 CR3: 0000000001603000 CR4: 
00000000000006f0
[ 2991.259885] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 
0000000000000000
[ 2991.259887] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 2991.259890] Process swapper (pid: 0, threadinfo ffffffff81600000, task 
ffffffff8160b020)
[ 2991.259891] Stack:
[ 2991.259893]  0000000000000096 ffffffff8101ffa1 ffff88015fc0ecf0 ffffffff81096d64
[ 2991.259896]  ffff8801402c8e40 0000000000000000 0000000000000000 
0000000000000000
[ 2991.259900]  ffff88015fc03e18 0000000000000001 ffffffff8106d090 ffffffff81097365
[ 2991.259903] Call Trace:
[ 2991.259905]  <IRQ> 
[ 2991.259910]  [<ffffffff8101ffa1>] ? arch_trigger_all_cpu_backtrace+0x6c/0x7b
[ 2991.259914]  [<ffffffff81096d64>] ? __rcu_pending+0x82/0x2ed
[ 2991.259917]  [<ffffffff8106d090>] ? tick_nohz_handler+0xd0/0xd0
[ 2991.259920]  [<ffffffff81097365>] ? rcu_check_callbacks+0x7e/0xa9
[ 2991.259923]  [<ffffffff81053372>] ? update_process_times+0x31/0x63
[ 2991.259926]  [<ffffffff8106d0fa>] ? tick_sched_timer+0x6a/0x90
[ 2991.259930]  [<ffffffff81062e12>] ? __run_hrtimer+0xaf/0x13a
[ 2991.259933]  [<ffffffff810635a3>] ? hrtimer_interrupt+0xd6/0x19a
[ 2991.259936]  [<ffffffff810671a7>] ? timekeeping_get_ns+0xd/0x2a
[ 2991.259940]  [<ffffffff8106c389>] ? tick_do_broadcast+0x3f/0x83
[ 2991.259943]  [<ffffffff8106c49c>] ? tick_handle_oneshot_broadcast+0xcf/0x103
[ 2991.259947]  [<ffffffff8100afe8>] ? timer_interrupt+0x18/0x22
[ 2991.259950]  [<ffffffff81092746>] ? handle_irq_event_percpu+0x50/0x184
[ 2991.259954]  [<ffffffff8100e28d>] ? paravirt_read_tsc+0x5/0x8
[ 2991.259956]  [<ffffffff810671a7>] ? timekeeping_get_ns+0xd/0x2a
[ 2991.259959]  [<ffffffff810928ae>] ? handle_irq_event+0x34/0x52
[ 2991.259962]  [<ffffffff8109481a>] ? handle_edge_irq+0x9f/0xc6
[ 2991.259965]  [<ffffffff8100a9aa>] ? handle_irq+0x1a/0x20
[ 2991.259967]  [<ffffffff8100a6db>] ? do_IRQ+0x45/0x9e
[ 2991.259970]  [<ffffffff813371d3>] ? common_interrupt+0x13/0x13
[ 2991.259972]  <EOI> 
[ 2991.259979]  [<ffffffffa0172400>] ? arch_local_irq_enable+0x4/0x8 [processor]
[ 2991.259984]  [<ffffffffa0172fcb>] ? acpi_idle_enter_bm+0x218/0x250 [processor]
[ 2991.259988]  [<ffffffff81265ce4>] ? cpuidle_idle_call+0xf5/0x180
[ 2991.259991]  [<ffffffff8100827e>] ? cpu_idle+0xa2/0xc4
[ 2991.259995]  [<ffffffff8169fb65>] ? start_kernel+0x3bd/0x3c8
[ 2991.259997]  [<ffffffff8169f3c6>] ? x86_64_start_kernel+0x102/0x10f
[ 2991.259999] Code: 1f 84 00 00 00 00 00 eb 0e 66 66 66 66 66 2e 0f 1f 84 00 
00 00 00 00 48 ff c8 75 fb 48 ff c8 c3 48 83 ec 08 48 8b 05 7c 13 49 00 
[ 2991.260016]  83 c4 08 ff e0 48 83 ec 08 48 8d 04 bd 00 00 00 00 65 48 8b 
[ 2991.260025] Call Trace:
[ 2991.260026]  <IRQ>  [<ffffffff8101ffa1>] ? 
arch_trigger_all_cpu_backtrace+0x6c/0x7b
[ 2991.260031]  [<ffffffff81096d64>] ? __rcu_pending+0x82/0x2ed
[ 2991.260034]  [<ffffffff8106d090>] ? tick_nohz_handler+0xd0/0xd0
[ 2991.260037]  [<ffffffff81097365>] ? rcu_check_callbacks+0x7e/0xa9
[ 2991.260039]  [<ffffffff81053372>] ? update_process_times+0x31/0x63
[ 2991.260042]  [<ffffffff8106d0fa>] ? tick_sched_timer+0x6a/0x90
[ 2991.260045]  [<ffffffff81062e12>] ? __run_hrtimer+0xaf/0x13a
[ 2991.260047]  [<ffffffff810635a3>] ? hrtimer_interrupt+0xd6/0x19a
[ 2991.260050]  [<ffffffff810671a7>] ? timekeeping_get_ns+0xd/0x2a
[ 2991.260053]  [<ffffffff8106c389>] ? tick_do_broadcast+0x3f/0x83
[ 2991.260056]  [<ffffffff8106c49c>] ? tick_handle_oneshot_broadcast+0xcf/0x103
[ 2991.260059]  [<ffffffff8100afe8>] ? timer_interrupt+0x18/0x22
[ 2991.260061]  [<ffffffff81092746>] ? handle_irq_event_percpu+0x50/0x184
[ 2991.260064]  [<ffffffff8100e28d>] ? paravirt_read_tsc+0x5/0x8
[ 2991.260067]  [<ffffffff810671a7>] ? timekeeping_get_ns+0xd/0x2a
[ 2991.260069]  [<ffffffff810928ae>] ? handle_irq_event+0x34/0x52
[ 2991.260072]  [<ffffffff8109481a>] ? handle_edge_irq+0x9f/0xc6
[ 2991.260075]  [<ffffffff8100a9aa>] ? handle_irq+0x1a/0x20
[ 2991.260077]  [<ffffffff8100a6db>] ? do_IRQ+0x45/0x9e
[ 2991.260080]  [<ffffffff813371d3>] ? common_interrupt+0x13/0x13
[ 2991.260081]  <EOI>  [<ffffffffa0172400>] ? arch_local_irq_enable+0x4/0x8 
[processor]
[ 2991.260090]  [<ffffffffa0172fcb>] ? acpi_idle_enter_bm+0x218/0x250 [processor]
[ 2991.260093]  [<ffffffff81265ce4>] ? cpuidle_idle_call+0xf5/0x180
[ 2991.260095]  [<ffffffff8100827e>] ? cpu_idle+0xa2/0xc4
[ 2991.260098]  [<ffffffff8169fb65>] ? start_kernel+0x3bd/0x3c8
[ 2991.260101]  [<ffffffff8169f3c6>] ? x86_64_start_kernel+0x102/0x10f

--------------