* [RFC] MIPS: smp: Sleeping func called from start_secondary()
@ 2024-08-02 8:45 Serge Semin
2024-08-02 9:43 ` Jiaxun Yang
0 siblings, 1 reply; 4+ messages in thread
From: Serge Semin @ 2024-08-02 8:45 UTC (permalink / raw)
To: Thomas Bogendoerfer, Jiaxun Yang, Thomas Gleixner
Cc: Serge Semin, Andrew Morton, Arnd Bergmann, Keguang Zhang,
Gregory CLEMENT, Théo Lebrun, Vladimir Kondratiev,
Tawfik Bayouk, Huacai Chen, linux-mips, linux-kernel
Hi folks,
To debug some another problem I recently enabled the
CONFIG_DEBUG_ATOMIC_SLEEP config for my SoC based on the 2xP5600 cores
with MIPS GIC as IRQ-controller. That caused the next BUG backtrace
started being printed to the system log during the device boot-up:
[ 0.118053] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:283
[ 0.118062] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 0, name: swapper/1
[ 0.118069] preempt_count: 1, expected: 0
[ 0.118074] RCU nest depth: 0, expected: 0
[ 0.118078] Preemption disabled at:
[ 0.118082] [<80105040>] arch_dup_task_struct+0x20/0x118
[ 0.118116] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted 6.11.0-rc1-bt1-00312-gca6f9469050c-dirty #2460
[ 0.118134] Stack : 816d0000 801b89bc 81870000 00000004 a02d0c08 00000000 84ae7dcc 801b84c0
[ 0.118167] 00000000 00000002 00000000 00000000 00000000 00000001 84ae7d70 84aaf200
[ 0.118195] 00000000 00000000 81115acc 00000000 00000059 84ae7bec 00000000 00000000
[ 0.118222] 00000000 ffffffff ffffffea 00000020 816d0000 00000000 81115acc 00000002
[ 0.118250] 00000000 04240021 a02d0c08 00000000 00000000 00000000 30400000 ac24242a
[ 0.118277] ...
[ 0.118286] Call Trace:
[ 0.118289] [<8010af2c>] show_stack+0x88/0x120
[ 0.118309] [<80f09dfc>] dump_stack_lvl+0x78/0xb0
[ 0.118323] [<801778d0>] __might_resched+0x190/0x1f0
[ 0.118349] [<80f10f80>] mutex_lock+0x20/0x74
[ 0.118365] [<801c8590>] irq_create_mapping_affinity+0x48/0x104
[ 0.118390] [<801121ec>] r4k_clockevent_init+0x58/0x38c
[ 0.118402] [<80116658>] start_secondary+0x34/0x134
[ 0.118411] [<80f0b1e4>] smp_bootstrap+0x68/0x98
[ 0.118424]
I managed to investigate the problem a bit and the reason turned out to be
in the irq_create_mapping() method eventually invoked in the framework of the
secondary CPU start-up procedure. The more detailed calls chain is:
start_secondary()
+-> mips_clockevent_init()
+-> r4k_clockevent_init()
+-> get_c0_compare_int()
+-> gic_get_c0_compare_int()
+-> irq_create_mapping()
+-> irq_create_mapping_affinity()
+-> mutex_lock()
+-> might_sleep()
+-> might_resched()
+-> __might_resched()
+-> Print the log above
I currently lack of free time for further investigation in an attempt to
find a reasonable solution. So here is just a report and a short summary
of the problem. Should you have any idea of how to fix the problem I'll be
very glad to test it out on a short notice.
-Serge(y)
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: [RFC] MIPS: smp: Sleeping func called from start_secondary()
2024-08-02 8:45 [RFC] MIPS: smp: Sleeping func called from start_secondary() Serge Semin
@ 2024-08-02 9:43 ` Jiaxun Yang
2024-08-02 9:53 ` Serge Semin
0 siblings, 1 reply; 4+ messages in thread
From: Jiaxun Yang @ 2024-08-02 9:43 UTC (permalink / raw)
To: Serge Semin, Thomas Bogendoerfer, Thomas Gleixner
Cc: Andrew Morton, Arnd Bergmann, Kelvin Cheung, Gregory CLEMENT,
Théo Lebrun, Vladimir Kondratiev, Tawfik Bayouk,
Huacai Chen, linux-mips, linux-kernel
在2024年8月2日八月 下午4:45，Serge Semin写道：
> Hi folks,
>
> To debug some another problem I recently enabled the
> CONFIG_DEBUG_ATOMIC_SLEEP config for my SoC based on the 2xP5600 cores
> with MIPS GIC as IRQ-controller. That caused the next BUG backtrace
> started being printed to the system log during the device boot-up:
Hi Serge,
Thanks for reporting the problem!
I actually have a patch lying around somewhere to convert cevt-r4k to use CPUHP
interface and avoid requesting interrupt on secondary CPUs.
Will post after getting more platform tests.
Thanks
- Jiaxun
>
> [ 0.118053] BUG: sleeping function called from invalid context at
> kernel/locking/mutex.c:283
> [ 0.118062] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid:
> 0, name: swapper/1
> [ 0.118069] preempt_count: 1, expected: 0
> [ 0.118074] RCU nest depth: 0, expected: 0
> [ 0.118078] Preemption disabled at:
> [ 0.118082] [<80105040>] arch_dup_task_struct+0x20/0x118
> [ 0.118116] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted
> 6.11.0-rc1-bt1-00312-gca6f9469050c-dirty #2460
> [ 0.118134] Stack : 816d0000 801b89bc 81870000 00000004 a02d0c08
> 00000000 84ae7dcc 801b84c0
> [ 0.118167] 00000000 00000002 00000000 00000000 00000000
> 00000001 84ae7d70 84aaf200
> [ 0.118195] 00000000 00000000 81115acc 00000000 00000059
> 84ae7bec 00000000 00000000
> [ 0.118222] 00000000 ffffffff ffffffea 00000020 816d0000
> 00000000 81115acc 00000002
> [ 0.118250] 00000000 04240021 a02d0c08 00000000 00000000
> 00000000 30400000 ac24242a
> [ 0.118277] ...
> [ 0.118286] Call Trace:
> [ 0.118289] [<8010af2c>] show_stack+0x88/0x120
> [ 0.118309] [<80f09dfc>] dump_stack_lvl+0x78/0xb0
> [ 0.118323] [<801778d0>] __might_resched+0x190/0x1f0
> [ 0.118349] [<80f10f80>] mutex_lock+0x20/0x74
> [ 0.118365] [<801c8590>] irq_create_mapping_affinity+0x48/0x104
> [ 0.118390] [<801121ec>] r4k_clockevent_init+0x58/0x38c
> [ 0.118402] [<80116658>] start_secondary+0x34/0x134
> [ 0.118411] [<80f0b1e4>] smp_bootstrap+0x68/0x98
> [ 0.118424]
>
> I managed to investigate the problem a bit and the reason turned out to be
> in the irq_create_mapping() method eventually invoked in the framework of the
> secondary CPU start-up procedure. The more detailed calls chain is:
> start_secondary()
> +-> mips_clockevent_init()
> +-> r4k_clockevent_init()
> +-> get_c0_compare_int()
> +-> gic_get_c0_compare_int()
> +-> irq_create_mapping()
> +-> irq_create_mapping_affinity()
> +-> mutex_lock()
> +-> might_sleep()
> +-> might_resched()
> +-> __might_resched()
> +-> Print the log above
>
> I currently lack of free time for further investigation in an attempt to
> find a reasonable solution. So here is just a report and a short summary
> of the problem. Should you have any idea of how to fix the problem I'll be
> very glad to test it out on a short notice.
>
> -Serge(y)
--
- Jiaxun
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [RFC] MIPS: smp: Sleeping func called from start_secondary()
2024-08-02 9:43 ` Jiaxun Yang
@ 2024-08-02 9:53 ` Serge Semin
2024-08-12 11:50 ` Jiaxun Yang
0 siblings, 1 reply; 4+ messages in thread
From: Serge Semin @ 2024-08-02 9:53 UTC (permalink / raw)
To: Jiaxun Yang
Cc: Thomas Bogendoerfer, Thomas Gleixner, Andrew Morton,
Arnd Bergmann, Kelvin Cheung, Gregory CLEMENT, Théo Lebrun,
Vladimir Kondratiev, Tawfik Bayouk, Huacai Chen, linux-mips,
linux-kernel
Hi Jiaxun
On Fri, Aug 02, 2024 at 05:43:45PM +0800, Jiaxun Yang wrote:
>
>
> 在2024年8月2日八月 下午4:45，Serge Semin写道：
> > Hi folks,
> >
> > To debug some another problem I recently enabled the
> > CONFIG_DEBUG_ATOMIC_SLEEP config for my SoC based on the 2xP5600 cores
> > with MIPS GIC as IRQ-controller. That caused the next BUG backtrace
> > started being printed to the system log during the device boot-up:
>
> Hi Serge,
>
> Thanks for reporting the problem!
>
> I actually have a patch lying around somewhere to convert cevt-r4k to use CPUHP
> interface and avoid requesting interrupt on secondary CPUs.
>
> Will post after getting more platform tests.
Great! Thanks. I'll test it out upon submission.
* Although I doubt that such (presumably) complicated change might be
considered as a backportable fix. But at least it shall fix the problem for the
mainline kernel.
Thanks,
-Serge(y)
>
> Thanks
> - Jiaxun
>
> >
> > [ 0.118053] BUG: sleeping function called from invalid context at
> > kernel/locking/mutex.c:283
> > [ 0.118062] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid:
> > 0, name: swapper/1
> > [ 0.118069] preempt_count: 1, expected: 0
> > [ 0.118074] RCU nest depth: 0, expected: 0
> > [ 0.118078] Preemption disabled at:
> > [ 0.118082] [<80105040>] arch_dup_task_struct+0x20/0x118
> > [ 0.118116] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted
> > 6.11.0-rc1-bt1-00312-gca6f9469050c-dirty #2460
> > [ 0.118134] Stack : 816d0000 801b89bc 81870000 00000004 a02d0c08
> > 00000000 84ae7dcc 801b84c0
> > [ 0.118167] 00000000 00000002 00000000 00000000 00000000
> > 00000001 84ae7d70 84aaf200
> > [ 0.118195] 00000000 00000000 81115acc 00000000 00000059
> > 84ae7bec 00000000 00000000
> > [ 0.118222] 00000000 ffffffff ffffffea 00000020 816d0000
> > 00000000 81115acc 00000002
> > [ 0.118250] 00000000 04240021 a02d0c08 00000000 00000000
> > 00000000 30400000 ac24242a
> > [ 0.118277] ...
> > [ 0.118286] Call Trace:
> > [ 0.118289] [<8010af2c>] show_stack+0x88/0x120
> > [ 0.118309] [<80f09dfc>] dump_stack_lvl+0x78/0xb0
> > [ 0.118323] [<801778d0>] __might_resched+0x190/0x1f0
> > [ 0.118349] [<80f10f80>] mutex_lock+0x20/0x74
> > [ 0.118365] [<801c8590>] irq_create_mapping_affinity+0x48/0x104
> > [ 0.118390] [<801121ec>] r4k_clockevent_init+0x58/0x38c
> > [ 0.118402] [<80116658>] start_secondary+0x34/0x134
> > [ 0.118411] [<80f0b1e4>] smp_bootstrap+0x68/0x98
> > [ 0.118424]
> >
> > I managed to investigate the problem a bit and the reason turned out to be
> > in the irq_create_mapping() method eventually invoked in the framework of the
> > secondary CPU start-up procedure. The more detailed calls chain is:
> > start_secondary()
> > +-> mips_clockevent_init()
> > +-> r4k_clockevent_init()
> > +-> get_c0_compare_int()
> > +-> gic_get_c0_compare_int()
> > +-> irq_create_mapping()
> > +-> irq_create_mapping_affinity()
> > +-> mutex_lock()
> > +-> might_sleep()
> > +-> might_resched()
> > +-> __might_resched()
> > +-> Print the log above
> >
> > I currently lack of free time for further investigation in an attempt to
> > find a reasonable solution. So here is just a report and a short summary
> > of the problem. Should you have any idea of how to fix the problem I'll be
> > very glad to test it out on a short notice.
> >
> > -Serge(y)
>
> --
> - Jiaxun
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [RFC] MIPS: smp: Sleeping func called from start_secondary()
2024-08-02 9:53 ` Serge Semin
@ 2024-08-12 11:50 ` Jiaxun Yang
0 siblings, 0 replies; 4+ messages in thread
From: Jiaxun Yang @ 2024-08-12 11:50 UTC (permalink / raw)
To: Serge Semin
Cc: Thomas Bogendoerfer, Thomas Gleixner, Andrew Morton,
Arnd Bergmann, Kelvin Cheung, Gregory CLEMENT, Théo Lebrun,
Vladimir Kondratiev, Tawfik Bayouk, Huacai Chen, linux-mips,
linux-kernel
在2024年8月2日八月 上午10:53，Serge Semin写道：
> Hi Jiaxun
>
> On Fri, Aug 02, 2024 at 05:43:45PM +0800, Jiaxun Yang wrote:
>>
>>
>> 在2024年8月2日八月 下午4:45，Serge Semin写道：
>> > Hi folks,
>> >
>> > To debug some another problem I recently enabled the
>> > CONFIG_DEBUG_ATOMIC_SLEEP config for my SoC based on the 2xP5600 cores
>> > with MIPS GIC as IRQ-controller. That caused the next BUG backtrace
>> > started being printed to the system log during the device boot-up:
>>
>> Hi Serge,
>>
>> Thanks for reporting the problem!
>>
>> I actually have a patch lying around somewhere to convert cevt-r4k to use CPUHP
>> interface and avoid requesting interrupt on secondary CPUs.
>>
>> Will post after getting more platform tests.
>
> Great! Thanks. I'll test it out upon submission.
>
> * Although I doubt that such (presumably) complicated change might be
> considered as a backportable fix. But at least it shall fix the problem for the
> mainline kernel.
It's actually harder than I expected, as managing it with percpu interrupt API would
break system sharing PCI with TI.
Maybe we need to come up a driver handle IRQ MUX.
Avoid calling get_c0_compare_int on secondary CPU init is easy, will post a patch.
Thanks
>
> Thanks,
> -Serge(y)
>
>>
>> Thanks
>> - Jiaxun
>>
>> >
>> > [ 0.118053] BUG: sleeping function called from invalid context at
>> > kernel/locking/mutex.c:283
>> > [ 0.118062] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid:
>> > 0, name: swapper/1
>> > [ 0.118069] preempt_count: 1, expected: 0
>> > [ 0.118074] RCU nest depth: 0, expected: 0
>> > [ 0.118078] Preemption disabled at:
>> > [ 0.118082] [<80105040>] arch_dup_task_struct+0x20/0x118
>> > [ 0.118116] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted
>> > 6.11.0-rc1-bt1-00312-gca6f9469050c-dirty #2460
>> > [ 0.118134] Stack : 816d0000 801b89bc 81870000 00000004 a02d0c08
>> > 00000000 84ae7dcc 801b84c0
>> > [ 0.118167] 00000000 00000002 00000000 00000000 00000000
>> > 00000001 84ae7d70 84aaf200
>> > [ 0.118195] 00000000 00000000 81115acc 00000000 00000059
>> > 84ae7bec 00000000 00000000
>> > [ 0.118222] 00000000 ffffffff ffffffea 00000020 816d0000
>> > 00000000 81115acc 00000002
>> > [ 0.118250] 00000000 04240021 a02d0c08 00000000 00000000
>> > 00000000 30400000 ac24242a
>> > [ 0.118277] ...
>> > [ 0.118286] Call Trace:
>> > [ 0.118289] [<8010af2c>] show_stack+0x88/0x120
>> > [ 0.118309] [<80f09dfc>] dump_stack_lvl+0x78/0xb0
>> > [ 0.118323] [<801778d0>] __might_resched+0x190/0x1f0
>> > [ 0.118349] [<80f10f80>] mutex_lock+0x20/0x74
>> > [ 0.118365] [<801c8590>] irq_create_mapping_affinity+0x48/0x104
>> > [ 0.118390] [<801121ec>] r4k_clockevent_init+0x58/0x38c
>> > [ 0.118402] [<80116658>] start_secondary+0x34/0x134
>> > [ 0.118411] [<80f0b1e4>] smp_bootstrap+0x68/0x98
>> > [ 0.118424]
>> >
>> > I managed to investigate the problem a bit and the reason turned out to be
>> > in the irq_create_mapping() method eventually invoked in the framework of the
>> > secondary CPU start-up procedure. The more detailed calls chain is:
>> > start_secondary()
>> > +-> mips_clockevent_init()
>> > +-> r4k_clockevent_init()
>> > +-> get_c0_compare_int()
>> > +-> gic_get_c0_compare_int()
>> > +-> irq_create_mapping()
>> > +-> irq_create_mapping_affinity()
>> > +-> mutex_lock()
>> > +-> might_sleep()
>> > +-> might_resched()
>> > +-> __might_resched()
>> > +-> Print the log above
>> >
>> > I currently lack of free time for further investigation in an attempt to
>> > find a reasonable solution. So here is just a report and a short summary
>> > of the problem. Should you have any idea of how to fix the problem I'll be
>> > very glad to test it out on a short notice.
>> >
>> > -Serge(y)
>>
>> --
>> - Jiaxun
--
- Jiaxun
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2024-08-12 11:50 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-08-02 8:45 [RFC] MIPS: smp: Sleeping func called from start_secondary() Serge Semin
2024-08-02 9:43 ` Jiaxun Yang
2024-08-02 9:53 ` Serge Semin
2024-08-12 11:50 ` Jiaxun Yang
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®