Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Mark Rutland]

On Tue, Oct 31, 2017 at 10:38:33AM +, Will Deacon wrote:
> On Mon, Oct 30, 2017 at 04:14:15PM -0400, Tyler Baicar wrote:
> > On 10/30/2017 1:46 PM, Linus Torvalds wrote:
> > >On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
> > > wrote:
> > >>I will add a "might_sleep()" to ioremap_page_range() itself, so that
> > >>we get this warning more reliably and much eailer. Right now it has
> > >>been hidden by the fact that most of the time the time the page tables
> > >>may be already allocated, but even then it's broken.
> > >Done. It doesn't report anything for me, so _hopefully_ the GHES
> > >driver is the only one that does games like this. See commit
> > >b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> > >
> > >So now it should hopefully warn about this bad usage of page remapping
> > >reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> > >
> > >Can somebody who has a working GHES setup (although Borislav seems to
> > >think no such thing exists) verify?
> > Hello Linus,
> > 
> > I have verified that this flags the error for me every time ghes_proc() is 
> > used.
> > But I also see it flagged in ARM PMU code:
> > 
> > [    7.381153] BUG: sleeping function called from invalid context at 
> > mm/slab.h:420
> > [    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
> > [    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
> > [    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development
> > Platform
> > [    7.414361] Call trace:
> > [    7.416797] [] dump_backtrace+0x0/0x270
> > [    7.422175] [] show_stack+0x24/0x30
> > [    7.427211] [] dump_stack+0x98/0xb8
> > [    7.432246] [] ___might_sleep+0x104/0x128
> > [    7.437799] [] __might_sleep+0x58/0x90
> > [    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
> > [    7.449347] [] armpmu_alloc+0x30/0x168
> > [    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
> > [    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
> > [    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
> > [    7.472872] [] smpboot_thread_fn+0x174/0x250
> > [    7.478684] [] kthread+0x114/0x140
> > [    7.483632] [] ret_from_fork+0x10/0x1c
> 
> I know Mark was doing some fixes in the ACPI notifier code here, so I've
> added him to CC.

Sorry for the delay on this; I have a rather hideous fix that I'll clean
up and post shortly.

Thanks,
Mark.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Mark Rutland]

On Tue, Oct 31, 2017 at 10:38:33AM +, Will Deacon wrote:
> On Mon, Oct 30, 2017 at 04:14:15PM -0400, Tyler Baicar wrote:
> > On 10/30/2017 1:46 PM, Linus Torvalds wrote:
> > >On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
> > > wrote:
> > >>I will add a "might_sleep()" to ioremap_page_range() itself, so that
> > >>we get this warning more reliably and much eailer. Right now it has
> > >>been hidden by the fact that most of the time the time the page tables
> > >>may be already allocated, but even then it's broken.
> > >Done. It doesn't report anything for me, so _hopefully_ the GHES
> > >driver is the only one that does games like this. See commit
> > >b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> > >
> > >So now it should hopefully warn about this bad usage of page remapping
> > >reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> > >
> > >Can somebody who has a working GHES setup (although Borislav seems to
> > >think no such thing exists) verify?
> > Hello Linus,
> > 
> > I have verified that this flags the error for me every time ghes_proc() is 
> > used.
> > But I also see it flagged in ARM PMU code:
> > 
> > [    7.381153] BUG: sleeping function called from invalid context at 
> > mm/slab.h:420
> > [    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
> > [    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
> > [    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development
> > Platform
> > [    7.414361] Call trace:
> > [    7.416797] [] dump_backtrace+0x0/0x270
> > [    7.422175] [] show_stack+0x24/0x30
> > [    7.427211] [] dump_stack+0x98/0xb8
> > [    7.432246] [] ___might_sleep+0x104/0x128
> > [    7.437799] [] __might_sleep+0x58/0x90
> > [    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
> > [    7.449347] [] armpmu_alloc+0x30/0x168
> > [    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
> > [    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
> > [    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
> > [    7.472872] [] smpboot_thread_fn+0x174/0x250
> > [    7.478684] [] kthread+0x114/0x140
> > [    7.483632] [] ret_from_fork+0x10/0x1c
> 
> I know Mark was doing some fixes in the ACPI notifier code here, so I've
> added him to CC.

Sorry for the delay on this; I have a rather hideous fix that I'll clean
up and post shortly.

Thanks,
Mark.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Will Deacon]

On Mon, Oct 30, 2017 at 04:14:15PM -0400, Tyler Baicar wrote:
> On 10/30/2017 1:46 PM, Linus Torvalds wrote:
> >On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
> > wrote:
> >>I will add a "might_sleep()" to ioremap_page_range() itself, so that
> >>we get this warning more reliably and much eailer. Right now it has
> >>been hidden by the fact that most of the time the time the page tables
> >>may be already allocated, but even then it's broken.
> >Done. It doesn't report anything for me, so _hopefully_ the GHES
> >driver is the only one that does games like this. See commit
> >b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> >
> >So now it should hopefully warn about this bad usage of page remapping
> >reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> >
> >Can somebody who has a working GHES setup (although Borislav seems to
> >think no such thing exists) verify?
> Hello Linus,
> 
> I have verified that this flags the error for me every time ghes_proc() is 
> used.
> But I also see it flagged in ARM PMU code:
> 
> [    7.381153] BUG: sleeping function called from invalid context at 
> mm/slab.h:420
> [    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
> [    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
> [    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development
> Platform
> [    7.414361] Call trace:
> [    7.416797] [] dump_backtrace+0x0/0x270
> [    7.422175] [] show_stack+0x24/0x30
> [    7.427211] [] dump_stack+0x98/0xb8
> [    7.432246] [] ___might_sleep+0x104/0x128
> [    7.437799] [] __might_sleep+0x58/0x90
> [    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
> [    7.449347] [] armpmu_alloc+0x30/0x168
> [    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
> [    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
> [    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
> [    7.472872] [] smpboot_thread_fn+0x174/0x250
> [    7.478684] [] kthread+0x114/0x140
> [    7.483632] [] ret_from_fork+0x10/0x1c

I know Mark was doing some fixes in the ACPI notifier code here, so I've
added him to CC.

Will

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Will Deacon]

On Mon, Oct 30, 2017 at 04:14:15PM -0400, Tyler Baicar wrote:
> On 10/30/2017 1:46 PM, Linus Torvalds wrote:
> >On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
> > wrote:
> >>I will add a "might_sleep()" to ioremap_page_range() itself, so that
> >>we get this warning more reliably and much eailer. Right now it has
> >>been hidden by the fact that most of the time the time the page tables
> >>may be already allocated, but even then it's broken.
> >Done. It doesn't report anything for me, so _hopefully_ the GHES
> >driver is the only one that does games like this. See commit
> >b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> >
> >So now it should hopefully warn about this bad usage of page remapping
> >reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> >
> >Can somebody who has a working GHES setup (although Borislav seems to
> >think no such thing exists) verify?
> Hello Linus,
> 
> I have verified that this flags the error for me every time ghes_proc() is 
> used.
> But I also see it flagged in ARM PMU code:
> 
> [    7.381153] BUG: sleeping function called from invalid context at 
> mm/slab.h:420
> [    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
> [    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
> [    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development
> Platform
> [    7.414361] Call trace:
> [    7.416797] [] dump_backtrace+0x0/0x270
> [    7.422175] [] show_stack+0x24/0x30
> [    7.427211] [] dump_stack+0x98/0xb8
> [    7.432246] [] ___might_sleep+0x104/0x128
> [    7.437799] [] __might_sleep+0x58/0x90
> [    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
> [    7.449347] [] armpmu_alloc+0x30/0x168
> [    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
> [    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
> [    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
> [    7.472872] [] smpboot_thread_fn+0x174/0x250
> [    7.478684] [] kthread+0x114/0x140
> [    7.483632] [] ret_from_fork+0x10/0x1c

I know Mark was doing some fixes in the ACPI notifier code here, so I've
added him to CC.

Will

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 1:46 PM, Linus Torvalds wrote:

On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
 wrote:

I will add a "might_sleep()" to ioremap_page_range() itself, so that
we get this warning more reliably and much eailer. Right now it has
been hidden by the fact that most of the time the time the page tables
may be already allocated, but even then it's broken.

Done. It doesn't report anything for me, so _hopefully_ the GHES
driver is the only one that does games like this. See commit
b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").

So now it should hopefully warn about this bad usage of page remapping
reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.

Can somebody who has a working GHES setup (although Borislav seems to
think no such thing exists) verify?

Hello Linus,

I have verified that this flags the error for me every time ghes_proc() is used.
But I also see it flagged in ARM PMU code:

[    7.381153] BUG: sleeping function called from invalid context at 
mm/slab.h:420
[    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
[    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
[    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[    7.414361] Call trace:
[    7.416797] [] dump_backtrace+0x0/0x270
[    7.422175] [] show_stack+0x24/0x30
[    7.427211] [] dump_stack+0x98/0xb8
[    7.432246] [] ___might_sleep+0x104/0x128
[    7.437799] [] __might_sleep+0x58/0x90
[    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
[    7.449347] [] armpmu_alloc+0x30/0x168
[    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
[    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
[    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
[    7.472872] [] smpboot_thread_fn+0x174/0x250
[    7.478684] [] kthread+0x114/0x140
[    7.483632] [] ret_from_fork+0x10/0x1c

For a GHES polling source:

[   47.944596] BUG: sleeping function called from invalid context at 
lib/ioremap.c:164

[   47.951290] in_atomic(): 1, irqs_disabled(): 128, pid: 0, name: swapper/19
[   47.958150] CPU: 19 PID: 0 Comm: swapper/19 Tainted: G W   4.14.0-rc7 #46
[   47.958152] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[   47.958154] Call trace:
[   47.958161] [] dump_backtrace+0x0/0x270
[   47.958165] [] show_stack+0x24/0x30
[   47.958169] [] dump_stack+0x98/0xb8
[   47.958174] [] ___might_sleep+0x104/0x128
[   47.958177] [] __might_sleep+0x58/0x90
[   47.958180] [] ioremap_page_range+0x40/0x310
[   47.958185] [] ghes_copy_tofrom_phys+0x1f8/0x240
[   47.958188] [] ghes_proc+0xb0/0x8f0
[   47.958190] [] ghes_poll_func+0x20/0x40
[   47.958196] [] call_timer_fn+0x3c/0x1b0
[   47.958198] [] expire_timers+0xe8/0x170
[   47.958201] [] run_timer_softirq+0x13c/0x188
[   47.958203] [] __do_softirq+0x144/0x33c
[   47.958206] [] irq_exit+0xd0/0x108
[   47.958210] [] __handle_domain_irq+0x6c/0xc0
[   47.958212] [] gic_handle_irq+0xcc/0x188

For a GHES interrupt source:

[  265.502603] BUG: sleeping function called from invalid context at 
lib/ioremap.c:164

[  265.509296] in_atomic(): 1, irqs_disabled(): 128, pid: 3, name: kworker/0:0
[  265.516242] CPU: 0 PID: 3 Comm: kworker/0:0 Tainted: G W   4.14.0-rc7 #46
[  265.516244] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[  265.516251] Workqueue: kacpi_notify acpi_os_execute_deferred
[  265.516254] Call trace:
[  265.516258] [] dump_backtrace+0x0/0x270
[  265.516261] [] show_stack+0x24/0x30
[  265.516264] [] dump_stack+0x98/0xb8
[  265.516268] [] ___might_sleep+0x104/0x128
[  265.516270] [] __might_sleep+0x58/0x90
[  265.516273] [] ioremap_page_range+0x40/0x310
[  265.516277] [] ghes_copy_tofrom_phys+0x1f8/0x240
[  265.516279] [] ghes_proc+0xb0/0x8f0
[  265.516282] [] ghes_notify_hed+0x50/0x90
[  265.516286] [] notifier_call_chain+0x5c/0xa0
[  265.516289] [] __blocking_notifier_call_chain+0x58/0xa0
[  265.516291] [] blocking_notifier_call_chain+0x3c/0x50
[  265.516293] [] acpi_hed_notify+0x28/0x30
[  265.516296] [] acpi_device_notify+0x30/0x40
[  265.516301] [] acpi_ev_notify_dispatch+0x64/0x74
[  265.516304] [] acpi_os_execute_deferred+0x24/0x38
[  265.516308] [] process_one_work+0x1f8/0x488
[  265.516310] [] worker_thread+0x58/0x4a0
[  265.516312] [] kthread+0x114/0x140
[  265.516315] [] ret_from_fork+0x10/0x1c

Thanks,
Tyler

--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 1:46 PM, Linus Torvalds wrote:

On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
 wrote:

I will add a "might_sleep()" to ioremap_page_range() itself, so that
we get this warning more reliably and much eailer. Right now it has
been hidden by the fact that most of the time the time the page tables
may be already allocated, but even then it's broken.

Done. It doesn't report anything for me, so _hopefully_ the GHES
driver is the only one that does games like this. See commit
b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").

So now it should hopefully warn about this bad usage of page remapping
reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.

Can somebody who has a working GHES setup (although Borislav seems to
think no such thing exists) verify?

Hello Linus,

I have verified that this flags the error for me every time ghes_proc() is used.
But I also see it flagged in ARM PMU code:

[    7.381153] BUG: sleeping function called from invalid context at 
mm/slab.h:420
[    7.387625] in_atomic(): 0, irqs_disabled(): 128, pid: 11, name: cpuhp/0
[    7.394310] CPU: 0 PID: 11 Comm: cpuhp/0 Not tainted 4.14.0-rc7 #46
[    7.400559] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[    7.414361] Call trace:
[    7.416797] [] dump_backtrace+0x0/0x270
[    7.422175] [] show_stack+0x24/0x30
[    7.427211] [] dump_stack+0x98/0xb8
[    7.432246] [] ___might_sleep+0x104/0x128
[    7.437799] [] __might_sleep+0x58/0x90
[    7.443097] [] kmem_cache_alloc_trace+0x224/0x280
[    7.449347] [] armpmu_alloc+0x30/0x168
[    7.454639] [] arm_pmu_acpi_cpu_starting+0x114/0x148
[    7.461151] [] cpuhp_invoke_callback+0xb8/0x760
[    7.467226] [] cpuhp_thread_fun+0xa4/0x1b8
[    7.472872] [] smpboot_thread_fn+0x174/0x250
[    7.478684] [] kthread+0x114/0x140
[    7.483632] [] ret_from_fork+0x10/0x1c

For a GHES polling source:

[   47.944596] BUG: sleeping function called from invalid context at 
lib/ioremap.c:164

[   47.951290] in_atomic(): 1, irqs_disabled(): 128, pid: 0, name: swapper/19
[   47.958150] CPU: 19 PID: 0 Comm: swapper/19 Tainted: G W   4.14.0-rc7 #46
[   47.958152] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[   47.958154] Call trace:
[   47.958161] [] dump_backtrace+0x0/0x270
[   47.958165] [] show_stack+0x24/0x30
[   47.958169] [] dump_stack+0x98/0xb8
[   47.958174] [] ___might_sleep+0x104/0x128
[   47.958177] [] __might_sleep+0x58/0x90
[   47.958180] [] ioremap_page_range+0x40/0x310
[   47.958185] [] ghes_copy_tofrom_phys+0x1f8/0x240
[   47.958188] [] ghes_proc+0xb0/0x8f0
[   47.958190] [] ghes_poll_func+0x20/0x40
[   47.958196] [] call_timer_fn+0x3c/0x1b0
[   47.958198] [] expire_timers+0xe8/0x170
[   47.958201] [] run_timer_softirq+0x13c/0x188
[   47.958203] [] __do_softirq+0x144/0x33c
[   47.958206] [] irq_exit+0xd0/0x108
[   47.958210] [] __handle_domain_irq+0x6c/0xc0
[   47.958212] [] gic_handle_irq+0xcc/0x188

For a GHES interrupt source:

[  265.502603] BUG: sleeping function called from invalid context at 
lib/ioremap.c:164

[  265.509296] in_atomic(): 1, irqs_disabled(): 128, pid: 3, name: kworker/0:0
[  265.516242] CPU: 0 PID: 3 Comm: kworker/0:0 Tainted: G W   4.14.0-rc7 #46
[  265.516244] Hardware name: Qualcomm Qualcomm Centriq(TM) 2400 Development 
Platform

[  265.516251] Workqueue: kacpi_notify acpi_os_execute_deferred
[  265.516254] Call trace:
[  265.516258] [] dump_backtrace+0x0/0x270
[  265.516261] [] show_stack+0x24/0x30
[  265.516264] [] dump_stack+0x98/0xb8
[  265.516268] [] ___might_sleep+0x104/0x128
[  265.516270] [] __might_sleep+0x58/0x90
[  265.516273] [] ioremap_page_range+0x40/0x310
[  265.516277] [] ghes_copy_tofrom_phys+0x1f8/0x240
[  265.516279] [] ghes_proc+0xb0/0x8f0
[  265.516282] [] ghes_notify_hed+0x50/0x90
[  265.516286] [] notifier_call_chain+0x5c/0xa0
[  265.516289] [] __blocking_notifier_call_chain+0x58/0xa0
[  265.516291] [] blocking_notifier_call_chain+0x3c/0x50
[  265.516293] [] acpi_hed_notify+0x28/0x30
[  265.516296] [] acpi_device_notify+0x30/0x40
[  265.516301] [] acpi_ev_notify_dispatch+0x64/0x74
[  265.516304] [] acpi_os_execute_deferred+0x24/0x38
[  265.516308] [] process_one_work+0x1f8/0x488
[  265.516310] [] worker_thread+0x58/0x4a0
[  265.516312] [] kthread+0x114/0x140
[  265.516315] [] ret_from_fork+0x10/0x1c

Thanks,
Tyler

--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 10:49 AM, Will Deacon  wrote:
>
> FWIW, we discussed some of this back in 2015, because the TLB invalidation
> looks busted to me too:

Yeah, I think the basic issue is that ioremap() is not supposed to map
*over* an existing mapping, it's designed to map pages into a new
mapping.

I think *every* other user of "ioremap_page_range()" is literally the
architecture-specific implementation of "ioremap()" (which does the
whole "allocate new VM area, then remap page range into that".

So the GHES driver use of this function really looks very wrong on so
many levels.

Checking..

Oh, git grep shows "drivers/pci/host/pci-tegra.c".

I'm afraid to even look into that file.

And pci_remap_iospace() looks potentially like a problem spot too -
but hopefully is done only at driver init time (but it could possibly
have the TLB issue).

  Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 10:49 AM, Will Deacon  wrote:
>
> FWIW, we discussed some of this back in 2015, because the TLB invalidation
> looks busted to me too:

Yeah, I think the basic issue is that ioremap() is not supposed to map
*over* an existing mapping, it's designed to map pages into a new
mapping.

I think *every* other user of "ioremap_page_range()" is literally the
architecture-specific implementation of "ioremap()" (which does the
whole "allocate new VM area, then remap page range into that".

So the GHES driver use of this function really looks very wrong on so
many levels.

Checking..

Oh, git grep shows "drivers/pci/host/pci-tegra.c".

I'm afraid to even look into that file.

And pci_remap_iospace() looks potentially like a problem spot too -
but hopefully is done only at driver init time (but it could possibly
have the TLB issue).

  Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Will Deacon]

On Mon, Oct 30, 2017 at 10:46:31AM -0700, Linus Torvalds wrote:
> On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
>  wrote:
> >
> > I will add a "might_sleep()" to ioremap_page_range() itself, so that
> > we get this warning more reliably and much eailer. Right now it has
> > been hidden by the fact that most of the time the time the page tables
> > may be already allocated, but even then it's broken.
> 
> Done. It doesn't report anything for me, so _hopefully_ the GHES
> driver is the only one that does games like this. See commit
> b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> 
> So now it should hopefully warn about this bad usage of page remapping
> reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> 
> Can somebody who has a working GHES setup (although Borislav seems to
> think no such thing exists) verify?
> 
> This obviously won't _fix_ anything, but at least it should make it
> clear it's not that recent change that broke things - that just
> happened to expose it. And hopefully somebody who knows that driver
> will do the proper fixmap thing (or just ioremap once at probe time,
> rather than at run-time).

FWIW, we discussed some of this back in 2015, because the TLB invalidation
looks busted to me too:

https://marc.info/?l=linux-kernel=145009681808308=2

Didn't go anywhere though...

Will

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Will Deacon]

On Mon, Oct 30, 2017 at 10:46:31AM -0700, Linus Torvalds wrote:
> On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
>  wrote:
> >
> > I will add a "might_sleep()" to ioremap_page_range() itself, so that
> > we get this warning more reliably and much eailer. Right now it has
> > been hidden by the fact that most of the time the time the page tables
> > may be already allocated, but even then it's broken.
> 
> Done. It doesn't report anything for me, so _hopefully_ the GHES
> driver is the only one that does games like this. See commit
> b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").
> 
> So now it should hopefully warn about this bad usage of page remapping
> reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.
> 
> Can somebody who has a working GHES setup (although Borislav seems to
> think no such thing exists) verify?
> 
> This obviously won't _fix_ anything, but at least it should make it
> clear it's not that recent change that broke things - that just
> happened to expose it. And hopefully somebody who knows that driver
> will do the proper fixmap thing (or just ioremap once at probe time,
> rather than at run-time).

FWIW, we discussed some of this back in 2015, because the TLB invalidation
looks busted to me too:

https://marc.info/?l=linux-kernel=145009681808308=2

Didn't go anywhere though...

Will

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
 wrote:
>
> I will add a "might_sleep()" to ioremap_page_range() itself, so that
> we get this warning more reliably and much eailer. Right now it has
> been hidden by the fact that most of the time the time the page tables
> may be already allocated, but even then it's broken.

Done. It doesn't report anything for me, so _hopefully_ the GHES
driver is the only one that does games like this. See commit
b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").

So now it should hopefully warn about this bad usage of page remapping
reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.

Can somebody who has a working GHES setup (although Borislav seems to
think no such thing exists) verify?

This obviously won't _fix_ anything, but at least it should make it
clear it's not that recent change that broke things - that just
happened to expose it. And hopefully somebody who knows that driver
will do the proper fixmap thing (or just ioremap once at probe time,
rather than at run-time).

Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 10:20 AM, Linus Torvalds
 wrote:
>
> I will add a "might_sleep()" to ioremap_page_range() itself, so that
> we get this warning more reliably and much eailer. Right now it has
> been hidden by the fact that most of the time the time the page tables
> may be already allocated, but even then it's broken.

Done. It doesn't report anything for me, so _hopefully_ the GHES
driver is the only one that does games like this. See commit
b39ab98e2f47 ("Mark 'ioremap_page_range()' as possibly sleeping").

So now it should hopefully warn about this bad usage of page remapping
reliably, at least if you have CONFIG_DEBUG_ATOMIC_SLEEP enabled.

Can somebody who has a working GHES setup (although Borislav seems to
think no such thing exists) verify?

This obviously won't _fix_ anything, but at least it should make it
clear it's not that recent change that broke things - that just
happened to expose it. And hopefully somebody who knows that driver
will do the proper fixmap thing (or just ioremap once at probe time,
rather than at run-time).

Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:20:40AM -0700, Linus Torvalds wrote:
> I think this whole driver is garbage.

This "driver" was supposed to implement the handle-hw-errors-in-fw glue
crap. The thing is, no one has been using it properly because there's
not even a single firmware vendor who has managed to produce a working
fw glue reporting errors properly. At least I haven't seen one.

Which means, no one is really using this. And now ARM start using it for
real and shit hits fan.

And I'd love to fix it but finding a box which *actually* has a usable
GHES glue is, as I mentioned above, almost impossible so testing fixes
would be hard. I need to figure out something...

Thanks.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:20:40AM -0700, Linus Torvalds wrote:
> I think this whole driver is garbage.

This "driver" was supposed to implement the handle-hw-errors-in-fw glue
crap. The thing is, no one has been using it properly because there's
not even a single firmware vendor who has managed to produce a working
fw glue reporting errors properly. At least I haven't seen one.

Which means, no one is really using this. And now ARM start using it for
real and shit hits fan.

And I'd love to fix it but finding a box which *actually* has a usable
GHES glue is, as I mentioned above, almost impossible so testing fixes
would be hard. I need to figure out something...

Thanks.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 4:05 AM, Borislav Petkov  wrote:
>
> Looks like Tyler broke it:
>
> 77b246b32b2c ("acpi: apei: check for pending errors when probing GHES 
> entries")
>
> and it went into 4.13 and -stable.

I think this whole driver is garbage.

It does ioremap_page_range() in both NMI and irq context.

The fact that it triggers at probe time is just pure luck, and is
probably because at that point we don't happen to have the page tables
for the ioremap set up yet, so it actually does an allocation, which
is what then causes the warning.

But we should have warned much eariler, and this code has apparently
never worked right.

The driver is COMPLETELY broken. It needs to do the ioremap not at
interrupt time, but when setting up the device, and outside a
spinlock.

I think somebody must have known how broken this whole thing was,
because it literally uses a RAW spinloick, and I suspect the reason
for that is because lockdep complained about the breakage without it.

Reverting just the latest addition is not going to help. The breakage
is much more fundamental than that.

Note that doing this thing in NMI context is *really* wrong, because
the whole ioremap() code is definitely not NMI-safe. I don't think
it's irq-safe either.

I will add a "might_sleep()" to ioremap_page_range() itself, so that
we get this warning more reliably and much eailer. Right now it has
been hidden by the fact that most of the time the time the page tables
may be already allocated, but even then it's broken.

The only safe way to do that kind of access is likely using the FIXMAP model.

 Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Linus Torvalds]

On Mon, Oct 30, 2017 at 4:05 AM, Borislav Petkov  wrote:
>
> Looks like Tyler broke it:
>
> 77b246b32b2c ("acpi: apei: check for pending errors when probing GHES 
> entries")
>
> and it went into 4.13 and -stable.

I think this whole driver is garbage.

It does ioremap_page_range() in both NMI and irq context.

The fact that it triggers at probe time is just pure luck, and is
probably because at that point we don't happen to have the page tables
for the ioremap set up yet, so it actually does an allocation, which
is what then causes the warning.

But we should have warned much eariler, and this code has apparently
never worked right.

The driver is COMPLETELY broken. It needs to do the ioremap not at
interrupt time, but when setting up the device, and outside a
spinlock.

I think somebody must have known how broken this whole thing was,
because it literally uses a RAW spinloick, and I suspect the reason
for that is because lockdep complained about the breakage without it.

Reverting just the latest addition is not going to help. The breakage
is much more fundamental than that.

Note that doing this thing in NMI context is *really* wrong, because
the whole ioremap() code is definitely not NMI-safe. I don't think
it's irq-safe either.

I will add a "might_sleep()" to ioremap_page_range() itself, so that
we get this warning more reliably and much eailer. Right now it has
been hidden by the fact that most of the time the time the page tables
may be already allocated, but even then it's broken.

The only safe way to do that kind of access is likely using the FIXMAP model.

 Linus

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:17:27AM -0400, Tyler Baicar wrote:
> I'm okay with reverting this

Then please send a revert patch along with a cleaned up splat explaining why
we're reverting.

> and coming up with another solution, but that seems like it could be
> masking a problem.

Doh, the splat already told you what the problem is:

[   49.311408] BUG: sleeping function called from invalid context at 
mm/page_alloc.c:4150

you simply can't sleep in atomic context. GHES code better adhere to
that.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:17:27AM -0400, Tyler Baicar wrote:
> I'm okay with reverting this

Then please send a revert patch along with a cleaned up splat explaining why
we're reverting.

> and coming up with another solution, but that seems like it could be
> masking a problem.

Doh, the splat already told you what the problem is:

[   49.311408] BUG: sleeping function called from invalid context at 
mm/page_alloc.c:4150

you simply can't sleep in atomic context. GHES code better adhere to
that.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 10:06 AM, Borislav Petkov wrote:

On Mon, Oct 30, 2017 at 10:01:52AM -0400, Tyler Baicar wrote:

This is not as important for polling sources as it is for the
interrupt sources since polling sources are regularly checked and
shouldn't be used for fatal error scenarios. For interrupt driven
sources, there could already be a fatal error pending, so we should
handle it immediately.

Whatever it is, you can't call it there as it could deadlock. You need
to think about doing that differently. If you can't come up with a
solution quickly, it should be reverted and then you can try again
later.
I'm okay with reverting this and coming up with another solution, but that seems 
like it
could be masking a problem. It should be valid for the polling timer to expire 
right after

this probe function completes which would then trigger ghes_poll_func() to be 
called
and that calls into ghes_proc() immediately.

--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 10:06 AM, Borislav Petkov wrote:

On Mon, Oct 30, 2017 at 10:01:52AM -0400, Tyler Baicar wrote:

This is not as important for polling sources as it is for the
interrupt sources since polling sources are regularly checked and
shouldn't be used for fatal error scenarios. For interrupt driven
sources, there could already be a fatal error pending, so we should
handle it immediately.

Whatever it is, you can't call it there as it could deadlock. You need
to think about doing that differently. If you can't come up with a
solution quickly, it should be reverted and then you can try again
later.
I'm okay with reverting this and coming up with another solution, but that seems 
like it
could be masking a problem. It should be valid for the polling timer to expire 
right after

this probe function completes which would then trigger ghes_poll_func() to be 
called
and that calls into ghes_proc() immediately.

--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:01:52AM -0400, Tyler Baicar wrote:
> This is not as important for polling sources as it is for the
> interrupt sources since polling sources are regularly checked and
> shouldn't be used for fatal error scenarios. For interrupt driven
> sources, there could already be a fatal error pending, so we should
> handle it immediately.

Whatever it is, you can't call it there as it could deadlock. You need
to think about doing that differently. If you can't come up with a
solution quickly, it should be reverted and then you can try again
later.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 10:01:52AM -0400, Tyler Baicar wrote:
> This is not as important for polling sources as it is for the
> interrupt sources since polling sources are regularly checked and
> shouldn't be used for fatal error scenarios. For interrupt driven
> sources, there could already be a fatal error pending, so we should
> handle it immediately.

Whatever it is, you can't call it there as it could deadlock. You need
to think about doing that differently. If you can't come up with a
solution quickly, it should be reverted and then you can try again
later.

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 7:05 AM, Borislav Petkov wrote:

On Mon, Oct 30, 2017 at 12:18:35AM +0100, Fengguang Wu wrote:

CC related developers for the BUG in v4.14-rc6.

On Sun, Oct 29, 2017 at 11:51:55PM +0100, Fengguang Wu wrote:

Hi Linus,

Up to now we see the below boot error/warnings when testing v4.14-rc6.

They hit the RC release mainly due to various imperfections in 0day's
auto bisection. So I manually list them here and CC the likely easy to
debug ones to the corresponding maintainers in the followup emails.

boot_successes: 4700
boot_failures: 247

BUG:kernel_hang_in_test_stage: 152
BUG:kernel_reboot-without-warning_in_test_stage: 10
BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c: 1
BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c: 3
BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c: 21

Here is the dmesg fragment:

[   47.597981] clocksource: tsc: mask: 0x max_cycles: 
0x26d34d96462, max_idle_ns: 440795289520 ns
[   48.626601] clocksource: Switched to clocksource tsc
[   49.273620] ERST: Error Record Serialization Table (ERST) support is 
initialized.
[   49.290288] pstore: using zlib compression
[   49.299588] pstore: Registered erst as persistent store backend
[   49.311408] BUG: sleeping function called from invalid context at 
mm/page_alloc.c:4150
[   49.312031] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper/0
[   49.312031] CPU: 37 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc6 #1
[   49.312031] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS 
SE5C600.86B.02.02.0002.122320131210 12/23/2013
[   49.312031] Call Trace:
[   49.312031]  dump_stack+0x63/0x86
[   49.312031]  ___might_sleep+0xf1/0x110
[   49.312031]  __might_sleep+0x4a/0x80
[   49.312031]  __alloc_pages_nodemask+0x14e/0x270
[   49.312031]  alloc_page_interleave+0x17/0x80
[   49.312031]  alloc_pages_current+0xc8/0xe0
[   49.312031]  __get_free_pages+0xe/0x40
[   49.312031]  pte_alloc_one_kernel+0x15/0x20
[   49.312031]  __pte_alloc_kernel+0x1d/0x100
[   49.312031]  ioremap_page_range+0x330/0x3a0
[   49.312031]  ghes_copy_tofrom_phys+0x182/0x2b0
[   49.312031]  ghes_read_estatus+0x76/0x140
[   49.312031]  ghes_proc+0x1c/0x130
[   49.312031]  ghes_probe+0x157/0x430
[   49.312031]  platform_drv_probe+0x3b/0xa0
[   49.312031]  driver_probe_device+0x29c/0x450
[   49.312031]  __driver_attach+0xdf/0xf0
[   49.312031]  ? driver_probe_device+0x450/0x450
[   49.312031]  bus_for_each_dev+0x60/0xa0
[   49.312031]  driver_attach+0x1e/0x20
[   49.312031]  bus_add_driver+0x170/0x260
[   49.312031]  ? set_debug_rodata+0x17/0x17
[   49.312031]  driver_register+0x60/0xe0
[   49.312031]  __platform_driver_register+0x36/0x40
[   49.312031]  ghes_init+0x10f/0x199
[   49.312031]  ? bert_init+0x215/0x215
[   49.312031]  do_one_initcall+0x43/0x170
[   49.312031]  ? set_debug_rodata+0x17/0x17
[   49.312031]  kernel_init_freeable+0x198/0x220
[   49.312031]  ? rest_init+0xd0/0xd0
[   49.312031]  kernel_init+0xe/0x101
[   49.312031]  ret_from_fork+0x25/0x30
[   49.670116] GHES: APEI firmware first mode is enabled by APEI bit and WHEA 
_OSC.
[   49.691436] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[   49.729954] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 
16550A
[   49.767235] Non-volatile memory driver v1.3
[   49.778363] Linux agpgart interface v0.103

Looks like Tyler broke it:

77b246b32b2c ("acpi: apei: check for pending errors when probing GHES entries")

and it went into 4.13 and -stable.

Tyler, why is it so important to do the polling immediately upon
registration? Can't we wait until the polling does it?
This is not as important for polling sources as it is for the interrupt sources 
since polling sources
are regularly checked and shouldn't be used for fatal error scenarios. For 
interrupt driven sources,
there could already be a fatal error pending, so we should handle it 
immediately. Also, it's possible
that the interrupt was cleared because it happened prior to GHES probing so then 
the error
wouldn't get serviced. Example of that would be interrupts handled through the 
GED driver.


--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Tyler Baicar]

On 10/30/2017 7:05 AM, Borislav Petkov wrote:

On Mon, Oct 30, 2017 at 12:18:35AM +0100, Fengguang Wu wrote:

CC related developers for the BUG in v4.14-rc6.

On Sun, Oct 29, 2017 at 11:51:55PM +0100, Fengguang Wu wrote:

Hi Linus,

Up to now we see the below boot error/warnings when testing v4.14-rc6.

They hit the RC release mainly due to various imperfections in 0day's
auto bisection. So I manually list them here and CC the likely easy to
debug ones to the corresponding maintainers in the followup emails.

boot_successes: 4700
boot_failures: 247

BUG:kernel_hang_in_test_stage: 152
BUG:kernel_reboot-without-warning_in_test_stage: 10
BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c: 1
BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c: 3
BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c: 21

Here is the dmesg fragment:

[   47.597981] clocksource: tsc: mask: 0x max_cycles: 
0x26d34d96462, max_idle_ns: 440795289520 ns
[   48.626601] clocksource: Switched to clocksource tsc
[   49.273620] ERST: Error Record Serialization Table (ERST) support is 
initialized.
[   49.290288] pstore: using zlib compression
[   49.299588] pstore: Registered erst as persistent store backend
[   49.311408] BUG: sleeping function called from invalid context at 
mm/page_alloc.c:4150
[   49.312031] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper/0
[   49.312031] CPU: 37 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc6 #1
[   49.312031] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS 
SE5C600.86B.02.02.0002.122320131210 12/23/2013
[   49.312031] Call Trace:
[   49.312031]  dump_stack+0x63/0x86
[   49.312031]  ___might_sleep+0xf1/0x110
[   49.312031]  __might_sleep+0x4a/0x80
[   49.312031]  __alloc_pages_nodemask+0x14e/0x270
[   49.312031]  alloc_page_interleave+0x17/0x80
[   49.312031]  alloc_pages_current+0xc8/0xe0
[   49.312031]  __get_free_pages+0xe/0x40
[   49.312031]  pte_alloc_one_kernel+0x15/0x20
[   49.312031]  __pte_alloc_kernel+0x1d/0x100
[   49.312031]  ioremap_page_range+0x330/0x3a0
[   49.312031]  ghes_copy_tofrom_phys+0x182/0x2b0
[   49.312031]  ghes_read_estatus+0x76/0x140
[   49.312031]  ghes_proc+0x1c/0x130
[   49.312031]  ghes_probe+0x157/0x430
[   49.312031]  platform_drv_probe+0x3b/0xa0
[   49.312031]  driver_probe_device+0x29c/0x450
[   49.312031]  __driver_attach+0xdf/0xf0
[   49.312031]  ? driver_probe_device+0x450/0x450
[   49.312031]  bus_for_each_dev+0x60/0xa0
[   49.312031]  driver_attach+0x1e/0x20
[   49.312031]  bus_add_driver+0x170/0x260
[   49.312031]  ? set_debug_rodata+0x17/0x17
[   49.312031]  driver_register+0x60/0xe0
[   49.312031]  __platform_driver_register+0x36/0x40
[   49.312031]  ghes_init+0x10f/0x199
[   49.312031]  ? bert_init+0x215/0x215
[   49.312031]  do_one_initcall+0x43/0x170
[   49.312031]  ? set_debug_rodata+0x17/0x17
[   49.312031]  kernel_init_freeable+0x198/0x220
[   49.312031]  ? rest_init+0xd0/0xd0
[   49.312031]  kernel_init+0xe/0x101
[   49.312031]  ret_from_fork+0x25/0x30
[   49.670116] GHES: APEI firmware first mode is enabled by APEI bit and WHEA 
_OSC.
[   49.691436] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[   49.729954] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 
16550A
[   49.767235] Non-volatile memory driver v1.3
[   49.778363] Linux agpgart interface v0.103

Looks like Tyler broke it:

77b246b32b2c ("acpi: apei: check for pending errors when probing GHES entries")

and it went into 4.13 and -stable.

Tyler, why is it so important to do the polling immediately upon
registration? Can't we wait until the polling does it?
This is not as important for polling sources as it is for the interrupt sources 
since polling sources
are regularly checked and shouldn't be used for fatal error scenarios. For 
interrupt driven sources,
there could already be a fatal error pending, so we should handle it 
immediately. Also, it's possible
that the interrupt was cleared because it happened prior to GHES probing so then 
the error
wouldn't get serviced. Example of that would be interrupts handled through the 
GED driver.


--
Qualcomm Datacenter Technologies, Inc. as an affiliate of Qualcomm 
Technologies, Inc.
Qualcomm Technologies, Inc. is a member of the Code Aurora Forum,
a Linux Foundation Collaborative Project.

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 12:18:35AM +0100, Fengguang Wu wrote:
> CC related developers for the BUG in v4.14-rc6.
> 
> On Sun, Oct 29, 2017 at 11:51:55PM +0100, Fengguang Wu wrote:
> > Hi Linus,
> > 
> > Up to now we see the below boot error/warnings when testing v4.14-rc6.
> > 
> > They hit the RC release mainly due to various imperfections in 0day's
> > auto bisection. So I manually list them here and CC the likely easy to
> > debug ones to the corresponding maintainers in the followup emails.
> > 
> > boot_successes: 4700
> > boot_failures: 247
> > 
> > BUG:kernel_hang_in_test_stage: 152
> > BUG:kernel_reboot-without-warning_in_test_stage: 10
> > BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c:
> >  1
> > BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c:
> >  3
> > BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c: 21
> 
> Here is the dmesg fragment:
> 
> [   47.597981] clocksource: tsc: mask: 0x max_cycles: 
> 0x26d34d96462, max_idle_ns: 440795289520 ns
> [   48.626601] clocksource: Switched to clocksource tsc
> [   49.273620] ERST: Error Record Serialization Table (ERST) support is 
> initialized.
> [   49.290288] pstore: using zlib compression
> [   49.299588] pstore: Registered erst as persistent store backend
> [   49.311408] BUG: sleeping function called from invalid context at 
> mm/page_alloc.c:4150
> [   49.312031] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper/0
> [   49.312031] CPU: 37 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc6 #1
> [   49.312031] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS 
> SE5C600.86B.02.02.0002.122320131210 12/23/2013
> [   49.312031] Call Trace:
> [   49.312031]  dump_stack+0x63/0x86
> [   49.312031]  ___might_sleep+0xf1/0x110
> [   49.312031]  __might_sleep+0x4a/0x80
> [   49.312031]  __alloc_pages_nodemask+0x14e/0x270
> [   49.312031]  alloc_page_interleave+0x17/0x80
> [   49.312031]  alloc_pages_current+0xc8/0xe0
> [   49.312031]  __get_free_pages+0xe/0x40
> [   49.312031]  pte_alloc_one_kernel+0x15/0x20
> [   49.312031]  __pte_alloc_kernel+0x1d/0x100
> [   49.312031]  ioremap_page_range+0x330/0x3a0
> [   49.312031]  ghes_copy_tofrom_phys+0x182/0x2b0
> [   49.312031]  ghes_read_estatus+0x76/0x140
> [   49.312031]  ghes_proc+0x1c/0x130
> [   49.312031]  ghes_probe+0x157/0x430
> [   49.312031]  platform_drv_probe+0x3b/0xa0
> [   49.312031]  driver_probe_device+0x29c/0x450
> [   49.312031]  __driver_attach+0xdf/0xf0
> [   49.312031]  ? driver_probe_device+0x450/0x450
> [   49.312031]  bus_for_each_dev+0x60/0xa0
> [   49.312031]  driver_attach+0x1e/0x20
> [   49.312031]  bus_add_driver+0x170/0x260
> [   49.312031]  ? set_debug_rodata+0x17/0x17
> [   49.312031]  driver_register+0x60/0xe0
> [   49.312031]  __platform_driver_register+0x36/0x40
> [   49.312031]  ghes_init+0x10f/0x199
> [   49.312031]  ? bert_init+0x215/0x215
> [   49.312031]  do_one_initcall+0x43/0x170
> [   49.312031]  ? set_debug_rodata+0x17/0x17
> [   49.312031]  kernel_init_freeable+0x198/0x220
> [   49.312031]  ? rest_init+0xd0/0xd0
> [   49.312031]  kernel_init+0xe/0x101
> [   49.312031]  ret_from_fork+0x25/0x30
> [   49.670116] GHES: APEI firmware first mode is enabled by APEI bit and WHEA 
> _OSC.
> [   49.691436] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
> [   49.729954] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 
> 16550A
> [   49.767235] Non-volatile memory driver v1.3
> [   49.778363] Linux agpgart interface v0.103

Looks like Tyler broke it:

77b246b32b2c ("acpi: apei: check for pending errors when probing GHES entries")

and it went into 4.13 and -stable.

Tyler, why is it so important to do the polling immediately upon
registration? Can't we wait until the polling does it?

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
-- 

Re: [ghes_copy_tofrom_phys] BUG: sleeping function called from invalid context at mm/page_alloc.c:4150

[Borislav Petkov]

On Mon, Oct 30, 2017 at 12:18:35AM +0100, Fengguang Wu wrote:
> CC related developers for the BUG in v4.14-rc6.
> 
> On Sun, Oct 29, 2017 at 11:51:55PM +0100, Fengguang Wu wrote:
> > Hi Linus,
> > 
> > Up to now we see the below boot error/warnings when testing v4.14-rc6.
> > 
> > They hit the RC release mainly due to various imperfections in 0day's
> > auto bisection. So I manually list them here and CC the likely easy to
> > debug ones to the corresponding maintainers in the followup emails.
> > 
> > boot_successes: 4700
> > boot_failures: 247
> > 
> > BUG:kernel_hang_in_test_stage: 152
> > BUG:kernel_reboot-without-warning_in_test_stage: 10
> > BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c:
> >  1
> > BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c:
> >  3
> > BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c: 21
> 
> Here is the dmesg fragment:
> 
> [   47.597981] clocksource: tsc: mask: 0x max_cycles: 
> 0x26d34d96462, max_idle_ns: 440795289520 ns
> [   48.626601] clocksource: Switched to clocksource tsc
> [   49.273620] ERST: Error Record Serialization Table (ERST) support is 
> initialized.
> [   49.290288] pstore: using zlib compression
> [   49.299588] pstore: Registered erst as persistent store backend
> [   49.311408] BUG: sleeping function called from invalid context at 
> mm/page_alloc.c:4150
> [   49.312031] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper/0
> [   49.312031] CPU: 37 PID: 1 Comm: swapper/0 Not tainted 4.14.0-rc6 #1
> [   49.312031] Hardware name: Intel Corporation S2600WP/S2600WP, BIOS 
> SE5C600.86B.02.02.0002.122320131210 12/23/2013
> [   49.312031] Call Trace:
> [   49.312031]  dump_stack+0x63/0x86
> [   49.312031]  ___might_sleep+0xf1/0x110
> [   49.312031]  __might_sleep+0x4a/0x80
> [   49.312031]  __alloc_pages_nodemask+0x14e/0x270
> [   49.312031]  alloc_page_interleave+0x17/0x80
> [   49.312031]  alloc_pages_current+0xc8/0xe0
> [   49.312031]  __get_free_pages+0xe/0x40
> [   49.312031]  pte_alloc_one_kernel+0x15/0x20
> [   49.312031]  __pte_alloc_kernel+0x1d/0x100
> [   49.312031]  ioremap_page_range+0x330/0x3a0
> [   49.312031]  ghes_copy_tofrom_phys+0x182/0x2b0
> [   49.312031]  ghes_read_estatus+0x76/0x140
> [   49.312031]  ghes_proc+0x1c/0x130
> [   49.312031]  ghes_probe+0x157/0x430
> [   49.312031]  platform_drv_probe+0x3b/0xa0
> [   49.312031]  driver_probe_device+0x29c/0x450
> [   49.312031]  __driver_attach+0xdf/0xf0
> [   49.312031]  ? driver_probe_device+0x450/0x450
> [   49.312031]  bus_for_each_dev+0x60/0xa0
> [   49.312031]  driver_attach+0x1e/0x20
> [   49.312031]  bus_add_driver+0x170/0x260
> [   49.312031]  ? set_debug_rodata+0x17/0x17
> [   49.312031]  driver_register+0x60/0xe0
> [   49.312031]  __platform_driver_register+0x36/0x40
> [   49.312031]  ghes_init+0x10f/0x199
> [   49.312031]  ? bert_init+0x215/0x215
> [   49.312031]  do_one_initcall+0x43/0x170
> [   49.312031]  ? set_debug_rodata+0x17/0x17
> [   49.312031]  kernel_init_freeable+0x198/0x220
> [   49.312031]  ? rest_init+0xd0/0xd0
> [   49.312031]  kernel_init+0xe/0x101
> [   49.312031]  ret_from_fork+0x25/0x30
> [   49.670116] GHES: APEI firmware first mode is enabled by APEI bit and WHEA 
> _OSC.
> [   49.691436] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
> [   49.729954] 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 
> 16550A
> [   49.767235] Non-volatile memory driver v1.3
> [   49.778363] Linux agpgart interface v0.103

Looks like Tyler broke it:

77b246b32b2c ("acpi: apei: check for pending errors when probing GHES entries")

and it went into 4.13 and -stable.

Tyler, why is it so important to do the polling immediately upon
registration? Can't we wait until the polling does it?

-- 
Regards/Gruss,
Boris.

SUSE Linux GmbH, GF: Felix Imendörffer, Jane Smithard, Graham Norton, HRB 21284 
(AG Nürnberg)
--