[3.2+] BUG: scheduling while atomic: swapper/0/0/0x10000100

Hi,

I have an issue starting with 3.2 kernel on my Thinkpad x201s. I've reported a bug on kernel bugzilla
(https://bugzilla.kernel.org/show_bug.cgi?id=42615) but I'm not too sure anyone reads it so I'm re-reporting it here. It looks like the same bug as https://bugs.launchpad.net/linux/+bug/917962.

Basically everything is explained in both bugs, but here's a summary. When I first upgraded to the 3.2 linux-image package (the system runs Debian sid amd64), few seconds after the boot is complete I got the following BUG():

Jan 20 11:27:53 scapa kernel: [   63.904544] BUG: scheduling while atomic: swapper/0/0/0x10000100
Jan 20 11:27:53 scapa kernel: [   63.904550] Modules linked in: bnep rfcomm bluetooth deflate zlib_deflate ctr twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common camellia serpent blowfish_generic blowfish_x86_64 blowfish_common nf_conntrack_ipv6 nf_defrag_ipv6 cast5 ip6table_filter ip6_tables des_generic nf_conntrack_ipv4 cbc nf_defrag_ipv4 xt_state xcbc nf_conntrack rmd160 iptable_filter ip_tables x_tables sha512_generic sha256_generic sha1_ssse3 sha1_generic hmac crypto_null af_key ums_realtek usb_storage uas ext2 acpi_cpufreq mperf snd_hda_codec_hdmi snd_hda_codec_conexant arc4 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss iwlwifi snd_pcm mac80211 snd_timer cfg80211 ehci_hcd thinkpad_acpi usbcore e1000e snd psmouse iTCO_wdt soundcore pcspkr rfkill i2c_i801 iTCO_vendor_support snd_page_alloc intel_ips serio_raw ac usb_common nvram battery tpm_tis power_supply tpm tpm_bios wmi evdev processor ext4 mbcache jbd2 crc16 xts gf128mul dm_crypt dm_mod aesni_intel cryptd aes_x86_64 aes
Jan 20 11:27:53 scapa kernel: _generic sd_mod crc_t10dif ahci libahci i915 thermal drm_kms_helper libata scsi_mod drm i2c_algo_bit button i2c_core video thermal_sys
Jan 20 11:27:53 scapa kernel: [   63.904669] CPU 0 
Jan 20 11:27:53 scapa kernel: [   63.904671] Modules linked in: bnep rfcomm bluetooth deflate zlib_deflate ctr twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common camellia serpent blowfish_generic blowfish_x86_64 blowfish_common nf_conntrack_ipv6 nf_defrag_ipv6 cast5 ip6table_filter ip6_tables des_generic nf_conntrack_ipv4 cbc nf_defrag_ipv4 xt_state xcbc nf_conntrack rmd160 iptable_filter ip_tables x_tables sha512_generic sha256_generic sha1_ssse3 sha1_generic hmac crypto_null af_key ums_realtek usb_storage uas ext2 acpi_cpufreq mperf snd_hda_codec_hdmi snd_hda_codec_conexant arc4 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss iwlwifi snd_pcm mac80211 snd_timer cfg80211 ehci_hcd thinkpad_acpi usbcore e1000e snd psmouse iTCO_wdt soundcore pcspkr rfkill i2c_i801 iTCO_vendor_support snd_page_alloc intel_ips serio_raw ac usb_common nvram battery tpm_tis power_supply tpm tpm_bios wmi evdev processor ext4 mbcache jbd2 crc16 xts gf128mul dm_crypt dm_mod aesni_intel cryptd aes_x86_64 aes
Jan 20 11:27:53 scapa kernel: _generic sd_mod crc_t10dif ahci libahci i915 thermal drm_kms_helper libata scsi_mod drm i2c_algo_bit button i2c_core video thermal_sys
Jan 20 11:27:53 scapa kernel: [   63.904752] 
Jan 20 11:27:53 scapa kernel: [   63.904756] Pid: 0, comm: swapper/0 Not tainted 3.2.0-1-amd64 #1 LENOVO 51434JG/51434JG
Jan 20 11:27:53 scapa kernel: [   63.904761] RIP: 0010:[<ffffffff811e36f5>]  [<ffffffff811e36f5>] intel_idle+0xea/0x119
Jan 20 11:27:53 scapa kernel: [   63.904773] RSP: 0018:ffffffff81601e88  EFLAGS: 00000202
Jan 20 11:27:53 scapa kernel: [   63.904776] RAX: 0000000000000000 RBX: ffffffff81023b30 RCX: 0000000000007fda
Jan 20 11:27:53 scapa kernel: [   63.904779] RDX: 0000000000007fda RSI: 0000000000000000 RDI: 00000000000003e8
Jan 20 11:27:53 scapa kernel: [   63.904782] RBP: 0000000000000003 R08: 0000000000007fa9 R09: 0000000000007fa9
Jan 20 11:27:53 scapa kernel: [   63.904785] R10: 0000000000001311 R11: ffffffff8160d020 R12: ffffffff81065de9
Jan 20 11:27:53 scapa kernel: [   63.904788] R13: 000000000000003f R14: ffffffff810659e7 R15: ffffffff8101357e
Jan 20 11:27:53 scapa kernel: [   63.904792] FS:  0000000000000000(0000) GS:ffff880137c00000(0000) knlGS:0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904796] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 20 11:27:53 scapa kernel: [   63.904799] CR2: 00007fc217631aa1 CR3: 0000000001605000 CR4: 00000000000006f0
Jan 20 11:27:53 scapa kernel: [   63.904802] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904805] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 20 11:27:53 scapa kernel: [   63.904809] Process swapper/0 (pid: 0, threadinfo ffffffff81600000, task ffffffff8160d020)
Jan 20 11:27:53 scapa kernel: [   63.904811] Stack:
Jan 20 11:27:53 scapa kernel: [   63.904813]  0000000000000000 0000000000007fda 0000000000000000 0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904819]  0000000000007fda 0000000001f2ae3a ffff880137c19970 ffffffff81645680
Jan 20 11:27:53 scapa kernel: [   63.904824]  00000000fffffff0 0000000000000003 ffffffff81645778 ffffffff812633c3
Jan 20 11:27:53 scapa kernel: [   63.904829] Call Trace:
Jan 20 11:27:53 scapa kernel: [   63.904839]  [<ffffffff812633c3>] ? cpuidle_idle_call+0xec/0x179
Jan 20 11:27:53 scapa kernel: [   63.904846]  [<ffffffff8100d255>] ? cpu_idle+0xa1/0xe8
Jan 20 11:27:53 scapa kernel: [   63.904852]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Jan 20 11:27:53 scapa kernel: [   63.904857]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Jan 20 11:27:53 scapa kernel: [   63.904861]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111
Jan 20 11:27:53 scapa kernel: [   63.904864] Code: 29 f0 48 89 c7 e8 77 77 e6 ff 4c 69 e8 40 42 0f 00 48 89 04 24 48 89 54 24 08 48 89 44 24 18 48 89 54 24 20 49 01 d5 fb 66 66 90 <66> 66 90 85 1d ea 21 46 00 75 0f 48 8d 74 24 2c bf 05 00 00 00 
Jan 20 11:27:53 scapa kernel: [   63.904905] Call Trace:
Jan 20 11:27:53 scapa kernel: [   63.904910]  [<ffffffff812633c3>] ? cpuidle_idle_call+0xec/0x179
Jan 20 11:27:53 scapa kernel: [   63.904914]  [<ffffffff8100d255>] ? cpu_idle+0xa1/0xe8
Jan 20 11:27:53 scapa kernel: [   63.904918]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Jan 20 11:27:53 scapa kernel: [   63.904922]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Jan 20 11:27:53 scapa kernel: [   63.904926]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111

I successfully reproduced using vanilla kernel, so I started bisecting. I did two bisect rounds (complete log on the bug reports) and found the first bad commit to be:

a2c76b83fdd763c826f38a55127ccf25708099ce is the first bad commit commit a2c76b83fdd763c826f38a55127ccf25708099ce
Author: Kuninori Morimoto <[email protected]>
Date: Tue Oct 18 20:05:50 2011 -0700

usb: renesas_usbhs: fixup inconsistent return from usbhs_pkt_push()

usbhs_pkt_push() had inconsistent return under spin lock. This patch fix it up.
Special thanks to Dan

Cc Dan Carpenter <[email protected]>

Signed-off-by Kuninori Morimoto <[email protected]>

Signed-off-by Greg Kroah-Hartman <[email protected]>

:040000 040000 08d80fa06121151b36ae17dc693c14d58c0d5db3
86b920618ceb575cebf610798c24a104dea36a2c M drivers

Reverting this commit on top of 3.2.1 removes the BUG().

Very odd, it wouldn't seem that this patch would cause such a problem, as it is "obviously" correct.

Kuninori, any thoughts about this? Should I revert this from the tree?

Quoted 8 lines · Yves-Alexis Perez

Hi,

I have an issue starting with 3.2 kernel on my Thinkpad x201s. I've reported a bug on kernel bugzilla
(https://bugzilla.kernel.org/show_bug.cgi?id=42615) but I'm not too sure anyone reads it so I'm re-reporting it here. It looks like the same bug as https://bugs.launchpad.net/linux/+bug/917962.

Quoted 7 lines

Basically everything is explained in both bugs, but here's a summary. When I first upgraded to the 3.2 linux-image package (the system runs Debian sid amd64), few seconds after the boot is complete I got the following BUG():

Jan 20 11:27:53 scapa kernel: [   63.904544] BUG: scheduling while atomic: swapper/0/0/0x10000100
Jan 20 11:27:53 scapa kernel: [   63.904550] Modules linked in: bnep rfcomm bluetooth deflate zlib_deflate ctr twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common camellia serpent blowfish_generic blowfish_x86_64 blowfish_common nf_conntrack_ipv6 nf_defrag_ipv6 cast5 ip6table_filter ip6_tables des_generic nf_conntrack_ipv4 cbc nf_defrag_ipv4 xt_state xcbc nf_conntrack rmd160 iptable_filter ip_tables x_tables sha512_generic sha256_generic sha1_ssse3 sha1_generic hmac crypto_null af_key ums_realtek usb_storage uas ext2 acpi_cpufreq mperf snd_hda_codec_hdmi snd_hda_codec_conexant arc4 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss iwlwifi snd_pcm mac80211 snd_timer cfg80211 ehci_hcd thinkpad_acpi usbcore e1000e snd psmouse iTCO_wdt soundcore pcspkr rfkill i2c_i801 iTCO_vendor_support snd_page_alloc intel_ips serio_raw ac usb_common nvram battery tpm_tis power_supply tpm tpm_bios wmi evdev processor ext4 mbcache jbd2 crc16 xts gf128mul dm_crypt d!

m_mod aesni_intel cryptd aes_x86_64 aes

Quoted 3 lines

Jan 20 11:27:53 scapa kernel: _generic sd_mod crc_t10dif ahci libahci i915 thermal drm_kms_helper libata scsi_mod drm i2c_algo_bit button i2c_core video thermal_sys
Jan 20 11:27:53 scapa kernel: [   63.904669] CPU 0 
Jan 20 11:27:53 scapa kernel: [   63.904671] Modules linked in: bnep rfcomm bluetooth deflate zlib_deflate ctr twofish_generic twofish_x86_64_3way twofish_x86_64 twofish_common camellia serpent blowfish_generic blowfish_x86_64 blowfish_common nf_conntrack_ipv6 nf_defrag_ipv6 cast5 ip6table_filter ip6_tables des_generic nf_conntrack_ipv4 cbc nf_defrag_ipv4 xt_state xcbc nf_conntrack rmd160 iptable_filter ip_tables x_tables sha512_generic sha256_generic sha1_ssse3 sha1_generic hmac crypto_null af_key ums_realtek usb_storage uas ext2 acpi_cpufreq mperf snd_hda_codec_hdmi snd_hda_codec_conexant arc4 snd_hda_intel snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss iwlwifi snd_pcm mac80211 snd_timer cfg80211 ehci_hcd thinkpad_acpi usbcore e1000e snd psmouse iTCO_wdt soundcore pcspkr rfkill i2c_i801 iTCO_vendor_support snd_page_alloc intel_ips serio_raw ac usb_common nvram battery tpm_tis power_supply tpm tpm_bios wmi evdev processor ext4 mbcache jbd2 crc16 xts gf128mul dm_crypt d!

m_mod aesni_intel cryptd aes_x86_64 aes

Quoted 53 lines

Jan 20 11:27:53 scapa kernel: _generic sd_mod crc_t10dif ahci libahci i915 thermal drm_kms_helper libata scsi_mod drm i2c_algo_bit button i2c_core video thermal_sys
Jan 20 11:27:53 scapa kernel: [   63.904752] 
Jan 20 11:27:53 scapa kernel: [   63.904756] Pid: 0, comm: swapper/0 Not tainted 3.2.0-1-amd64 #1 LENOVO 51434JG/51434JG
Jan 20 11:27:53 scapa kernel: [   63.904761] RIP: 0010:[<ffffffff811e36f5>]  [<ffffffff811e36f5>] intel_idle+0xea/0x119
Jan 20 11:27:53 scapa kernel: [   63.904773] RSP: 0018:ffffffff81601e88  EFLAGS: 00000202
Jan 20 11:27:53 scapa kernel: [   63.904776] RAX: 0000000000000000 RBX: ffffffff81023b30 RCX: 0000000000007fda
Jan 20 11:27:53 scapa kernel: [   63.904779] RDX: 0000000000007fda RSI: 0000000000000000 RDI: 00000000000003e8
Jan 20 11:27:53 scapa kernel: [   63.904782] RBP: 0000000000000003 R08: 0000000000007fa9 R09: 0000000000007fa9
Jan 20 11:27:53 scapa kernel: [   63.904785] R10: 0000000000001311 R11: ffffffff8160d020 R12: ffffffff81065de9
Jan 20 11:27:53 scapa kernel: [   63.904788] R13: 000000000000003f R14: ffffffff810659e7 R15: ffffffff8101357e
Jan 20 11:27:53 scapa kernel: [   63.904792] FS:  0000000000000000(0000) GS:ffff880137c00000(0000) knlGS:0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904796] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 20 11:27:53 scapa kernel: [   63.904799] CR2: 00007fc217631aa1 CR3: 0000000001605000 CR4: 00000000000006f0
Jan 20 11:27:53 scapa kernel: [   63.904802] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904805] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 20 11:27:53 scapa kernel: [   63.904809] Process swapper/0 (pid: 0, threadinfo ffffffff81600000, task ffffffff8160d020)
Jan 20 11:27:53 scapa kernel: [   63.904811] Stack:
Jan 20 11:27:53 scapa kernel: [   63.904813]  0000000000000000 0000000000007fda 0000000000000000 0000000000000000
Jan 20 11:27:53 scapa kernel: [   63.904819]  0000000000007fda 0000000001f2ae3a ffff880137c19970 ffffffff81645680
Jan 20 11:27:53 scapa kernel: [   63.904824]  00000000fffffff0 0000000000000003 ffffffff81645778 ffffffff812633c3
Jan 20 11:27:53 scapa kernel: [   63.904829] Call Trace:
Jan 20 11:27:53 scapa kernel: [   63.904839]  [<ffffffff812633c3>] ? cpuidle_idle_call+0xec/0x179
Jan 20 11:27:53 scapa kernel: [   63.904846]  [<ffffffff8100d255>] ? cpu_idle+0xa1/0xe8
Jan 20 11:27:53 scapa kernel: [   63.904852]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Jan 20 11:27:53 scapa kernel: [   63.904857]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Jan 20 11:27:53 scapa kernel: [   63.904861]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111
Jan 20 11:27:53 scapa kernel: [   63.904864] Code: 29 f0 48 89 c7 e8 77 77 e6 ff 4c 69 e8 40 42 0f 00 48 89 04 24 48 89 54 24 08 48 89 44 24 18 48 89 54 24 20 49 01 d5 fb 66 66 90 <66> 66 90 85 1d ea 21 46 00 75 0f 48 8d 74 24 2c bf 05 00 00 00 
Jan 20 11:27:53 scapa kernel: [   63.904905] Call Trace:
Jan 20 11:27:53 scapa kernel: [   63.904910]  [<ffffffff812633c3>] ? cpuidle_idle_call+0xec/0x179
Jan 20 11:27:53 scapa kernel: [   63.904914]  [<ffffffff8100d255>] ? cpu_idle+0xa1/0xe8
Jan 20 11:27:53 scapa kernel: [   63.904918]  [<ffffffff816a9b3d>] ? start_kernel+0x3bd/0x3c8
Jan 20 11:27:53 scapa kernel: [   63.904922]  [<ffffffff816a9140>] ? early_idt_handlers+0x140/0x140
Jan 20 11:27:53 scapa kernel: [   63.904926]  [<ffffffff816a93c4>] ? x86_64_start_kernel+0x104/0x111

I successfully reproduced using vanilla kernel, so I started bisecting. I did two bisect rounds (complete log on the bug reports) and found the first bad commit to be:

a2c76b83fdd763c826f38a55127ccf25708099ce is the first bad commit commit a2c76b83fdd763c826f38a55127ccf25708099ce
Author: Kuninori Morimoto <[email protected]>
Date: Tue Oct 18 20:05:50 2011 -0700

usb: renesas_usbhs: fixup inconsistent return from usbhs_pkt_push()

usbhs_pkt_push() had inconsistent return under spin lock. This patch fix it up.
Special thanks to Dan

Cc Dan Carpenter <[email protected]>

Signed-off-by Kuninori Morimoto <[email protected]>

Signed-off-by Greg Kroah-Hartman <[email protected]>

Quoted 4 lines

:040000 040000 08d80fa06121151b36ae17dc693c14d58c0d5db3
86b920618ceb575cebf610798c24a104dea36a2c M drivers

Reverting this commit on top of 3.2.1 removes the BUG().

Very odd, it wouldn't seem that this patch would cause such a problem, as it is "obviously" correct.

Kuninori, any thoughts about this? Should I revert this from the tree?

Quoted 2 lines

Very odd, it wouldn't seem that this patch would cause such a problem, as it is "obviously" correct.

The funny thing is that I don't think there's any x86 system out there with this *DRD* controller :-)

Specially when you consider the fact that
it's very recently that we dropped the ARCH dependency with commit d242c110c43b55aaf3ebb3ceac1eeab0d452a177

Quoted 2 lines

Kuninori, any thoughts about this? Should I revert this from the tree?

I don't think so, I think this was a bad bisection.

Quoted 5 lines · Felipe Balbi

Quoted 2 lines

Very odd, it wouldn't seem that this patch would cause such a problem, as it is "obviously" correct.

The funny thing is that I don't think there's any x86 system out there with this *DRD* controller :-)

Out of curiosity, what is a DRD controler?

Quoted 7 lines

Specially when you consider the fact that
it's very recently that we dropped the ARCH dependency with commit d242c110c43b55aaf3ebb3ceac1eeab0d452a177

Quoted 2 lines

Kuninori, any thoughts about this? Should I revert this from the tree?

Quoted 2 lines

I don't think so, I think this was a bad bisection.

Maybe (especially since the first bad commit is a merge commit, so I'm not completely sure I did correctly the second bisect). But I'm puzzled why reverting the commit on top of 3.2.1 fixes that. And now that Felipe mentions it, USB Gadget is not even compiled, so I'm completely lost.

Quoted 7 lines

Quoted 7 lines

Specially when you consider the fact that
it's very recently that we dropped the ARCH dependency with commit d242c110c43b55aaf3ebb3ceac1eeab0d452a177

Quoted 2 lines

Kuninori, any thoughts about this? Should I revert this from the tree?

Quoted 6 lines

Quoted 2 lines

I don't think so, I think this was a bad bisection.

Maybe (especially since the first bad commit is a merge commit, so I'm not completely sure I did correctly the second bisect). But I'm puzzled why reverting the commit on top of 3.2.1 fixes that. And now that Felipe mentions it, USB Gadget is not even compiled, so I'm completely lost.

Hehehe :-) That's fun... Maybe it's some other instability and it just didn't kick when you reverted that commit. It could be that the problem is somewhere completely different and you just didn't fully debug it yet :-)

I was very much surprised at this issue.
As Felipe explained, renesas_usbhs was for SuperH system. x86 can not use it,
but, if your PC has "renesas_usbhs.ko" as kernel module, and loaded it somehow...

Hi All

Quoted 14 lines

Quoted 7 lines

Quoted 7 lines

Specially when you consider the fact that
it's very recently that we dropped the ARCH dependency with commit d242c110c43b55aaf3ebb3ceac1eeab0d452a177

Quoted 2 lines

Kuninori, any thoughts about this? Should I revert this from the tree?

Quoted 6 lines

Quoted 2 lines

I don't think so, I think this was a bad bisection.

Maybe (especially since the first bad commit is a merge commit, so I'm not completely sure I did correctly the second bisect). But I'm puzzled why reverting the commit on top of 3.2.1 fixes that. And now that Felipe mentions it, USB Gadget is not even compiled, so I'm completely lost.

Quoted 4 lines

Hehehe :-) That's fun... Maybe it's some other instability and it just didn't kick when you reverted that commit. It could be that the problem is somewhere completely different and you just didn't fully debug it yet :-)

I was very much surprised at this issue.
As Felipe explained, renesas_usbhs was for SuperH system. x86 can not use it,
but, if your PC has "renesas_usbhs.ko" as kernel module, and loaded it somehow...