Bug 56781

Summary: BUG: scheduling while atomic: modprobe/256/0x00000100
Product: Other Reporter: kenzopl
Component: ModulesAssignee: other_modules
Status: RESOLVED PATCH_ALREADY_AVAILABLE    
Severity: high CC: aaron.lu, airlied
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 3.8.6, 3.8.7, 3.8.8 Subsystem:
Regression: No Bisected commit-id:
Attachments: kern.log
Make ata_port_acpi_handle does not block
Make ata_port_acpi_handle does not block

Description kenzopl 2013-04-18 05:42:32 UTC
Created attachment 99151 [details]
kern.log

Please be gently as this is my first bug report here.

This issue is repeating since kernel version 3.8.6 up to 3.8.8 (current stable) and since I haven't found any solution I decided to post it here because it became really annoying. It maybe related to my Radeon card or my DVB USB adapter. It happens randomly while booting (kernel panic), sometimes I need to reboot my system for several times until it boots up properly, unfortunatelly I do not have any other log files, only pictures taken by camera. Please let me know if you need more information.


kernel: [    4.633786] BUG: scheduling while atomic: modprobe/256/0x00000100
kernel: [    4.633852] Modules linked in: wmi(+) ttm drm_kms_helper drm forcedeth(+) i2c_algo_bit
kernel: [    4.633861] Pid: 256, comm: modprobe Not tainted 3.8.6 #1
kernel: [    4.633863] Call Trace:
kernel: [    4.633865]  <IRQ>  [<ffffffff81752bc9>] __schedule_bug+0x4d/0x59
kernel: [    4.633881]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
kernel: [    4.633884]  [<ffffffff8175e4c9>] schedule+0x29/0x70
kernel: [    4.633886]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
kernel: [    4.633892]  [<ffffffff8108d6f5>] ? check_preempt_curr+0x85/0xa0
kernel: [    4.633894]  [<ffffffff8108d73c>] ? ttwu_do_wakeup+0x2c/0xf0
kernel: [    4.633897]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
kernel: [    4.633899]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
kernel: [    4.633904]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
kernel: [    4.633908]  [<ffffffff813d2181>] acpi_os_wait_semaphore+0x49/0x5f
kernel: [    4.633913]  [<ffffffff813f880e>] acpi_ut_acquire_mutex+0x51/0x93
kernel: [    4.633917]  [<ffffffff813eae40>] acpi_ex_enter_interpreter+0x10/0x30
kernel: [    4.633922]  [<ffffffff813f0037>] acpi_evaluate_object+0x1f5/0x233
kernel: [    4.633927]  [<ffffffff814dd157>] ata_acpi_stm+0x97/0xe0
kernel: [    4.633930]  [<ffffffff814e07b1>] pacpi_set_piomode+0x51/0x70
kernel: [    4.633932]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
kernel: [    4.633936]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
kernel: [    4.633940]  [<ffffffff814cd470>] ? ata_scsi_set_sense.constprop.24+0x30/0x30
kernel: [    4.633942]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
kernel: [    4.633945]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
kernel: [    4.633949]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
kernel: [    4.633953]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
kernel: [    4.633956]  [<ffffffff81768b1d>] ? call_function_single_interrupt+0x6d/0x80
kernel: [    4.633960]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
kernel: [    4.633963]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
kernel: [    4.633966]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
kernel: [    4.633969]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
kernel: [    4.633971]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
kernel: [    4.633974]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
kernel: [    4.633977]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
kernel: [    4.633981]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
kernel: [    4.633984]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
kernel: [    4.633989]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
kernel: [    4.633991]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
kernel: [    4.633996]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
kernel: [    4.633999]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
kernel: [    4.634002]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
kernel: [    4.634005]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
kernel: [    4.634006]  <EOI>  [<ffffffff817633f4>] ? __do_page_fault+0x264/0x4e0
kernel: [    4.634011]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
kernel: [    4.634014]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
kernel: [    4.634019]  [<ffffffff811ab116>] ? mntput+0x26/0x40
kernel: [    4.634023]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
kernel: [    4.634026]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
kernel: [    4.634031]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
kernel: [    4.634034]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
kernel: [    4.634037]  [<ffffffff8175fc98>] page_fault+0x28/0x30
kernel: [    4.640098] BUG: scheduling while atomic: modprobe/256/0x00000100
kernel: [    4.640167] Modules linked in: wmi(+) ttm drm_kms_helper drm forcedeth(+) i2c_algo_bit
kernel: [    4.640179] Pid: 256, comm: modprobe Tainted: G        W    3.8.6 #1
kernel: [    4.640181] Call Trace:
kernel: [    4.640183]  <IRQ>  [<ffffffff81752bc9>] __schedule_bug+0x4d/0x59
kernel: [    4.640201]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
kernel: [    4.640204]  [<ffffffff8175e4c9>] schedule+0x29/0x70
kernel: [    4.640206]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
kernel: [    4.640212]  [<ffffffff813ef0ee>] ? acpi_ns_search_one_scope+0x22/0x45
kernel: [    4.640215]  [<ffffffff813ef19c>] ? acpi_ns_search_and_enter+0x8b/0x147
kernel: [    4.640217]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
kernel: [    4.640220]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
kernel: [    4.640225]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
kernel: [    4.640229]  [<ffffffff813d2181>] acpi_os_wait_semaphore+0x49/0x5f
kernel: [    4.640233]  [<ffffffff813f880e>] acpi_ut_acquire_mutex+0x51/0x93
kernel: [    4.640236]  [<ffffffff813eae40>] acpi_ex_enter_interpreter+0x10/0x30
kernel: [    4.640239]  [<ffffffff813ed28d>] acpi_ns_evaluate+0x13d/0x1ad
kernel: [    4.640242]  [<ffffffff813eff69>] acpi_evaluate_object+0x127/0x233
kernel: [    4.640245]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
kernel: [    4.640248]  [<ffffffff813d25aa>] acpi_evaluate_integer+0x34/0x53
kernel: [    4.640250]  [<ffffffff813d4d96>] do_acpi_find_child+0x2d/0x52
kernel: [    4.640253]  [<ffffffff813ef970>] acpi_ns_walk_namespace+0xd5/0x179
kernel: [    4.640256]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
kernel: [    4.640258]  [<ffffffff813efe0f>] acpi_walk_namespace+0x98/0xcb
kernel: [    4.640261]  [<ffffffff813d4d5f>] acpi_get_child+0x45/0x4f
kernel: [    4.640266]  [<ffffffff814dceeb>] ata_ap_acpi_handle+0x2b/0x30
kernel: [    4.640268]  [<ffffffff814dd1cb>] ata_acpi_gtm+0x2b/0x100
kernel: [    4.640271]  [<ffffffff814e07bc>] pacpi_set_piomode+0x5c/0x70
kernel: [    4.640274]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
kernel: [    4.640278]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
kernel: [    4.640282]  [<ffffffff814cd470>] ? ata_scsi_set_sense.constprop.24+0x30/0x30
kernel: [    4.640285]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
kernel: [    4.640287]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
kernel: [    4.640291]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
kernel: [    4.640294]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
kernel: [    4.640298]  [<ffffffff81768b1d>] ? call_function_single_interrupt+0x6d/0x80
kernel: [    4.640302]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
kernel: [    4.640304]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
kernel: [    4.640310]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
kernel: [    4.640314]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
kernel: [    4.640316]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
kernel: [    4.640319]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
kernel: [    4.640322]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
kernel: [    4.640328]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
kernel: [    4.640333]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
kernel: [    4.640338]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
kernel: [    4.640340]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
kernel: [    4.640349]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
kernel: [    4.640352]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
kernel: [    4.640355]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
kernel: [    4.640358]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
kernel: [    4.640360]  <EOI>  [<ffffffff817633f4>] ? __do_page_fault+0x264/0x4e0
kernel: [    4.640366]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
kernel: [    4.640369]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
kernel: [    4.640374]  [<ffffffff811ab116>] ? mntput+0x26/0x40
kernel: [    4.640378]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
kernel: [    4.640381]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
kernel: [    4.640385]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
kernel: [    4.640388]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
kernel: [    4.640390]  [<ffffffff8175fc98>] page_fault+0x28/0x30
Comment 1 Rusty Russell 2013-04-18 06:53:52 UTC
Tejun, you touched it last?

Cheers,
Rusty.

bugzilla-daemon@bugzilla.kernel.org writes:
> https://bugzilla.kernel.org/show_bug.cgi?id=56781
>
>            Summary: BUG: scheduling while atomic: modprobe/256/0x00000100
>            Product: Other
>            Version: 2.5
>     Kernel Version: 3.8.6, 3.8.7, 3.8.8
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: high
>           Priority: P1
>          Component: Modules
>         AssignedTo: other_modules@kernel-bugs.osdl.org
>         ReportedBy: kenzopl@o2.pl
>                 CC: airlied@linux.ie
>         Regression: No
>
>
> Created an attachment (id=99151)
>  --> (https://bugzilla.kernel.org/attachment.cgi?id=99151)
> kern.log
>
> Please be gently as this is my first bug report here.
>
> This issue is repeating since kernel version 3.8.6 up to 3.8.8 (current
> stable)
> and since I haven't found any solution I decided to post it here because it
> became really annoying. It maybe related to my Radeon card or my DVB USB
> adapter. It happens randomly while booting (kernel panic), sometimes I need
> to
> reboot my system for several times until it boots up properly, unfortunatelly
> I
> do not have any other log files, only pictures taken by camera. Please let me
> know if you need more information.
>
>
> kernel: [    4.633786] BUG: scheduling while atomic: modprobe/256/0x00000100
> kernel: [    4.633852] Modules linked in: wmi(+) ttm drm_kms_helper drm
> forcedeth(+) i2c_algo_bit
> kernel: [    4.633861] Pid: 256, comm: modprobe Not tainted 3.8.6 #1
> kernel: [    4.633863] Call Trace:
> kernel: [    4.633865]  <IRQ>  [<ffffffff81752bc9>] __schedule_bug+0x4d/0x59
> kernel: [    4.633881]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
> kernel: [    4.633884]  [<ffffffff8175e4c9>] schedule+0x29/0x70
> kernel: [    4.633886]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
> kernel: [    4.633892]  [<ffffffff8108d6f5>] ? check_preempt_curr+0x85/0xa0
> kernel: [    4.633894]  [<ffffffff8108d73c>] ? ttwu_do_wakeup+0x2c/0xf0
> kernel: [    4.633897]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
> kernel: [    4.633899]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
> kernel: [    4.633904]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
> kernel: [    4.633908]  [<ffffffff813d2181>] acpi_os_wait_semaphore+0x49/0x5f
> kernel: [    4.633913]  [<ffffffff813f880e>] acpi_ut_acquire_mutex+0x51/0x93
> kernel: [    4.633917]  [<ffffffff813eae40>]
> acpi_ex_enter_interpreter+0x10/0x30
> kernel: [    4.633922]  [<ffffffff813f0037>] acpi_evaluate_object+0x1f5/0x233
> kernel: [    4.633927]  [<ffffffff814dd157>] ata_acpi_stm+0x97/0xe0
> kernel: [    4.633930]  [<ffffffff814e07b1>] pacpi_set_piomode+0x51/0x70
> kernel: [    4.633932]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
> kernel: [    4.633936]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
> kernel: [    4.633940]  [<ffffffff814cd470>] ?
> ata_scsi_set_sense.constprop.24+0x30/0x30
> kernel: [    4.633942]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
> kernel: [    4.633945]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
> kernel: [    4.633949]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
> kernel: [    4.633953]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
> kernel: [    4.633956]  [<ffffffff81768b1d>] ?
> call_function_single_interrupt+0x6d/0x80
> kernel: [    4.633960]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
> kernel: [    4.633963]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
> kernel: [    4.633966]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
> kernel: [    4.633969]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
> kernel: [    4.633971]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
> kernel: [    4.633974]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
> kernel: [    4.633977]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
> kernel: [    4.633981]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
> kernel: [    4.633984]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
> kernel: [    4.633989]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
> kernel: [    4.633991]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
> kernel: [    4.633996]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
> kernel: [    4.633999]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
> kernel: [    4.634002]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
> kernel: [    4.634005]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
> kernel: [    4.634006]  <EOI>  [<ffffffff817633f4>] ?
> __do_page_fault+0x264/0x4e0
> kernel: [    4.634011]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
> kernel: [    4.634014]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
> kernel: [    4.634019]  [<ffffffff811ab116>] ? mntput+0x26/0x40
> kernel: [    4.634023]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
> kernel: [    4.634026]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
> kernel: [    4.634031]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
> kernel: [    4.634034]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
> kernel: [    4.634037]  [<ffffffff8175fc98>] page_fault+0x28/0x30
> kernel: [    4.640098] BUG: scheduling while atomic: modprobe/256/0x00000100
> kernel: [    4.640167] Modules linked in: wmi(+) ttm drm_kms_helper drm
> forcedeth(+) i2c_algo_bit
> kernel: [    4.640179] Pid: 256, comm: modprobe Tainted: G        W    3.8.6
> #1
> kernel: [    4.640181] Call Trace:
> kernel: [    4.640183]  <IRQ>  [<ffffffff81752bc9>] __schedule_bug+0x4d/0x59
> kernel: [    4.640201]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
> kernel: [    4.640204]  [<ffffffff8175e4c9>] schedule+0x29/0x70
> kernel: [    4.640206]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
> kernel: [    4.640212]  [<ffffffff813ef0ee>] ?
> acpi_ns_search_one_scope+0x22/0x45
> kernel: [    4.640215]  [<ffffffff813ef19c>] ?
> acpi_ns_search_and_enter+0x8b/0x147
> kernel: [    4.640217]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
> kernel: [    4.640220]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
> kernel: [    4.640225]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
> kernel: [    4.640229]  [<ffffffff813d2181>] acpi_os_wait_semaphore+0x49/0x5f
> kernel: [    4.640233]  [<ffffffff813f880e>] acpi_ut_acquire_mutex+0x51/0x93
> kernel: [    4.640236]  [<ffffffff813eae40>]
> acpi_ex_enter_interpreter+0x10/0x30
> kernel: [    4.640239]  [<ffffffff813ed28d>] acpi_ns_evaluate+0x13d/0x1ad
> kernel: [    4.640242]  [<ffffffff813eff69>] acpi_evaluate_object+0x127/0x233
> kernel: [    4.640245]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
> kernel: [    4.640248]  [<ffffffff813d25aa>] acpi_evaluate_integer+0x34/0x53
> kernel: [    4.640250]  [<ffffffff813d4d96>] do_acpi_find_child+0x2d/0x52
> kernel: [    4.640253]  [<ffffffff813ef970>]
> acpi_ns_walk_namespace+0xd5/0x179
> kernel: [    4.640256]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
> kernel: [    4.640258]  [<ffffffff813efe0f>] acpi_walk_namespace+0x98/0xcb
> kernel: [    4.640261]  [<ffffffff813d4d5f>] acpi_get_child+0x45/0x4f
> kernel: [    4.640266]  [<ffffffff814dceeb>] ata_ap_acpi_handle+0x2b/0x30
> kernel: [    4.640268]  [<ffffffff814dd1cb>] ata_acpi_gtm+0x2b/0x100
> kernel: [    4.640271]  [<ffffffff814e07bc>] pacpi_set_piomode+0x5c/0x70
> kernel: [    4.640274]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
> kernel: [    4.640278]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
> kernel: [    4.640282]  [<ffffffff814cd470>] ?
> ata_scsi_set_sense.constprop.24+0x30/0x30
> kernel: [    4.640285]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
> kernel: [    4.640287]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
> kernel: [    4.640291]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
> kernel: [    4.640294]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
> kernel: [    4.640298]  [<ffffffff81768b1d>] ?
> call_function_single_interrupt+0x6d/0x80
> kernel: [    4.640302]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
> kernel: [    4.640304]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
> kernel: [    4.640310]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
> kernel: [    4.640314]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
> kernel: [    4.640316]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
> kernel: [    4.640319]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
> kernel: [    4.640322]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
> kernel: [    4.640328]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
> kernel: [    4.640333]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
> kernel: [    4.640338]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
> kernel: [    4.640340]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
> kernel: [    4.640349]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
> kernel: [    4.640352]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
> kernel: [    4.640355]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
> kernel: [    4.640358]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
> kernel: [    4.640360]  <EOI>  [<ffffffff817633f4>] ?
> __do_page_fault+0x264/0x4e0
> kernel: [    4.640366]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
> kernel: [    4.640369]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
> kernel: [    4.640374]  [<ffffffff811ab116>] ? mntput+0x26/0x40
> kernel: [    4.640378]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
> kernel: [    4.640381]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
> kernel: [    4.640385]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
> kernel: [    4.640388]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
> kernel: [    4.640390]  [<ffffffff8175fc98>] page_fault+0x28/0x30
>
> -- 
> Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
> ------- You are receiving this mail because: -------
> You are watching the assignee of the bug.
Comment 2 Tejun Heo 2013-04-18 18:32:14 UTC
Hello,

(cc'ing Jeff, linux-ide and copying the whole message)

So, the problem seems to be inside pata_acpi driver.  It's calling
pacpi_set_piomode() from qc_issue path while holding the queue lock.
pacpi_set_piomode() calls into acpi which may sleep.  It gets blocked
on a semaphore and triggers the bug.  Maybe some changes between 3.8.6
and 3.8.8 made it more likely to trigger but fundamentally it's a bug
in the pata_acpi driver.  It can't directly call into acpi while
holding queue lock.

Thanks.

On Thu, Apr 18, 2013 at 03:55:54PM +0930, Rusty Russell wrote:
> Tejun, you touched it last?
> 
> Cheers,
> Rusty.
> 
> bugzilla-daemon@bugzilla.kernel.org writes:
> > https://bugzilla.kernel.org/show_bug.cgi?id=56781
> >
> >            Summary: BUG: scheduling while atomic: modprobe/256/0x00000100
> >            Product: Other
> >            Version: 2.5
> >     Kernel Version: 3.8.6, 3.8.7, 3.8.8
> >           Platform: All
> >         OS/Version: Linux
> >               Tree: Mainline
> >             Status: NEW
> >           Severity: high
> >           Priority: P1
> >          Component: Modules
> >         AssignedTo: other_modules@kernel-bugs.osdl.org
> >         ReportedBy: kenzopl@o2.pl
> >                 CC: airlied@linux.ie
> >         Regression: No
> >
> >
> > Created an attachment (id=99151)
> >  --> (https://bugzilla.kernel.org/attachment.cgi?id=99151)
> > kern.log
> >
> > Please be gently as this is my first bug report here.
> >
> > This issue is repeating since kernel version 3.8.6 up to 3.8.8 (current
> stable)
> > and since I haven't found any solution I decided to post it here because it
> > became really annoying. It maybe related to my Radeon card or my DVB USB
> > adapter. It happens randomly while booting (kernel panic), sometimes I need
> to
> > reboot my system for several times until it boots up properly,
> unfortunatelly I
> > do not have any other log files, only pictures taken by camera. Please let
> me
> > know if you need more information.
> >
> >
> > kernel: [    4.633786] BUG: scheduling while atomic:
> modprobe/256/0x00000100
> > kernel: [    4.633852] Modules linked in: wmi(+) ttm drm_kms_helper drm
> > forcedeth(+) i2c_algo_bit
> > kernel: [    4.633861] Pid: 256, comm: modprobe Not tainted 3.8.6 #1
> > kernel: [    4.633863] Call Trace:
> > kernel: [    4.633865]  <IRQ>  [<ffffffff81752bc9>]
> __schedule_bug+0x4d/0x59
> > kernel: [    4.633881]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
> > kernel: [    4.633884]  [<ffffffff8175e4c9>] schedule+0x29/0x70
> > kernel: [    4.633886]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
> > kernel: [    4.633892]  [<ffffffff8108d6f5>] ? check_preempt_curr+0x85/0xa0
> > kernel: [    4.633894]  [<ffffffff8108d73c>] ? ttwu_do_wakeup+0x2c/0xf0
> > kernel: [    4.633897]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
> > kernel: [    4.633899]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
> > kernel: [    4.633904]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
> > kernel: [    4.633908]  [<ffffffff813d2181>]
> acpi_os_wait_semaphore+0x49/0x5f
> > kernel: [    4.633913]  [<ffffffff813f880e>]
> acpi_ut_acquire_mutex+0x51/0x93
> > kernel: [    4.633917]  [<ffffffff813eae40>]
> > acpi_ex_enter_interpreter+0x10/0x30
> > kernel: [    4.633922]  [<ffffffff813f0037>]
> acpi_evaluate_object+0x1f5/0x233
> > kernel: [    4.633927]  [<ffffffff814dd157>] ata_acpi_stm+0x97/0xe0
> > kernel: [    4.633930]  [<ffffffff814e07b1>] pacpi_set_piomode+0x51/0x70
> > kernel: [    4.633932]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
> > kernel: [    4.633936]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
> > kernel: [    4.633940]  [<ffffffff814cd470>] ?
> > ata_scsi_set_sense.constprop.24+0x30/0x30
> > kernel: [    4.633942]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
> > kernel: [    4.633945]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
> > kernel: [    4.633949]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
> > kernel: [    4.633953]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
> > kernel: [    4.633956]  [<ffffffff81768b1d>] ?
> > call_function_single_interrupt+0x6d/0x80
> > kernel: [    4.633960]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
> > kernel: [    4.633963]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
> > kernel: [    4.633966]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
> > kernel: [    4.633969]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
> > kernel: [    4.633971]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
> > kernel: [    4.633974]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
> > kernel: [    4.633977]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
> > kernel: [    4.633981]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
> > kernel: [    4.633984]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
> > kernel: [    4.633989]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
> > kernel: [    4.633991]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
> > kernel: [    4.633996]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
> > kernel: [    4.633999]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
> > kernel: [    4.634002]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
> > kernel: [    4.634005]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
> > kernel: [    4.634006]  <EOI>  [<ffffffff817633f4>] ?
> > __do_page_fault+0x264/0x4e0
> > kernel: [    4.634011]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
> > kernel: [    4.634014]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
> > kernel: [    4.634019]  [<ffffffff811ab116>] ? mntput+0x26/0x40
> > kernel: [    4.634023]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
> > kernel: [    4.634026]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
> > kernel: [    4.634031]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
> > kernel: [    4.634034]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
> > kernel: [    4.634037]  [<ffffffff8175fc98>] page_fault+0x28/0x30
> > kernel: [    4.640098] BUG: scheduling while atomic:
> modprobe/256/0x00000100
> > kernel: [    4.640167] Modules linked in: wmi(+) ttm drm_kms_helper drm
> > forcedeth(+) i2c_algo_bit
> > kernel: [    4.640179] Pid: 256, comm: modprobe Tainted: G        W   
> 3.8.6 #1
> > kernel: [    4.640181] Call Trace:
> > kernel: [    4.640183]  <IRQ>  [<ffffffff81752bc9>]
> __schedule_bug+0x4d/0x59
> > kernel: [    4.640201]  [<ffffffff8175e0f6>] __schedule+0x726/0x7b0
> > kernel: [    4.640204]  [<ffffffff8175e4c9>] schedule+0x29/0x70
> > kernel: [    4.640206]  [<ffffffff8175c96c>] schedule_timeout+0x1fc/0x2c0
> > kernel: [    4.640212]  [<ffffffff813ef0ee>] ?
> > acpi_ns_search_one_scope+0x22/0x45
> > kernel: [    4.640215]  [<ffffffff813ef19c>] ?
> > acpi_ns_search_and_enter+0x8b/0x147
> > kernel: [    4.640217]  [<ffffffff8175d75b>] __down_common+0xa0/0xf7
> > kernel: [    4.640220]  [<ffffffff8175d7c8>] __down_timeout+0x16/0x18
> > kernel: [    4.640225]  [<ffffffff810844fe>] down_timeout+0x5e/0x70
> > kernel: [    4.640229]  [<ffffffff813d2181>]
> acpi_os_wait_semaphore+0x49/0x5f
> > kernel: [    4.640233]  [<ffffffff813f880e>]
> acpi_ut_acquire_mutex+0x51/0x93
> > kernel: [    4.640236]  [<ffffffff813eae40>]
> > acpi_ex_enter_interpreter+0x10/0x30
> > kernel: [    4.640239]  [<ffffffff813ed28d>] acpi_ns_evaluate+0x13d/0x1ad
> > kernel: [    4.640242]  [<ffffffff813eff69>]
> acpi_evaluate_object+0x127/0x233
> > kernel: [    4.640245]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
> > kernel: [    4.640248]  [<ffffffff813d25aa>]
> acpi_evaluate_integer+0x34/0x53
> > kernel: [    4.640250]  [<ffffffff813d4d96>] do_acpi_find_child+0x2d/0x52
> > kernel: [    4.640253]  [<ffffffff813ef970>]
> acpi_ns_walk_namespace+0xd5/0x179
> > kernel: [    4.640256]  [<ffffffff813d4d69>] ? acpi_get_child+0x4f/0x4f
> > kernel: [    4.640258]  [<ffffffff813efe0f>] acpi_walk_namespace+0x98/0xcb
> > kernel: [    4.640261]  [<ffffffff813d4d5f>] acpi_get_child+0x45/0x4f
> > kernel: [    4.640266]  [<ffffffff814dceeb>] ata_ap_acpi_handle+0x2b/0x30
> > kernel: [    4.640268]  [<ffffffff814dd1cb>] ata_acpi_gtm+0x2b/0x100
> > kernel: [    4.640271]  [<ffffffff814e07bc>] pacpi_set_piomode+0x5c/0x70
> > kernel: [    4.640274]  [<ffffffff814e0816>] pacpi_qc_issue+0x46/0x80
> > kernel: [    4.640278]  [<ffffffff814c73b3>] ata_qc_issue+0x173/0x380
> > kernel: [    4.640282]  [<ffffffff814cd470>] ?
> > ata_scsi_set_sense.constprop.24+0x30/0x30
> > kernel: [    4.640285]  [<ffffffff814cc097>] ata_scsi_translate+0xa7/0x180
> > kernel: [    4.640287]  [<ffffffff814d0259>] ata_scsi_queuecmd+0xa9/0x2b0
> > kernel: [    4.640291]  [<ffffffff814a342e>] scsi_dispatch_cmd+0xde/0x2c0
> > kernel: [    4.640294]  [<ffffffff814aae70>] scsi_request_fn+0x350/0x560
> > kernel: [    4.640298]  [<ffffffff81768b1d>] ?
> > call_function_single_interrupt+0x6d/0x80
> > kernel: [    4.640302]  [<ffffffff8133e1c7>] __blk_run_queue+0x37/0x50
> > kernel: [    4.640304]  [<ffffffff814a9ef9>] scsi_run_queue+0x179/0x2b0
> > kernel: [    4.640310]  [<ffffffff81464ce7>] ? put_device+0x17/0x20
> > kernel: [    4.640314]  [<ffffffff814ab462>] scsi_next_command+0x42/0x60
> > kernel: [    4.640316]  [<ffffffff814ab6ce>] scsi_io_completion+0x1ee/0x6c0
> > kernel: [    4.640319]  [<ffffffff814a166d>] scsi_finish_command+0xbd/0x120
> > kernel: [    4.640322]  [<ffffffff814ab3ee>] scsi_softirq_done+0x13e/0x150
> > kernel: [    4.640328]  [<ffffffff81344ce3>] blk_done_softirq+0x83/0xa0
> > kernel: [    4.640333]  [<ffffffff81061aef>] __do_softirq+0xcf/0x210
> > kernel: [    4.640338]  [<ffffffff8103b948>] ? ack_apic_level+0x78/0x130
> > kernel: [    4.640340]  [<ffffffff8176905c>] call_softirq+0x1c/0x30
> > kernel: [    4.640349]  [<ffffffff810161b5>] do_softirq+0x75/0xb0
> > kernel: [    4.640352]  [<ffffffff81061da5>] irq_exit+0xa5/0xb0
> > kernel: [    4.640355]  [<ffffffff817698f3>] do_IRQ+0x63/0xe0
> > kernel: [    4.640358]  [<ffffffff8175f9ad>] common_interrupt+0x6d/0x6d
> > kernel: [    4.640360]  <EOI>  [<ffffffff817633f4>] ?
> > __do_page_fault+0x264/0x4e0
> > kernel: [    4.640366]  [<ffffffff817633ec>] ? __do_page_fault+0x25c/0x4e0
> > kernel: [    4.640369]  [<ffffffff81086bda>] ? lg_local_unlock+0x1a/0x20
> > kernel: [    4.640374]  [<ffffffff811ab116>] ? mntput+0x26/0x40
> > kernel: [    4.640378]  [<ffffffff8118d9fe>] ? __fput+0x16e/0x240
> > kernel: [    4.640381]  [<ffffffff8118dade>] ? ____fput+0xe/0x10
> > kernel: [    4.640385]  [<ffffffff8107af71>] ? task_work_run+0xc1/0xe0
> > kernel: [    4.640388]  [<ffffffff8176367e>] do_page_fault+0xe/0x10
> > kernel: [    4.640390]  [<ffffffff8175fc98>] page_fault+0x28/0x30
> >
> > -- 
> > Configure bugmail: https://bugzilla.kernel.org/userprefs.cgi?tab=email
> > ------- You are receiving this mail because: -------
> > You are watching the assignee of the bug.
Comment 3 kenzopl 2013-04-19 05:39:08 UTC
3.8.8 is the same, log from yesterday:

kernel: [   26.540051] dib0700: firmware started successfully.
kernel: [   27.040231] BUG: scheduling while atomic: apt-check/558/0x00000100
kernel: [   27.040238] Modules linked in: dvb_usb_dib0700(+) snd_hda_codec_hdmi dib0090 dib7000p dib7000m dib0070 dib8000 snd_hda_codec_realtek mt2266 dib3000mc binfmt_misc mxl5007t s5h1411 mt2060 lgdt3305 snd_hda_intel(+) dibx000_common snd_hda_codec saa7134 joydev coretemp snd_hwdep ftdi_sio snd_pcm usbserial i2c_nforce2 ppdev microcode videobuf_dma_sg parport_pc serio_raw asus_atk0110 snd_seq_midi mac_hid snd_page_alloc snd_rawmidi snd_seq_midi_event snd_mixer_oss snd_seq snd_timer snd_seq_device snd soundcore lp parport hid_generic usbhid hid usb_storage radeon ttm drm_kms_helper wmi drm i2c_algo_bit forcedeth
kernel: [   27.040281] Pid: 558, comm: apt-check Not tainted 3.8.8 #1
kernel: [   27.040283] Call Trace:
kernel: [   27.040284]  <IRQ>  [<ffffffff81752917>] __schedule_bug+0x4d/0x59
kernel: [   27.040295]  [<ffffffff8175dee6>] __schedule+0x726/0x7b0
kernel: [   27.040298]  [<ffffffff8175e2a9>] schedule+0x29/0x70
kernel: [   27.040300]  [<ffffffff8175c75c>] schedule_timeout+0x1fc/0x2c0
kernel: [   27.040305]  [<ffffffff8108d675>] ? check_preempt_curr+0x85/0xa0
kernel: [   27.040308]  [<ffffffff8108d6bc>] ? ttwu_do_wakeup+0x2c/0xe0
kernel: [   27.040310]  [<ffffffff8175d54b>] __down_common+0xa0/0xf7
kernel: [   27.040313]  [<ffffffff8175d5b8>] __down_timeout+0x16/0x18
kernel: [   27.040317]  [<ffffffff8108447e>] down_timeout+0x5e/0x70
kernel: [   27.040321]  [<ffffffff813d1ef1>] acpi_os_wait_semaphore+0x49/0x5f
kernel: [   27.040325]  [<ffffffff813f8582>] acpi_ut_acquire_mutex+0x51/0x93
kernel: [   27.040329]  [<ffffffff813eabb4>] acpi_ex_enter_interpreter+0x10/0x30
kernel: [   27.040332]  [<ffffffff813efdab>] acpi_evaluate_object+0x1f5/0x233
kernel: [   27.040337]  [<ffffffff814dcd97>] ata_acpi_stm+0x97/0xe0
kernel: [   27.040342]  [<ffffffff8117d25c>] ? kfree+0x2c/0x120
kernel: [   27.040344]  [<ffffffff814dce71>] ? ata_acpi_gtm+0x91/0x100
kernel: [   27.040347]  [<ffffffff814e0357>] pacpi_set_dmamode+0x77/0xc0
kernel: [   27.040350]  [<ffffffff814e046c>] pacpi_qc_issue+0x5c/0x80
kernel: [   27.040354]  [<ffffffff814c70b3>] ata_qc_issue+0x173/0x380
kernel: [   27.040357]  [<ffffffff814cd0b0>] ? ata_scsi_set_sense.constprop.24+0x30/0x30
kernel: [   27.040360]  [<ffffffff814cbcd7>] ata_scsi_translate+0xa7/0x180
kernel: [   27.040362]  [<ffffffff814cfe99>] ata_scsi_queuecmd+0xa9/0x2b0
kernel: [   27.040366]  [<ffffffff814a314e>] scsi_dispatch_cmd+0xde/0x2b0
kernel: [   27.040369]  [<ffffffff814aab80>] scsi_request_fn+0x350/0x560
kernel: [   27.040373]  [<ffffffff8133df17>] __blk_run_queue+0x37/0x50
kernel: [   27.040376]  [<ffffffff814a9c09>] scsi_run_queue+0x179/0x2b0
kernel: [   27.040379]  [<ffffffff81464a47>] ? put_device+0x17/0x20
kernel: [   27.040382]  [<ffffffff814ab172>] scsi_next_command+0x42/0x60
kernel: [   27.040384]  [<ffffffff814ab3de>] scsi_io_completion+0x1ee/0x6c0
kernel: [   27.040387]  [<ffffffff814a138d>] scsi_finish_command+0xbd/0x120
kernel: [   27.040390]  [<ffffffff814ab0fe>] scsi_softirq_done+0x13e/0x150
kernel: [   27.040393]  [<ffffffff81344a23>] blk_done_softirq+0x83/0xa0
kernel: [   27.040396]  [<ffffffff81061acf>] __do_softirq+0xcf/0x200
kernel: [   27.040400]  [<ffffffff8103b918>] ? ack_apic_level+0x78/0x130
kernel: [   27.040404]  [<ffffffff81768e9c>] call_softirq+0x1c/0x30
kernel: [   27.040408]  [<ffffffff810161a5>] do_softirq+0x75/0xb0
kernel: [   27.040410]  [<ffffffff81061d75>] irq_exit+0xa5/0xb0
kernel: [   27.040413]  [<ffffffff81769733>] do_IRQ+0x63/0xe0
kernel: [   27.040416]  [<ffffffff8175f7ad>] common_interrupt+0x6d/0x6d
kernel: [   27.040417]  <EOI> 
kernel: [   27.040578] BUG: scheduling while atomic: apt-check/558/0x00000100
kernel: [   27.040580] Modules linked in: dvb_usb_dib0700(+) snd_hda_codec_hdmi dib0090 dib7000p dib7000m dib0070 dib8000 snd_hda_codec_realtek mt2266 dib3000mc binfmt_misc mxl5007t s5h1411 mt2060 lgdt3305 snd_hda_intel(+) dibx000_common snd_hda_codec saa7134 joydev coretemp snd_hwdep ftdi_sio snd_pcm usbserial i2c_nforce2 ppdev microcode videobuf_dma_sg parport_pc serio_raw asus_atk0110 snd_seq_midi mac_hid snd_page_alloc snd_rawmidi snd_seq_midi_event snd_mixer_oss snd_seq snd_timer snd_seq_device snd soundcore lp parport hid_generic usbhid hid usb_storage radeon ttm drm_kms_helper wmi drm i2c_algo_bit forcedeth
kernel: [   27.040611] Pid: 558, comm: apt-check Tainted: G        W    3.8.8 #1
kernel: [   27.040612] Call Trace:
kernel: [   27.040614]  <IRQ>  [<ffffffff81752917>] __schedule_bug+0x4d/0x59
kernel: [   27.040619]  [<ffffffff8175dee6>] __schedule+0x726/0x7b0
kernel: [   27.040621]  [<ffffffff8175e2a9>] schedule+0x29/0x70
kernel: [   27.040624]  [<ffffffff8175c75c>] schedule_timeout+0x1fc/0x2c0
kernel: [   27.040627]  [<ffffffff813eee62>] ? acpi_ns_search_one_scope+0x22/0x45
kernel: [   27.040630]  [<ffffffff813eef10>] ? acpi_ns_search_and_enter+0x8b/0x147
kernel: [   27.040632]  [<ffffffff8175d54b>] __down_common+0xa0/0xf7
kernel: [   27.040634]  [<ffffffff8175d5b8>] __down_timeout+0x16/0x18
kernel: [   27.040637]  [<ffffffff8108447e>] down_timeout+0x5e/0x70
kernel: [   27.040640]  [<ffffffff813d1ef1>] acpi_os_wait_semaphore+0x49/0x5f
kernel: [   27.040643]  [<ffffffff813f8582>] acpi_ut_acquire_mutex+0x51/0x93
kernel: [   27.040645]  [<ffffffff813eabb4>] acpi_ex_enter_interpreter+0x10/0x30
kernel: [   27.040648]  [<ffffffff813ed001>] acpi_ns_evaluate+0x13d/0x1ad
kernel: [   27.040651]  [<ffffffff813efcdd>] acpi_evaluate_object+0x127/0x233
kernel: [   27.040654]  [<ffffffff813f24c7>] ? acpi_ps_delete_parse_tree+0x2f/0x64
kernel: [   27.040657]  [<ffffffff813d4ad9>] ? acpi_get_child+0x4f/0x4f
kernel: [   27.040659]  [<ffffffff813d231a>] acpi_evaluate_integer+0x34/0x53
kernel: [   27.040662]  [<ffffffff813d4b06>] do_acpi_find_child+0x2d/0x52
kernel: [   27.040665]  [<ffffffff813ef6e4>] acpi_ns_walk_namespace+0xd5/0x179
kernel: [   27.040667]  [<ffffffff813d4ad9>] ? acpi_get_child+0x4f/0x4f
kernel: [   27.040670]  [<ffffffff813efb83>] acpi_walk_namespace+0x98/0xcb
kernel: [   27.040672]  [<ffffffff813d4acf>] acpi_get_child+0x45/0x4f
kernel: [   27.040675]  [<ffffffff814dcb2b>] ata_ap_acpi_handle+0x2b/0x30
kernel: [   27.040678]  [<ffffffff814dcd82>] ata_acpi_stm+0x82/0xe0
kernel: [   27.040680]  [<ffffffff814e03f1>] pacpi_set_piomode+0x51/0x70
kernel: [   27.040683]  [<ffffffff814e0456>] pacpi_qc_issue+0x46/0x80
kernel: [   27.040685]  [<ffffffff814c70b3>] ata_qc_issue+0x173/0x380
kernel: [   27.040688]  [<ffffffff814cd0b0>] ? ata_scsi_set_sense.constprop.24+0x30/0x30
kernel: [   27.040691]  [<ffffffff814cbcd7>] ata_scsi_translate+0xa7/0x180
kernel: [   27.040693]  [<ffffffff814cfe99>] ata_scsi_queuecmd+0xa9/0x2b0
kernel: [   27.040696]  [<ffffffff814a314e>] scsi_dispatch_cmd+0xde/0x2b0
kernel: [   27.040699]  [<ffffffff814aab80>] scsi_request_fn+0x350/0x560
kernel: [   27.040701]  [<ffffffff8133df17>] __blk_run_queue+0x37/0x50
kernel: [   27.040704]  [<ffffffff814a9c09>] scsi_run_queue+0x179/0x2b0
kernel: [   27.040706]  [<ffffffff81464a47>] ? put_device+0x17/0x20
kernel: [   27.040709]  [<ffffffff814ab172>] scsi_next_command+0x42/0x60
kernel: [   27.040712]  [<ffffffff814ab3de>] scsi_io_completion+0x1ee/0x6c0
kernel: [   27.040714]  [<ffffffff814a138d>] scsi_finish_command+0xbd/0x120
kernel: [   27.040717]  [<ffffffff814ab0fe>] scsi_softirq_done+0x13e/0x150
kernel: [   27.040720]  [<ffffffff81344a23>] blk_done_softirq+0x83/0xa0
kernel: [   27.040722]  [<ffffffff81061acf>] __do_softirq+0xcf/0x200
kernel: [   27.040725]  [<ffffffff8103b918>] ? ack_apic_level+0x78/0x130
kernel: [   27.040728]  [<ffffffff81768e9c>] call_softirq+0x1c/0x30
kernel: [   27.040731]  [<ffffffff810161a5>] do_softirq+0x75/0xb0
kernel: [   27.040733]  [<ffffffff81061d75>] irq_exit+0xa5/0xb0
kernel: [   27.040736]  [<ffffffff81769733>] do_IRQ+0x63/0xe0
kernel: [   27.040739]  [<ffffffff8175f7ad>] common_interrupt+0x6d/0x6d
kernel: [   27.040740]  <EOI>  [<ffffffff81763204>] ? __do_page_fault+0x264/0x500
kernel: [   27.040745]  [<ffffffff8176321c>] ? __do_page_fault+0x27c/0x500
kernel: [   27.040748]  [<ffffffff81086b5a>] ? lg_local_unlock+0x1a/0x20
kernel: [   27.040752]  [<ffffffff811ab046>] ? mntput+0x26/0x40
kernel: [   27.040755]  [<ffffffff8118d92e>] ? __fput+0x16e/0x240
kernel: [   27.040757]  [<ffffffff8118da0e>] ? ____fput+0xe/0x10
kernel: [   27.040761]  [<ffffffff8107aec1>] ? task_work_run+0xc1/0xe0
kernel: [   27.040764]  [<ffffffff817634ae>] do_page_fault+0xe/0x10
kernel: [   27.040766]  [<ffffffff8175fa98>] page_fault+0x28/0x30
kernel: [   27.040802] BUG: scheduling while atomic: apt-check/558/0x00000100
kernel: [   27.040804] Modules linked in: dvb_usb_dib0700(+) snd_hda_codec_hdmi dib0090 dib7000p dib7000m dib0070 dib8000 snd_hda_codec_realtek mt2266 dib3000mc binfmt_misc mxl5007t s5h1411 mt2060 lgdt3305 snd_hda_intel(+) dibx000_common snd_hda_codec saa7134 joydev coretemp snd_hwdep ftdi_sio snd_pcm usbserial i2c_nforce2 ppdev microcode videobuf_dma_sg parport_pc serio_raw asus_atk0110 snd_seq_midi mac_hid snd_page_alloc snd_rawmidi snd_seq_midi_event snd_mixer_oss snd_seq snd_timer snd_seq_device snd soundcore lp parport hid_generic usbhid hid usb_storage radeon ttm drm_kms_helper wmi drm i2c_algo_bit forcedeth
kernel: [   27.040834] Pid: 558, comm: apt-check Tainted: G        W    3.8.8 #1
kernel: [   27.040835] Call Trace:
kernel: [   27.040836]  <IRQ>  [<ffffffff81752917>] __schedule_bug+0x4d/0x59
kernel: [   27.040841]  [<ffffffff8175dee6>] __schedule+0x726/0x7b0
kernel: [   27.040843]  [<ffffffff8175e2a9>] schedule+0x29/0x70
kernel: [   27.040845]  [<ffffffff8175c75c>] schedule_timeout+0x1fc/0x2c0
kernel: [   27.040848]  [<ffffffff8108cd3c>] ? resched_task+0x2c/0x80
kernel: [   27.040851]  [<ffffffff8108d665>] ? check_preempt_curr+0x75/0xa0
kernel: [   27.040853]  [<ffffffff8108d6bc>] ? ttwu_do_wakeup+0x2c/0xe0
kernel: [   27.040856]  [<ffffffff8175d54b>] __down_common+0xa0/0xf7
kernel: [   27.040858]  [<ffffffff8175d5b8>] __down_timeout+0x16/0x18
kernel: [   27.040861]  [<ffffffff8108447e>] down_timeout+0x5e/0x70
kernel: [   27.040864]  [<ffffffff813d1ef1>] acpi_os_wait_semaphore+0x49/0x5f
kernel: [   27.040867]  [<ffffffff813f8582>] acpi_ut_acquire_mutex+0x51/0x93
kernel: [   27.040869]  [<ffffffff813eabb4>] acpi_ex_enter_interpreter+0x10/0x30
kernel: [   27.040872]  [<ffffffff813efdab>] acpi_evaluate_object+0x1f5/0x233
kernel: [   27.040875]  [<ffffffff813d4ad9>] ? acpi_get_child+0x4f/0x4f
kernel: [   27.040877]  [<ffffffff813d231a>] acpi_evaluate_integer+0x34/0x53
kernel: [   27.040880]  [<ffffffff813d4b06>] do_acpi_find_child+0x2d/0x52
kernel: [   27.040883]  [<ffffffff813ef6e4>] acpi_ns_walk_namespace+0xd5/0x179
kernel: [   27.040886]  [<ffffffff813d4ad9>] ? acpi_get_child+0x4f/0x4f
kernel: [   27.040888]  [<ffffffff813efb83>] acpi_walk_namespace+0x98/0xcb
kernel: [   27.040891]  [<ffffffff813d4acf>] acpi_get_child+0x45/0x4f
kernel: [   27.040894]  [<ffffffff814dcb2b>] ata_ap_acpi_handle+0x2b/0x30
kernel: [   27.040896]  [<ffffffff814dcd82>] ata_acpi_stm+0x82/0xe0
kernel: [   27.040899]  [<ffffffff814e03f1>] pacpi_set_piomode+0x51/0x70
kernel: [   27.040901]  [<ffffffff814e0456>] pacpi_qc_issue+0x46/0x80
kernel: [   27.040904]  [<ffffffff814c70b3>] ata_qc_issue+0x173/0x380
kernel: [   27.040907]  [<ffffffff814cd0b0>] ? ata_scsi_set_sense.constprop.24+0x30/0x30
kernel: [   27.040909]  [<ffffffff814cbcd7>] ata_scsi_translate+0xa7/0x180
kernel: [   27.040912]  [<ffffffff814cfe99>] ata_scsi_queuecmd+0xa9/0x2b0
kernel: [   27.040914]  [<ffffffff814a314e>] scsi_dispatch_cmd+0xde/0x2b0
kernel: [   27.040917]  [<ffffffff814aab80>] scsi_request_fn+0x350/0x560
kernel: [   27.040920]  [<ffffffff8133df17>] __blk_run_queue+0x37/0x50
kernel: [   27.040922]  [<ffffffff814a9c09>] scsi_run_queue+0x179/0x2b0
kernel: [   27.040925]  [<ffffffff81464a47>] ? put_device+0x17/0x20
kernel: [   27.040927]  [<ffffffff814ab172>] scsi_next_command+0x42/0x60
kernel: [   27.040930]  [<ffffffff814ab3de>] scsi_io_completion+0x1ee/0x6c0
kernel: [   27.040933]  [<ffffffff814a138d>] scsi_finish_command+0xbd/0x120
kernel: [   27.040935]  [<ffffffff814ab0fe>] scsi_softirq_done+0x13e/0x150
kernel: [   27.040938]  [<ffffffff81344a23>] blk_done_softirq+0x83/0xa0
kernel: [   27.040941]  [<ffffffff81061acf>] __do_softirq+0xcf/0x200
kernel: [   27.040943]  [<ffffffff8103b918>] ? ack_apic_level+0x78/0x130
kernel: [   27.040946]  [<ffffffff81768e9c>] call_softirq+0x1c/0x30
kernel: [   27.040949]  [<ffffffff810161a5>] do_softirq+0x75/0xb0
kernel: [   27.040951]  [<ffffffff81061d75>] irq_exit+0xa5/0xb0
kernel: [   27.040954]  [<ffffffff81769733>] do_IRQ+0x63/0xe0
kernel: [   27.040956]  [<ffffffff8175f7ad>] common_interrupt+0x6d/0x6d
kernel: [   27.040958]  <EOI>  [<ffffffff81763204>] ? __do_page_fault+0x264/0x500
kernel: [   27.040963]  [<ffffffff8176321c>] ? __do_page_fault+0x27c/0x500
kernel: [   27.040965]  [<ffffffff81086b5a>] ? lg_local_unlock+0x1a/0x20
kernel: [   27.040968]  [<ffffffff811ab046>] ? mntput+0x26/0x40
kernel: [   27.040971]  [<ffffffff8118d92e>] ? __fput+0x16e/0x240
kernel: [   27.040974]  [<ffffffff8118da0e>] ? ____fput+0xe/0x10
kernel: [   27.040977]  [<ffffffff8107aec1>] ? task_work_run+0xc1/0xe0
kernel: [   27.040980]  [<ffffffff817634ae>] do_page_fault+0xe/0x10
kernel: [   27.040983]  [<ffffffff8175fa98>] page_fault+0x28/0x30
kernel: [   27.048049] dvb-usb: found a 'Medion CTX1921 DVB-T USB' in warm state.
kernel: [   27.048242] dvb-usb: will pass the complete MPEG2 transport stream to the software demuxer.
kernel: [   27.048696] DVB: registering new adapter (Medion CTX1921 DVB-T USB)
kernel: [   27.220221] input: HDA NVidia HDMI/DP,pcm=3 Phantom as /devices/pci0000:00/0000:00:09.0/sound/card0/input6
kernel: [   27.220396] input: HDA NVidia Line as /devices/pci0000:00/0000:00:09.0/sound/card0/input7
kernel: [   27.220557] input: HDA NVidia Rear Mic as /devices/pci0000:00/0000:00:09.0/sound/card0/input8
kernel: [   27.220621] input: HDA NVidia Front Mic as /devices/pci0000:00/0000:00:09.0/sound/card0/input9
kernel: [   27.220720] input: HDA NVidia Front Headphone as /devices/pci0000:00/0000:00:09.0/sound/card0/input10
kernel: [   27.220813] input: HDA NVidia Line Out Side as /devices/pci0000:00/0000:00:09.0/sound/card0/input11
kernel: [   27.220908] input: HDA NVidia Line Out CLFE as /devices/pci0000:00/0000:00:09.0/sound/card0/input12
kernel: [   27.221000] input: HDA NVidia Line Out Surround as /devices/pci0000:00/0000:00:09.0/sound/card0/input13
kernel: [   27.221092] input: HDA NVidia Line Out Front as /devices/pci0000:00/0000:00:09.0/sound/card0/input14
kernel: [   27.228429] ACPI: PCI Interrupt Link [APC7] enabled at IRQ 16
kernel: [   27.228445] hda-intel 0000:02:00.1: Handle VGA-switcheroo audio client
kernel: [   27.228512] snd_hda_intel 0000:02:00.1: irq 44 for MSI/MSI-X
kernel: [   27.231262] input: HDA ATI HDMI HDMI/DP,pcm=3 as /devices/pci0000:00/0000:00:0b.0/0000:02:00.1/sound/card1/input15
kernel: [   27.264933] usb 1-6: DVB: registering adapter 0 frontend 0 (DiBcom 7000PC)...
kernel: [   27.475795] DiB0070: successfully identified
kernel: [   27.475813] Registered IR keymap rc-dib0700-rc5
kernel: [   27.475955] input: IR-receiver inside an USB DVB receiver as /devices/pci0000:00/0000:00:04.1/usb1/1-6/rc/rc0/input16
kernel: [   27.476136] rc0: IR-receiver inside an USB DVB receiver as /devices/pci0000:00/0000:00:04.1/usb1/1-6/rc/rc0
kernel: [   27.476690] dvb-usb: schedule remote query interval to 50 msecs.
kernel: [   27.476695] dvb-usb: Medion CTX1921 DVB-T USB successfully initialized and connected.
kernel: [   27.476855] usbcore: registered new interface driver dvb_usb_dib0700
Comment 4 Aaron Lu 2013-04-19 08:57:27 UTC
On 04/19/2013 02:32 AM, Tejun Heo wrote:
> Hello,
> 
> (cc'ing Jeff, linux-ide and copying the whole message)
> 
> So, the problem seems to be inside pata_acpi driver.  It's calling
> pacpi_set_piomode() from qc_issue path while holding the queue lock.
> pacpi_set_piomode() calls into acpi which may sleep.  It gets blocked
> on a semaphore and triggers the bug.  Maybe some changes between 3.8.6
> and 3.8.8 made it more likely to trigger but fundamentally it's a bug
> in the pata_acpi driver.  It can't directly call into acpi while
> holding queue lock.

The ata acpi code to get port's handle used to not block, but since the
rework to bind ata handle to scsi device tree, it is now.

I didn't check how much work is required to modify the pata acpi driver
to solve the problem, but I have written a patch to make
ata_ap_acpi_handle(which ata_acpi_gtm calls) does not block, and so
should be able to fix this problem. I'll attach that patch to the bug
page too for the reporter to test soon.

Patch here, not tested:

 drivers/ata/libata-acpi.c | 44 ++++++++++++++++++++++++++------------------
 1 file changed, 26 insertions(+), 18 deletions(-)

diff --git a/drivers/ata/libata-acpi.c b/drivers/ata/libata-acpi.c
index 1c33f78..0e6cf89 100644
--- a/drivers/ata/libata-acpi.c
+++ b/drivers/ata/libata-acpi.c
@@ -60,7 +60,7 @@ acpi_handle ata_ap_acpi_handle(struct ata_port *ap)
 	if (ap->flags & ATA_FLAG_ACPI_SATA)
 		return NULL;
 
-	return acpi_get_child(DEVICE_ACPI_HANDLE(ap->host->dev), ap->port_no);
+	return ACPI_HANDLE(ap->host->dev);
 }
 EXPORT_SYMBOL(ata_ap_acpi_handle);
 
@@ -239,28 +239,15 @@ void ata_acpi_dissociate(struct ata_host *host)
 	}
 }
 
-/**
- * ata_acpi_gtm - execute _GTM
- * @ap: target ATA port
- * @gtm: out parameter for _GTM result
- *
- * Evaluate _GTM and store the result in @gtm.
- *
- * LOCKING:
- * EH context.
- *
- * RETURNS:
- * 0 on success, -ENOENT if _GTM doesn't exist, -errno on failure.
- */
-int ata_acpi_gtm(struct ata_port *ap, struct ata_acpi_gtm *gtm)
+static int __ata_acpi_gtm(struct ata_port *ap, acpi_handle handle,
+			  struct ata_acpi_gtm *gtm)
 {
 	struct acpi_buffer output = { .length = ACPI_ALLOCATE_BUFFER };
 	union acpi_object *out_obj;
 	acpi_status status;
 	int rc = 0;
 
-	status = acpi_evaluate_object(ata_ap_acpi_handle(ap), "_GTM", NULL,
-				      &output);
+	status = acpi_evaluate_object(handle, "_GTM", NULL, &output);
 
 	rc = -ENOENT;
 	if (status == AE_NOT_FOUND)
@@ -294,6 +281,27 @@ int ata_acpi_gtm(struct ata_port *ap, struct ata_acpi_gtm *gtm)
 	return rc;
 }
 
+/**
+ * ata_acpi_gtm - execute _GTM
+ * @ap: target ATA port
+ * @gtm: out parameter for _GTM result
+ *
+ * Evaluate _GTM and store the result in @gtm.
+ *
+ * LOCKING:
+ * EH context.
+ *
+ * RETURNS:
+ * 0 on success, -ENOENT if _GTM doesn't exist, -errno on failure.
+ */
+int ata_acpi_gtm(struct ata_port *ap, struct ata_acpi_gtm *gtm)
+{
+	if (ata_ap_acpi_handle(ap))
+		return __ata_acpi_gtm(ap, ata_ap_acpi_handle(ap), gtm);
+	else
+		return -EINVAL;
+}
+
 EXPORT_SYMBOL_GPL(ata_acpi_gtm);
 
 /**
@@ -1047,7 +1055,7 @@ static int ata_acpi_bind_host(struct ata_port *ap, acpi_handle *handle)
 	if (!*handle)
 		return -ENODEV;
 
-	if (ata_acpi_gtm(ap, &ap->__acpi_init_gtm) == 0)
+	if (__ata_acpi_gtm(ap, *handle, &ap->__acpi_init_gtm) == 0)
 		ap->pflags |= ATA_PFLAG_INIT_GTM_VALID;
 
 	return 0;
Comment 5 Aaron Lu 2013-04-19 09:02:14 UTC
Created attachment 99281 [details]
Make ata_port_acpi_handle does not block

Apply on top of v3.8 or Linus' git tree.

BTW, you should not use pata_acpi driver for your nvidia pata controller, the native driver should be used instead. I saw you are using Ubuntu from the dmesg log, they seem to be making CONFIG_PATA_ACPI=y IIRC, which will make pata_acpi driver be preferred than native driver, which is not a good thing I think.
The pata_acpi driver is there for controllers that do not have a native driver, it should be the last resort, not the first :-)
Comment 6 Aaron Lu 2013-04-19 10:15:08 UTC
Created attachment 99291 [details]
Make ata_port_acpi_handle does not block

Sorry, made a mistake in the previous one, please use this instead, thanks.
Comment 7 kenzopl 2013-04-20 15:04:38 UTC
Hi Aaron

Thank you for your quick and kind support. I've tested this patch by the following sequence:
1. Apply patch and recompile
2. Reboot for 20 times
3. Go back to previous kernel
4. Reboot for 20 times

Result: No hang-up with patch applied. 6 hangs-up without patch.

I'm not really familiar with the procedures here so could you please tell me whether this patch could be included under next kernel release or should I apply it myself with each kernel release?
Comment 8 Aaron Lu 2013-04-21 14:35:20 UTC
Hi,

I'll submit the patch to linux-ide mailing list tomorrow and Jeff will probably take it. I'm not sure which version it will be merged, and if -stable tree would accept such a patch. I'll add you to the cc list when submitting the patch.
Thanks for your test!