Initial booting is setting the task flag to idle (PF_IDLE) by the call path sched_init() -> init_idle(). Having the task idle and calling call_rcu() in kernel/rcu/tiny.c means that TIF_NEED_RESCHED will be set. Subsequent calls to any cond_resched() will enable IRQs, potentially earlier than the IRQ setup has completed. Recent changes have caused just this scenario and IRQs have been enabled early.
This causes a warning later in start_kernel() as interrupts are enabled before they are fully set up.
Fix this issue by clearing the PF_IDLE flag on return from sched_init() and restore the flag in rest_init(). Although the boot task was marked as idle since (at least) d80e4fda576d, I am not sure that it is wrong to do so. The forced context-switch on idle task was introduced in the tiny_rcu update, so I'm going to claim this fixes 5f6130fa52ee.
Link: https://lore.kernel.org/linux-mm/87v8cv22jh.fsf@mail.lhotse/ Link: https://lore.kernel.org/linux-mm/CAMuHMdWpvpWoDa=Ox-do92czYRvkok6_x6pYUH+Zou... Fixes: 5f6130fa52ee ("tiny_rcu: Directly force QS when call_rcu_[bh|sched]() on idle_task") Cc: stable@vger.kernel.org Cc: Geert Uytterhoeven geert@linux-m68k.org Cc: "Paul E. McKenney" paulmck@kernel.org Cc: Christophe Leroy christophe.leroy@csgroup.eu Cc: Andreas Schwab schwab@linux-m68k.org Cc: Matthew Wilcox willy@infradead.org Cc: Peng Zhang zhangpeng.00@bytedance.com Cc: Peter Zijlstra peterz@infradead.org Cc: Ingo Molnar mingo@redhat.com Cc: Juri Lelli juri.lelli@redhat.com Cc: Vincent Guittot vincent.guittot@linaro.org Cc: Andrew Morton akpm@linux-foundation.org Cc: "Mike Rapoport (IBM)" rppt@kernel.org Cc: Vlastimil Babka vbabka@suse.cz Signed-off-by: Liam R. Howlett Liam.Howlett@oracle.com --- init/main.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns); - tsk->flags |= PF_NO_SETAFFINITY; + tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
@@ -938,6 +938,8 @@ void start_kernel(void) * time - but meanwhile we still have a functioning scheduler. */ sched_init(); + /* Avoid early context switch, rest_init() restores PF_IDLE */ + current->flags &= ~PF_IDLE;
if (WARN(!irqs_disabled(), "Interrupts were enabled *very* early, fixing it\n"))
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
Initial booting is setting the task flag to idle (PF_IDLE) by the call path sched_init() -> init_idle(). Having the task idle and calling call_rcu() in kernel/rcu/tiny.c means that TIF_NEED_RESCHED will be set. Subsequent calls to any cond_resched() will enable IRQs, potentially earlier than the IRQ setup has completed. Recent changes have caused just this scenario and IRQs have been enabled early.
This causes a warning later in start_kernel() as interrupts are enabled before they are fully set up.
Fix this issue by clearing the PF_IDLE flag on return from sched_init() and restore the flag in rest_init(). Although the boot task was marked as idle since (at least) d80e4fda576d, I am not sure that it is wrong to do so. The forced context-switch on idle task was introduced in the tiny_rcu update, so I'm going to claim this fixes 5f6130fa52ee.
Link: https://lore.kernel.org/linux-mm/87v8cv22jh.fsf@mail.lhotse/ Link: https://lore.kernel.org/linux-mm/CAMuHMdWpvpWoDa=Ox-do92czYRvkok6_x6pYUH+Zou... Fixes: 5f6130fa52ee ("tiny_rcu: Directly force QS when call_rcu_[bh|sched]() on idle_task") Cc: stable@vger.kernel.org Cc: Geert Uytterhoeven geert@linux-m68k.org Cc: "Paul E. McKenney" paulmck@kernel.org Cc: Christophe Leroy christophe.leroy@csgroup.eu Cc: Andreas Schwab schwab@linux-m68k.org Cc: Matthew Wilcox willy@infradead.org Cc: Peng Zhang zhangpeng.00@bytedance.com Cc: Peter Zijlstra peterz@infradead.org Cc: Ingo Molnar mingo@redhat.com Cc: Juri Lelli juri.lelli@redhat.com Cc: Vincent Guittot vincent.guittot@linaro.org Cc: Andrew Morton akpm@linux-foundation.org Cc: "Mike Rapoport (IBM)" rppt@kernel.org Cc: Vlastimil Babka vbabka@suse.cz Signed-off-by: Liam R. Howlett Liam.Howlett@oracle.com
init/main.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
@@ -938,6 +938,8 @@ void start_kernel(void) * time - but meanwhile we still have a functioning scheduler. */ sched_init();
- /* Avoid early context switch, rest_init() restores PF_IDLE */
- current->flags &= ~PF_IDLE;
if (WARN(!irqs_disabled(), "Interrupts were enabled *very* early, fixing it\n"))
Hurmph... so since this is about IRQs, would it not make sense to have the | PF_IDLE near 'early_boot_irqs_disabled = false' ?
Or, alternatively, make the tinyrcu thing check that variable?
On Wed, Sep 13, 2023 at 01:01:39PM +0200, Peter Zijlstra wrote:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
Initial booting is setting the task flag to idle (PF_IDLE) by the call path sched_init() -> init_idle(). Having the task idle and calling call_rcu() in kernel/rcu/tiny.c means that TIF_NEED_RESCHED will be set. Subsequent calls to any cond_resched() will enable IRQs, potentially earlier than the IRQ setup has completed. Recent changes have caused just this scenario and IRQs have been enabled early.
This causes a warning later in start_kernel() as interrupts are enabled before they are fully set up.
Fix this issue by clearing the PF_IDLE flag on return from sched_init() and restore the flag in rest_init(). Although the boot task was marked as idle since (at least) d80e4fda576d, I am not sure that it is wrong to do so. The forced context-switch on idle task was introduced in the tiny_rcu update, so I'm going to claim this fixes 5f6130fa52ee.
Link: https://lore.kernel.org/linux-mm/87v8cv22jh.fsf@mail.lhotse/ Link: https://lore.kernel.org/linux-mm/CAMuHMdWpvpWoDa=Ox-do92czYRvkok6_x6pYUH+Zou... Fixes: 5f6130fa52ee ("tiny_rcu: Directly force QS when call_rcu_[bh|sched]() on idle_task") Cc: stable@vger.kernel.org Cc: Geert Uytterhoeven geert@linux-m68k.org Cc: "Paul E. McKenney" paulmck@kernel.org Cc: Christophe Leroy christophe.leroy@csgroup.eu Cc: Andreas Schwab schwab@linux-m68k.org Cc: Matthew Wilcox willy@infradead.org Cc: Peng Zhang zhangpeng.00@bytedance.com Cc: Peter Zijlstra peterz@infradead.org Cc: Ingo Molnar mingo@redhat.com Cc: Juri Lelli juri.lelli@redhat.com Cc: Vincent Guittot vincent.guittot@linaro.org Cc: Andrew Morton akpm@linux-foundation.org Cc: "Mike Rapoport (IBM)" rppt@kernel.org Cc: Vlastimil Babka vbabka@suse.cz Signed-off-by: Liam R. Howlett Liam.Howlett@oracle.com
init/main.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
@@ -938,6 +938,8 @@ void start_kernel(void) * time - but meanwhile we still have a functioning scheduler. */ sched_init();
- /* Avoid early context switch, rest_init() restores PF_IDLE */
- current->flags &= ~PF_IDLE;
if (WARN(!irqs_disabled(), "Interrupts were enabled *very* early, fixing it\n"))
Hurmph... so since this is about IRQs, would it not make sense to have the | PF_IDLE near 'early_boot_irqs_disabled = false' ?
Or, alternatively, make the tinyrcu thing check that variable?
We could do that, but do we really the decidedly non-idle early boot sequence designated as idle?
What surprises me is that this is just now showing up. The ingredients for this one have been in place for almost 10 years.
Thanx, Paul
* Paul E. McKenney paulmck@kernel.org [230913 07:28]:
On Wed, Sep 13, 2023 at 01:01:39PM +0200, Peter Zijlstra wrote:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
Initial booting is setting the task flag to idle (PF_IDLE) by the call path sched_init() -> init_idle(). Having the task idle and calling call_rcu() in kernel/rcu/tiny.c means that TIF_NEED_RESCHED will be set. Subsequent calls to any cond_resched() will enable IRQs, potentially earlier than the IRQ setup has completed. Recent changes have caused just this scenario and IRQs have been enabled early.
This causes a warning later in start_kernel() as interrupts are enabled before they are fully set up.
Fix this issue by clearing the PF_IDLE flag on return from sched_init() and restore the flag in rest_init(). Although the boot task was marked as idle since (at least) d80e4fda576d, I am not sure that it is wrong to do so. The forced context-switch on idle task was introduced in the tiny_rcu update, so I'm going to claim this fixes 5f6130fa52ee.
Link: https://lore.kernel.org/linux-mm/87v8cv22jh.fsf@mail.lhotse/ Link: https://lore.kernel.org/linux-mm/CAMuHMdWpvpWoDa=Ox-do92czYRvkok6_x6pYUH+Zou... Fixes: 5f6130fa52ee ("tiny_rcu: Directly force QS when call_rcu_[bh|sched]() on idle_task") Cc: stable@vger.kernel.org Cc: Geert Uytterhoeven geert@linux-m68k.org Cc: "Paul E. McKenney" paulmck@kernel.org Cc: Christophe Leroy christophe.leroy@csgroup.eu Cc: Andreas Schwab schwab@linux-m68k.org Cc: Matthew Wilcox willy@infradead.org Cc: Peng Zhang zhangpeng.00@bytedance.com Cc: Peter Zijlstra peterz@infradead.org Cc: Ingo Molnar mingo@redhat.com Cc: Juri Lelli juri.lelli@redhat.com Cc: Vincent Guittot vincent.guittot@linaro.org Cc: Andrew Morton akpm@linux-foundation.org Cc: "Mike Rapoport (IBM)" rppt@kernel.org Cc: Vlastimil Babka vbabka@suse.cz Signed-off-by: Liam R. Howlett Liam.Howlett@oracle.com
init/main.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-)
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
@@ -938,6 +938,8 @@ void start_kernel(void) * time - but meanwhile we still have a functioning scheduler. */ sched_init();
- /* Avoid early context switch, rest_init() restores PF_IDLE */
- current->flags &= ~PF_IDLE;
if (WARN(!irqs_disabled(), "Interrupts were enabled *very* early, fixing it\n"))
Hurmph... so since this is about IRQs, would it not make sense to have the | PF_IDLE near 'early_boot_irqs_disabled = false' ?
I was thinking that this isn't an idle thread until the end of boot, so leave it set as not idle until the end.
Or, alternatively, make the tinyrcu thing check that variable?
We could do that, but do we really the decidedly non-idle early boot sequence designated as idle?
call_rcu() tiny is called more than this code, so unless there is another reason we want to check the IRQ status it seemed best to change the boot task flag. I mean, I think the is_idle_task() check is valid in every other context, right?
What surprises me is that this is just now showing up. The ingredients for this one have been in place for almost 10 years.
Am I just that lucky?
Cheers, Liam
Hi Liam,
On Wed, Sep 13, 2023 at 2:57 AM Liam R. Howlett Liam.Howlett@oracle.com wrote:
Initial booting is setting the task flag to idle (PF_IDLE) by the call path sched_init() -> init_idle(). Having the task idle and calling call_rcu() in kernel/rcu/tiny.c means that TIF_NEED_RESCHED will be set. Subsequent calls to any cond_resched() will enable IRQs, potentially earlier than the IRQ setup has completed. Recent changes have caused just this scenario and IRQs have been enabled early.
This causes a warning later in start_kernel() as interrupts are enabled before they are fully set up.
Fix this issue by clearing the PF_IDLE flag on return from sched_init() and restore the flag in rest_init(). Although the boot task was marked as idle since (at least) d80e4fda576d, I am not sure that it is wrong to do so. The forced context-switch on idle task was introduced in the tiny_rcu update, so I'm going to claim this fixes 5f6130fa52ee.
Link: https://lore.kernel.org/linux-mm/87v8cv22jh.fsf@mail.lhotse/ Link: https://lore.kernel.org/linux-mm/CAMuHMdWpvpWoDa=Ox-do92czYRvkok6_x6pYUH+Zou... Fixes: 5f6130fa52ee ("tiny_rcu: Directly force QS when call_rcu_[bh|sched]() on idle_task") Cc: stable@vger.kernel.org Cc: Geert Uytterhoeven geert@linux-m68k.org Cc: "Paul E. McKenney" paulmck@kernel.org Cc: Christophe Leroy christophe.leroy@csgroup.eu Cc: Andreas Schwab schwab@linux-m68k.org Cc: Matthew Wilcox willy@infradead.org Cc: Peng Zhang zhangpeng.00@bytedance.com Cc: Peter Zijlstra peterz@infradead.org Cc: Ingo Molnar mingo@redhat.com Cc: Juri Lelli juri.lelli@redhat.com Cc: Vincent Guittot vincent.guittot@linaro.org Cc: Andrew Morton akpm@linux-foundation.org Cc: "Mike Rapoport (IBM)" rppt@kernel.org Cc: Vlastimil Babka vbabka@suse.cz Signed-off-by: Liam R. Howlett Liam.Howlett@oracle.com
Thanks for your patch!
This fixes the
WARNING: CPU: 0 PID: 0 at init/main.c:992 start_kernel+0x2f0/0x480
I was seeing during boot on Renesas RZ/A1 and RZ/A2 since commit cfeb6ae8bcb96ccf ("maple_tree: disable mas_wr_append() when other readers are possible") in v6.5.
However, this causes lots of new warnings on e.g. R-Car M2-W, which wasn't affected before, like:
+BUG: sleeping function called from invalid context at kernel/sched/completion.c:111 +in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 1, name: swapper/0 +preempt_count: 0, expected: 0 +no locks held by swapper/0/1. +CPU: 0 PID: 1 Comm: swapper/0 Tainted: G W 6.6.0-rc1-koelsch-02359-g9a5bed6a8bd8 #1864 +Hardware name: Generic R-Car Gen2 (Flattened Device Tree) + unwind_backtrace from show_stack+0x10/0x14 + show_stack from dump_stack_lvl+0x68/0x90 + dump_stack_lvl from __might_resched+0x1b0/0x22c + __might_resched from __wait_for_common+0x38/0x170 + __wait_for_common from kernel_init+0x10/0x130 + kernel_init from ret_from_fork+0x14/0x30 +Exception stack(0xf0815fb0 to 0xf0815ff8) +5fa0: 00000000 00000000 00000000 00000000 +5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 +5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
and
+BUG: sleeping function called from invalid context at kernel/locking/mutex.c:580 +in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 1, name: systemd +preempt_count: 0, expected: 0 +no locks held by systemd/1. +CPU: 1 PID: 1 Comm: systemd Tainted: G W N 6.6.0-rc1-koelsch-02359-g9a5bed6a8bd8 #1864 +Hardware name: Generic R-Car Gen2 (Flattened Device Tree) + unwind_backtrace from show_stack+0x10/0x14 + show_stack from dump_stack_lvl+0x68/0x90 + dump_stack_lvl from __might_resched+0x1b0/0x22c + __might_resched from __mutex_lock+0x34/0x3a8 + __mutex_lock from mutex_lock_nested+0x18/0x20 + mutex_lock_nested from do_epoll_wait+0x220/0x5ac + do_epoll_wait from sys_epoll_wait+0x44/0x6c + sys_epoll_wait from ret_fast_syscall+0x0/0x1c +Exception stack(0xf0815fa8 to 0xf0815ff0) +5fa0: beff75e0 00000004 00000004 beff75e0 0000003b ffffffff +5fc0: beff75e0 00000004 ffffffff 000000fc 00000000 ffffffff 0000003b 00000004 +5fe0: 000000fc beff75b8 b6ef8511 b6e75786
Gr{oetje,eeting}s,
Geert
-- Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org
In personal conversations with technical people, I call myself a hacker. But when I'm talking to journalists I just say "programmer" or something like that. -- Linus Torvalds
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
Hmm, isn't that pid-1 you're setting PF_IDLE on?
The task becoming idle is 'current' at this point, see the cpu_startup_entry() call below.
Would not something like so be the right thing?
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 2299a5cfbfb9..802551e0009b 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -9269,7 +9269,7 @@ void __init init_idle(struct task_struct *idle, int cpu) * PF_KTHREAD should already be set at this point; regardless, make it * look like a proper per-CPU kthread. */ - idle->flags |= PF_IDLE | PF_KTHREAD | PF_NO_SETAFFINITY; + idle->flags |= PF_KTHREAD | PF_NO_SETAFFINITY; kthread_set_per_cpu(idle, cpu);
#ifdef CONFIG_SMP diff --git a/kernel/sched/idle.c b/kernel/sched/idle.c index 342f58a329f5..5007b25c5bc6 100644 --- a/kernel/sched/idle.c +++ b/kernel/sched/idle.c @@ -373,6 +373,7 @@ EXPORT_SYMBOL_GPL(play_idle_precise);
void cpu_startup_entry(enum cpuhp_state state) { + current->flags |= PF_IDLE; arch_cpu_idle_prepare(); cpuhp_online_idle(state); while (1)
* Peter Zijlstra peterz@infradead.org [230913 09:53]:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
Hmm, isn't that pid-1 you're setting PF_IDLE on?
Yes, thanks. I think that is what Geert is hitting with my patch.
debug __might_resched() in kernel/sched/core.c is failing to return in that first (complex) if statement. His report says pid 1 so this is likely the issue.
The task becoming idle is 'current' at this point, see the cpu_startup_entry() call below.
Would not something like so be the right thing?
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 2299a5cfbfb9..802551e0009b 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -9269,7 +9269,7 @@ void __init init_idle(struct task_struct *idle, int cpu) * PF_KTHREAD should already be set at this point; regardless, make it * look like a proper per-CPU kthread. */
- idle->flags |= PF_IDLE | PF_KTHREAD | PF_NO_SETAFFINITY;
- idle->flags |= PF_KTHREAD | PF_NO_SETAFFINITY;
I am concerned this will alter more than just the current task, which would mean more modifications later. There is a comment about it being called 'more than once' and 'per cpu' so I am hesitant to change the function itself.
Although I am unsure of the call path.. fork_idle() -> init_idle() I guess?
kthread_set_per_cpu(idle, cpu); #ifdef CONFIG_SMP diff --git a/kernel/sched/idle.c b/kernel/sched/idle.c index 342f58a329f5..5007b25c5bc6 100644 --- a/kernel/sched/idle.c +++ b/kernel/sched/idle.c @@ -373,6 +373,7 @@ EXPORT_SYMBOL_GPL(play_idle_precise); void cpu_startup_entry(enum cpuhp_state state) {
- current->flags |= PF_IDLE; arch_cpu_idle_prepare(); cpuhp_online_idle(state); while (1)
On Wed, Sep 13, 2023 at 10:51:25AM -0400, Liam R. Howlett wrote:
- Peter Zijlstra peterz@infradead.org [230913 09:53]:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
Hmm, isn't that pid-1 you're setting PF_IDLE on?
Yes, thanks. I think that is what Geert is hitting with my patch.
debug __might_resched() in kernel/sched/core.c is failing to return in that first (complex) if statement. His report says pid 1 so this is likely the issue.
The task becoming idle is 'current' at this point, see the cpu_startup_entry() call below.
Would not something like so be the right thing?
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 2299a5cfbfb9..802551e0009b 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -9269,7 +9269,7 @@ void __init init_idle(struct task_struct *idle, int cpu) * PF_KTHREAD should already be set at this point; regardless, make it * look like a proper per-CPU kthread. */
- idle->flags |= PF_IDLE | PF_KTHREAD | PF_NO_SETAFFINITY;
- idle->flags |= PF_KTHREAD | PF_NO_SETAFFINITY;
I am concerned this will alter more than just the current task, which would mean more modifications later. There is a comment about it being called 'more than once' and 'per cpu' so I am hesitant to change the function itself.
Although I am unsure of the call path.. fork_idle() -> init_idle() I guess?
There's only 2 ways to get into do_idle(), through cpu_startup_entry() and play_idle_precise(). The latter already frobs PF_IDLE since it is the forced idle path, this then leaves cpu_startup_entry() which is the regular idle path.
All idle threads will end up calling into it, the boot CPU through the rest_init() and the SMP cpus through arch SMP bringup.
IOW, this ensures all idle loops will have PF_IDLE set but not the pre-idle loop setup code these threads run.
* Peter Zijlstra peterz@infradead.org [230913 12:13]:
On Wed, Sep 13, 2023 at 10:51:25AM -0400, Liam R. Howlett wrote:
- Peter Zijlstra peterz@infradead.org [230913 09:53]:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
Hmm, isn't that pid-1 you're setting PF_IDLE on?
Yes, thanks. I think that is what Geert is hitting with my patch.
debug __might_resched() in kernel/sched/core.c is failing to return in that first (complex) if statement. His report says pid 1 so this is likely the issue.
The task becoming idle is 'current' at this point, see the cpu_startup_entry() call below.
Would not something like so be the right thing?
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 2299a5cfbfb9..802551e0009b 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -9269,7 +9269,7 @@ void __init init_idle(struct task_struct *idle, int cpu) * PF_KTHREAD should already be set at this point; regardless, make it * look like a proper per-CPU kthread. */
- idle->flags |= PF_IDLE | PF_KTHREAD | PF_NO_SETAFFINITY;
- idle->flags |= PF_KTHREAD | PF_NO_SETAFFINITY;
I am concerned this will alter more than just the current task, which would mean more modifications later. There is a comment about it being called 'more than once' and 'per cpu' so I am hesitant to change the function itself.
Although I am unsure of the call path.. fork_idle() -> init_idle() I guess?
There's only 2 ways to get into do_idle(), through cpu_startup_entry() and play_idle_precise(). The latter already frobs PF_IDLE since it is the forced idle path, this then leaves cpu_startup_entry() which is the regular idle path.
All idle threads will end up calling into it, the boot CPU through the rest_init() and the SMP cpus through arch SMP bringup.
IOW, this ensures all idle loops will have PF_IDLE set but not the pre-idle loop setup code these threads run.
Thanks for the information. This does leave the init_idle() function in the odd state of not setting PF_IDLE, but I guess that's okay?
On Wed, Sep 13, 2023 at 01:32:38PM -0400, Liam R. Howlett wrote:
- Peter Zijlstra peterz@infradead.org [230913 12:13]:
On Wed, Sep 13, 2023 at 10:51:25AM -0400, Liam R. Howlett wrote:
- Peter Zijlstra peterz@infradead.org [230913 09:53]:
On Tue, Sep 12, 2023 at 08:56:47PM -0400, Liam R. Howlett wrote:
diff --git a/init/main.c b/init/main.c index ad920fac325c..f74772acf612 100644 --- a/init/main.c +++ b/init/main.c @@ -696,7 +696,7 @@ noinline void __ref __noreturn rest_init(void) */ rcu_read_lock(); tsk = find_task_by_pid_ns(pid, &init_pid_ns);
- tsk->flags |= PF_NO_SETAFFINITY;
- tsk->flags |= PF_NO_SETAFFINITY | PF_IDLE; set_cpus_allowed_ptr(tsk, cpumask_of(smp_processor_id())); rcu_read_unlock();
Hmm, isn't that pid-1 you're setting PF_IDLE on?
Yes, thanks. I think that is what Geert is hitting with my patch.
debug __might_resched() in kernel/sched/core.c is failing to return in that first (complex) if statement. His report says pid 1 so this is likely the issue.
The task becoming idle is 'current' at this point, see the cpu_startup_entry() call below.
Would not something like so be the right thing?
diff --git a/kernel/sched/core.c b/kernel/sched/core.c index 2299a5cfbfb9..802551e0009b 100644 --- a/kernel/sched/core.c +++ b/kernel/sched/core.c @@ -9269,7 +9269,7 @@ void __init init_idle(struct task_struct *idle, int cpu) * PF_KTHREAD should already be set at this point; regardless, make it * look like a proper per-CPU kthread. */
- idle->flags |= PF_IDLE | PF_KTHREAD | PF_NO_SETAFFINITY;
- idle->flags |= PF_KTHREAD | PF_NO_SETAFFINITY;
I am concerned this will alter more than just the current task, which would mean more modifications later. There is a comment about it being called 'more than once' and 'per cpu' so I am hesitant to change the function itself.
Although I am unsure of the call path.. fork_idle() -> init_idle() I guess?
There's only 2 ways to get into do_idle(), through cpu_startup_entry() and play_idle_precise(). The latter already frobs PF_IDLE since it is the forced idle path, this then leaves cpu_startup_entry() which is the regular idle path.
All idle threads will end up calling into it, the boot CPU through the rest_init() and the SMP cpus through arch SMP bringup.
IOW, this ensures all idle loops will have PF_IDLE set but not the pre-idle loop setup code these threads run.
Thanks for the information. This does leave the init_idle() function in the odd state of not setting PF_IDLE, but I guess that's okay?
Yep, the few things that care about PF_IDLE seem to really only care about do_idle() and very much not (per the rcutiny thing) any code that comes before it.
Hello,
kernel test robot noticed "BUG:sleeping_function_called_from_invalid_context_at_kernel/sched/completion.c" on:
commit: afa19b70494c22ba27224f90c0805e88e5db41e1 ("[PATCH] init/main: Clear boot task idle flag") url: https://github.com/intel-lab-lkp/linux/commits/Liam-R-Howlett/init-main-Clea... base: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git 3669558bdf354cd352be955ef2764cde6a9bf5ec patch link: https://lore.kernel.org/all/20230913005647.1534747-1-Liam.Howlett@oracle.com... patch subject: [PATCH] init/main: Clear boot task idle flag
in testcase: boot
compiler: gcc-12 test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
besides BUG:sleeping_function_called_from_invalid_context_at_kernel/sched/completion.c, we also observed other issues on this commit but clean on parent:
3669558bdf354cd3 afa19b70494c22ba27224f90c08 ---------------- --------------------------- fail:runs %reproduction fail:runs | | | :6 17% 1:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_drivers/dma-buf/selftest.c :6 17% 1:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_drivers/net/ethernet/intel/e1000_hw.c :6 100% 6:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_include/linux/sched/mm.h :6 83% 5:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c :6 50% 3:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c :6 17% 1:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_kernel/rcu/tree.c :6 100% 6:6 dmesg.BUG:sleeping_function_called_from_invalid_context_at_kernel/sched/completion.c :6 100% 6:6 dmesg.RIP:__do_softirq :6 100% 6:6 dmesg.RIP:__flush_smp_call_function_queue :6 33% 2:6 dmesg.RIP:__handle_irq_event_percpu :6 100% 6:6 dmesg.RIP:__hrtimer_run_queues :6 100% 6:6 dmesg.RIP:__note_gp_changes :6 100% 6:6 dmesg.RIP:__queue_work :6 100% 6:6 dmesg.RIP:__raise_softirq_irqoff :6 100% 6:6 dmesg.RIP:__run_timers :6 100% 6:6 dmesg.RIP:__smp_call_single_queue :6 100% 6:6 dmesg.RIP:__sysvec_apic_timer_interrupt :6 100% 6:6 dmesg.RIP:__sysvec_call_function_single :6 50% 3:6 dmesg.RIP:__update_load_avg_blocked_se :6 100% 6:6 dmesg.RIP:__update_load_avg_cfs_rq :6 100% 6:6 dmesg.RIP:__update_load_avg_se :6 100% 6:6 dmesg.RIP:__wake_nocb_gp :6 67% 4:6 dmesg.RIP:_raw_spin_unlock_irqrestore :6 100% 6:6 dmesg.RIP:arch_ftrace_ops_list_func :6 100% 6:6 dmesg.RIP:attach_entity_load_avg :6 100% 6:6 dmesg.RIP:call_timer_fn :6 100% 6:6 dmesg.RIP:default_idle :6 100% 6:6 dmesg.RIP:dequeue_task_fair :6 100% 6:6 dmesg.RIP:detach_entity_load_avg :6 33% 2:6 dmesg.RIP:detach_if_pending :6 67% 4:6 dmesg.RIP:dma_fence_signal_timestamp_locked :6 33% 2:6 dmesg.RIP:do_nocb_deferred_wakeup :6 100% 6:6 dmesg.RIP:do_nocb_deferred_wakeup_timer :6 100% 6:6 dmesg.RIP:enqueue_hrtimer :6 100% 6:6 dmesg.RIP:enqueue_task_fair :6 100% 6:6 dmesg.RIP:enqueue_timer :6 17% 1:6 dmesg.RIP:hrtimer_init :6 67% 4:6 dmesg.RIP:load_balance :6 100% 6:6 dmesg.RIP:lock_acquire :6 100% 6:6 dmesg.RIP:lock_acquired :6 100% 6:6 dmesg.RIP:lock_contended :6 100% 6:6 dmesg.RIP:lock_release :6 33% 2:6 dmesg.RIP:printk_sprint :6 17% 1:6 dmesg.RIP:rcu_barrier_trace :6 100% 6:6 dmesg.RIP:rcu_core :6 100% 6:6 dmesg.RIP:rcu_is_cpu_rrupt_from_idle :6 83% 5:6 dmesg.RIP:rcu_qs :6 100% 6:6 dmesg.RIP:rcu_report_qs_rnp :6 100% 6:6 dmesg.RIP:rcu_sched_clock_irq :6 50% 3:6 dmesg.RIP:resched_curr :6 100% 6:6 dmesg.RIP:set_task_cpu :6 100% 6:6 dmesg.RIP:trace_hardirqs_off :6 100% 6:6 dmesg.RIP:trace_hardirqs_off_finish :6 100% 6:6 dmesg.RIP:trace_hardirqs_on :6 100% 6:6 dmesg.RIP:trace_reschedule_entry :6 100% 6:6 dmesg.RIP:trace_reschedule_exit :6 100% 6:6 dmesg.RIP:try_to_wake_up :6 100% 6:6 dmesg.RIP:ttwu_do_activate :6 100% 6:6 dmesg.RIP:update_cpu_capacity :6 100% 6:6 dmesg.RIP:update_curr :6 100% 6:6 dmesg.RIP:update_dl_rq_load_avg :6 100% 6:6 dmesg.RIP:update_irq_load_avg :6 100% 6:6 dmesg.RIP:update_rt_rq_load_avg :6 100% 6:6 dmesg.RIP:update_sd_lb_stats :6 17% 1:6 dmesg.RIP:wake_up_nohz_cpu :6 100% 6:6 dmesg.WARNING:at_arch/x86/include/asm/trace/irq_vectors.h:#__sysvec_apic_timer_interrupt :6 100% 6:6 dmesg.WARNING:at_arch/x86/include/asm/trace/irq_vectors.h:#__sysvec_call_function_single :6 100% 6:6 dmesg.WARNING:at_arch/x86/include/asm/trace/irq_vectors.h:#trace_reschedule_entry :6 100% 6:6 dmesg.WARNING:at_arch/x86/include/asm/trace/irq_vectors.h:#trace_reschedule_exit :6 100% 6:6 dmesg.WARNING:at_include/linux/trace_recursion.h:#arch_ftrace_ops_list_func :6 100% 6:6 dmesg.WARNING:at_include/trace/events/csd.h:#__flush_smp_call_function_queue :6 67% 4:6 dmesg.WARNING:at_include/trace/events/dma_fence.h:#dma_fence_signal_timestamp_locked :6 100% 6:6 dmesg.WARNING:at_include/trace/events/ipi.h:#__smp_call_single_queue :6 50% 3:6 dmesg.WARNING:at_include/trace/events/ipi.h:#resched_curr :6 17% 1:6 dmesg.WARNING:at_include/trace/events/ipi.h:#wake_up_nohz_cpu :6 100% 6:6 dmesg.WARNING:at_include/trace/events/irq.h:#__do_softirq :6 33% 2:6 dmesg.WARNING:at_include/trace/events/irq.h:#__handle_irq_event_percpu :6 100% 6:6 dmesg.WARNING:at_include/trace/events/irq.h:#__raise_softirq_irqoff :6 100% 6:6 dmesg.WARNING:at_include/trace/events/lock.h:#lock_acquire :6 100% 6:6 dmesg.WARNING:at_include/trace/events/lock.h:#lock_acquired :6 100% 6:6 dmesg.WARNING:at_include/trace/events/lock.h:#lock_contended :6 100% 6:6 dmesg.WARNING:at_include/trace/events/lock.h:#lock_release :6 100% 6:6 dmesg.WARNING:at_include/trace/events/preemptirq.h:#trace_hardirqs_off :6 100% 6:6 dmesg.WARNING:at_include/trace/events/preemptirq.h:#trace_hardirqs_off_finish :6 100% 6:6 dmesg.WARNING:at_include/trace/events/preemptirq.h:#trace_hardirqs_on :6 33% 2:6 dmesg.WARNING:at_include/trace/events/printk.h:#printk_sprint :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#__note_gp_changes :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#__wake_nocb_gp :6 33% 2:6 dmesg.WARNING:at_include/trace/events/rcu.h:#do_nocb_deferred_wakeup :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#do_nocb_deferred_wakeup_timer :6 17% 1:6 dmesg.WARNING:at_include/trace/events/rcu.h:#rcu_barrier_trace :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#rcu_core :6 83% 5:6 dmesg.WARNING:at_include/trace/events/rcu.h:#rcu_qs :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#rcu_report_qs_rnp :6 100% 6:6 dmesg.WARNING:at_include/trace/events/rcu.h:#rcu_sched_clock_irq :6 50% 3:6 dmesg.WARNING:at_include/trace/events/sched.h:#__update_load_avg_blocked_se :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#__update_load_avg_cfs_rq :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#__update_load_avg_se :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#attach_entity_load_avg :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#dequeue_task_fair :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#detach_entity_load_avg :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#enqueue_task_fair :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#set_task_cpu :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#try_to_wake_up :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#ttwu_do_activate :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_cpu_capacity :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_curr :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_dl_rq_load_avg :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_irq_load_avg :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_rt_rq_load_avg :6 100% 6:6 dmesg.WARNING:at_include/trace/events/sched.h:#update_sd_lb_stats :6 100% 6:6 dmesg.WARNING:at_include/trace/events/timer.h:#__hrtimer_run_queues :6 100% 6:6 dmesg.WARNING:at_include/trace/events/timer.h:#__run_timers :6 100% 6:6 dmesg.WARNING:at_include/trace/events/timer.h:#call_timer_fn :6 33% 2:6 dmesg.WARNING:at_include/trace/events/timer.h:#detach_if_pending :6 100% 6:6 dmesg.WARNING:at_include/trace/events/timer.h:#enqueue_hrtimer :6 100% 6:6 dmesg.WARNING:at_include/trace/events/timer.h:#enqueue_timer :6 17% 1:6 dmesg.WARNING:at_include/trace/events/timer.h:#hrtimer_init :6 100% 6:6 dmesg.WARNING:at_include/trace/events/workqueue.h:#__queue_work :6 100% 6:6 dmesg.WARNING:at_kernel/rcu/tree.c:#rcu_is_cpu_rrupt_from_idle :6 17% 1:6 dmesg.WARNING:inconsistent_lock_state :6 100% 6:6 dmesg.WARNING:suspicious_RCU_usage :6 33% 2:6 dmesg.arch/x86/kernel/irq.c:#IRQ_failed_to_wake_up_RCU :6 100% 6:6 dmesg.include/linux/cgroup.h:#suspicious_rcu_dereference_check()usage :6 100% 6:6 dmesg.include/linux/rcupdate.h:#rcu_read_lock()used_illegally_while_idle :6 100% 6:6 dmesg.include/linux/rcupdate.h:#rcu_read_unlock()used_illegally_while_idle :6 17% 1:6 dmesg.inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage :6 100% 6:6 dmesg.kernel/events/core.c:#suspicious_rcu_dereference_check()usage :6 83% 5:6 dmesg.kernel/exit.c:#suspicious_rcu_dereference_check()usage :6 100% 6:6 dmesg.kernel/rcu/tree.c:#RCU_dynticks_nmi_nesting_counter_underflow/zero :6 67% 4:6 dmesg.kernel/sched/core.c:#suspicious_rcu_dereference_check()usage :6 100% 6:6 dmesg.kernel/sched/fair.c:#suspicious_rcu_dereference_check()usage :6 83% 5:6 dmesg.kernel/workqueue.c:#RCU_or_wq_pool_mutex_should_be_held :6 83% 5:6 dmesg.kernel/workqueue.c:#suspicious_rcu_dereference_check()usage
If you fix the issue in a separate patch/commit (i.e. not just a new version of the same patch/commit), kindly add following tags | Reported-by: kernel test robot oliver.sang@intel.com | Closes: https://lore.kernel.org/oe-lkp/202309142334.a345320b-oliver.sang@intel.com
[ 2.318233][ T1] BUG: sleeping function called from invalid context at kernel/sched/completion.c:111 [ 2.318647][ T1] in_atomic(): 0, irqs_disabled(): 0, non_block: 0, pid: 1, name: swapper/0 [ 2.319725][ T1] preempt_count: 0, expected: 0 [ 2.320293][ T1] no locks held by swapper/0/1. [ 2.320882][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.6.0-rc1-00034-gafa19b70494c #1 [ 2.321957][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 [ 2.321957][ T1] Call Trace: [ 2.321957][ T1] <TASK> [ 2.321957][ T1] dump_stack_lvl (lib/dump_stack.c:107) [ 2.321957][ T1] __might_resched (kernel/sched/core.c:10188) [ 2.321957][ T1] ? sched_core_find (kernel/sched/core.c:10142) [ 2.321957][ T1] __wait_for_common (kernel/sched/completion.c:115) [ 2.321957][ T1] ? usleep_range_state (kernel/time/timer.c:2129) [ 2.321957][ T1] ? reacquire_held_locks (kernel/locking/lockdep.c:5404) [ 2.321957][ T1] ? wait_for_completion_io_timeout (kernel/sched/completion.c:110) [ 2.321957][ T1] ? do_raw_spin_lock (kernel/locking/spinlock_debug.c:121) [ 2.321957][ T1] ? rest_init (init/main.c:1431) [ 2.321957][ T1] kernel_init (init/main.c:1439) [ 2.321957][ T1] ? _raw_spin_unlock_irq (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 include/linux/spinlock_api_smp.h:159 kernel/locking/spinlock.c:202) [ 2.321957][ T1] ret_from_fork (arch/x86/kernel/process.c:153) [ 2.321957][ T1] ? rest_init (init/main.c:1431) [ 2.321957][ T1] ret_from_fork_asm (arch/x86/entry/entry_64.S:312) [ 2.321957][ T1] </TASK> [ 2.322276][ T1] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (family: 0x6, model: 0x2a, stepping: 0x1) [ 2.327212][ T1] RCU Tasks: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1. [ 2.328461][ T1] RCU Tasks Rude: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1. [ 2.330045][ T1] RCU Tasks Trace: Setting shift to 1 and lim to 1 rcu_task_cb_adjust=1. [ 2.331385][ T1] Running RCU-tasks wait API self tests [ 2.333117][ T1] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only. [ 2.334654][ T1] signal: max sigframe size: 1776 [ 2.335915][ T1] rcu: Hierarchical SRCU implementation. [ 2.336653][ T1] rcu: Max phase no-delay instances is 1000. [ 2.342550][ T14] Callback from call_rcu_tasks_trace() invoked. [ 2.344299][ T1] smp: Bringing up secondary CPUs ... [ 2.347251][ T1] smpboot: x86: Booting SMP configuration: [ 2.347999][ T1] .... node #0, CPUs: #1 [ 0.487313][ T0] masked ExtINT on CPU#1 [ 2.348624][ T0] ------------[ cut here ]------------ [ 2.348624][ T0] WARNING: CPU: 0 PID: 0 at include/trace/events/preemptirq.h:36 trace_hardirqs_off_finish (include/trace/events/preemptirq.h:36 include/trace/events/preemptirq.h:36 kernel/trace/trace_preemptirq.c:78 kernel/trace/trace_preemptirq.c:73) [ 2.348624][ T0] Modules linked in: [ 2.348624][ T0] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 6.6.0-rc1-00034-gafa19b70494c #1 [ 2.348624][ T0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014 [ 2.348624][ T0] RIP: 0010:trace_hardirqs_off_finish (include/trace/events/preemptirq.h:36 include/trace/events/preemptirq.h:36 kernel/trace/trace_preemptirq.c:78 kernel/trace/trace_preemptirq.c:73) [ 2.348624][ T0] Code: 03 80 3c 02 00 75 2a 48 8b 7b 08 31 d2 48 89 ee e8 99 f4 ff ff 65 ff 0d 0a 69 ce 7e e9 5d ff ff ff e8 38 18 e9 ff 84 c0 75 80 <0f> 0b e9 79 ff ff ff e8 c8 c0 3a 00 eb cf 66 0f 1f 44 00 00 65 8b All code ======== 0: 03 80 3c 02 00 75 add 0x7500023c(%rax),%eax 6: 2a 48 8b sub -0x75(%rax),%cl 9: 7b 08 jnp 0x13 b: 31 d2 xor %edx,%edx d: 48 89 ee mov %rbp,%rsi 10: e8 99 f4 ff ff call 0xfffffffffffff4ae 15: 65 ff 0d 0a 69 ce 7e decl %gs:0x7ece690a(%rip) # 0x7ece6926 1c: e9 5d ff ff ff jmp 0xffffffffffffff7e 21: e8 38 18 e9 ff call 0xffffffffffe9185e 26: 84 c0 test %al,%al 28: 75 80 jne 0xffffffffffffffaa 2a:* 0f 0b ud2 <-- trapping instruction 2c: e9 79 ff ff ff jmp 0xffffffffffffffaa 31: e8 c8 c0 3a 00 call 0x3ac0fe 36: eb cf jmp 0x7 38: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1) 3e: 65 gs 3f: 8b .byte 0x8b
Code starting with the faulting instruction =========================================== 0: 0f 0b ud2 2: e9 79 ff ff ff jmp 0xffffffffffffff80 7: e8 c8 c0 3a 00 call 0x3ac0d4 c: eb cf jmp 0xffffffffffffffdd e: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1) 14: 65 gs 15: 8b .byte 0x8b [ 2.348624][ T0] RSP: 0000:ffffffff84a07d60 EFLAGS: 00010046 [ 2.348624][ T0] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff81513ac2 [ 2.348624][ T0] RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff85a79540 [ 2.348624][ T0] RBP: ffffffff8352c418 R08: 0000000000000000 R09: fffffbfff0b4f2a8 [ 2.348624][ T0] R10: ffffffff85a79547 R11: 0000000000000000 R12: 0000000000000000 [ 2.348624][ T0] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000 [ 2.348624][ T0] FS: 0000000000000000(0000) GS:ffff8883aea00000(0000) knlGS:0000000000000000 [ 2.348624][ T0] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 2.348624][ T0] CR2: ffff88843ffff000 CR3: 0000000004a89000 CR4: 00000000000406f0 [ 2.348624][ T0] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 2.348624][ T0] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 2.348624][ T0] Call Trace: [ 2.348624][ T0] <TASK> [ 2.348624][ T0] ? __warn (kernel/panic.c:673) [ 2.348624][ T0] ? trace_hardirqs_off_finish (include/trace/events/preemptirq.h:36 include/trace/events/preemptirq.h:36 kernel/trace/trace_preemptirq.c:78 kernel/trace/trace_preemptirq.c:73) [ 2.348624][ T0] ? report_bug (lib/bug.c:180 lib/bug.c:219) [ 2.348624][ T0] ? handle_bug (arch/x86/kernel/traps.c:237) [ 2.348624][ T0] ? exc_invalid_op (arch/x86/kernel/traps.c:258 (discriminator 1)) [ 2.348624][ T0] ? asm_exc_invalid_op (arch/x86/include/asm/idtentry.h:568) [ 2.348624][ T0] ? irqentry_enter (kernel/entry/common.c:315) [ 2.348624][ T0] ? trace_hardirqs_off_finish (arch/x86/include/asm/bitops.h:228 arch/x86/include/asm/bitops.h:240 include/asm-generic/bitops/instrumented-non-atomic.h:142 include/linux/cpumask.h:504 include/linux/cpumask.h:1082 include/trace/events/preemptirq.h:36 kernel/trace/trace_preemptirq.c:78 kernel/trace/trace_preemptirq.c:73) [ 2.348624][ T0] ? trace_hardirqs_off_finish (include/trace/events/preemptirq.h:36 include/trace/events/preemptirq.h:36 kernel/trace/trace_preemptirq.c:78 kernel/trace/trace_preemptirq.c:73) [ 2.348624][ T0] irqentry_enter (kernel/entry/common.c:315) [ 2.348624][ T0] sysvec_call_function_single (arch/x86/kernel/smp.c:287) [ 2.348624][ T0] asm_sysvec_call_function_single (arch/x86/include/asm/idtentry.h:652) [ 2.348624][ T0] RIP: 0010:default_idle (arch/x86/include/asm/irqflags.h:37 arch/x86/include/asm/irqflags.h:72 arch/x86/kernel/process.c:750) [ 2.348624][ T0] Code: 07 76 e7 48 89 07 49 c7 c0 08 00 00 00 4d 29 c8 4c 01 c7 4c 29 c2 e9 72 ff ff ff cc cc cc cc eb 07 0f 00 2d 37 79 30 00 fb f4 <fa> c3 0f 1f 00 65 48 8b 04 25 40 a4 1f 00 f0 80 48 02 20 48 8b 10 All code ======== 0: 07 (bad) 1: 76 e7 jbe 0xffffffffffffffea 3: 48 89 07 mov %rax,(%rdi) 6: 49 c7 c0 08 00 00 00 mov $0x8,%r8 d: 4d 29 c8 sub %r9,%r8 10: 4c 01 c7 add %r8,%rdi 13: 4c 29 c2 sub %r8,%rdx 16: e9 72 ff ff ff jmp 0xffffffffffffff8d 1b: cc int3 1c: cc int3 1d: cc int3 1e: cc int3 1f: eb 07 jmp 0x28 21: 0f 00 2d 37 79 30 00 verw 0x307937(%rip) # 0x30795f 28: fb sti 29: f4 hlt 2a:* fa cli <-- trapping instruction 2b: c3 ret 2c: 0f 1f 00 nopl (%rax) 2f: 65 48 8b 04 25 40 a4 mov %gs:0x1fa440,%rax 36: 1f 00 38: f0 80 48 02 20 lock orb $0x20,0x2(%rax) 3d: 48 8b 10 mov (%rax),%rdx
Code starting with the faulting instruction =========================================== 0: fa cli 1: c3 ret 2: 0f 1f 00 nopl (%rax) 5: 65 48 8b 04 25 40 a4 mov %gs:0x1fa440,%rax c: 1f 00 e: f0 80 48 02 20 lock orb $0x20,0x2(%rax) 13: 48 8b 10 mov (%rax),%rdx [ 2.348624][ T0] RSP: 0000:ffffffff84a07e40 EFLAGS: 00000206 [ 2.348624][ T0] RAX: 0000000000003056 RBX: 0000000000000000 RCX: ffffffff8352c7ba [ 2.348624][ T0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff812e3bd3 [ 2.348624][ T0] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1075d7ed9d [ 2.348624][ T0] R10: ffff8883aebf6ceb R11: 0000000000000000 R12: 1ffffffff0940fca [ 2.348624][ T0] R13: ffffffff84a1e940 R14: dffffc0000000000 R15: 0000000000013f10 [ 2.348624][ T0] ? ct_kernel_exit+0xca/0x100 [ 2.348624][ T0] ? cpuidle_idle_call (kernel/sched/idle.c:171) [ 2.348624][ T0] default_idle_call (include/linux/cpuidle.h:143 kernel/sched/idle.c:98) [ 2.348624][ T0] cpuidle_idle_call (kernel/sched/idle.c:171) [ 2.348624][ T0] ? arch_cpu_idle_exit+0x30/0x30 [ 2.348624][ T0] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4565) [ 2.348624][ T0] do_idle (kernel/sched/idle.c:282) [ 2.348624][ T0] cpu_startup_entry (kernel/sched/idle.c:378 (discriminator 1)) [ 2.348624][ T0] rest_init (include/linux/rcupdate.h:750 init/main.c:697) [ 2.348624][ T0] arch_call_rest_init+0xf/0x20 [ 2.348624][ T0] start_kernel (init/main.c:1021 (discriminator 1)) [ 2.348624][ T0] x86_64_start_reservations (arch/x86/kernel/head64.c:544) [ 2.348624][ T0] x86_64_start_kernel (??:?) [ 2.348624][ T0] secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:433) [ 2.348624][ T0] </TASK> [ 2.348624][ T0] irq event stamp: 12375 [ 2.348624][ T0] hardirqs last enabled at (12374): cpuidle_idle_call (kernel/sched/idle.c:171) [ 2.348624][ T0] hardirqs last disabled at (12375): sysvec_call_function_single (arch/x86/kernel/smp.c:287) [ 2.348624][ T0] softirqs last enabled at (8563): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:400 kernel/softirq.c:582) [ 2.348624][ T0] softirqs last disabled at (8558): __irq_exit_rcu (kernel/softirq.c:427 kernel/softirq.c:632) [ 2.348624][ T0] ---[ end trace 0000000000000000 ]---
The kernel config and materials to reproduce are available at: https://download.01.org/0day-ci/archive/20230914/202309142334.a345320b-olive...
linux-stable-mirror@lists.linaro.org
-
Geert Uytterhoeven -
kernel test robot -
Liam R. Howlett -
Liam R. Howlett
-
Paul E. McKenney -
Peter Zijlstra