From: Bert Karwatzki <spasswolf@web.de>
To: Steven Rostedt <rostedt@goodmis.org>
Cc: Calvin Owens <calvin@wbinvd.org>,
"spasswolf@web.de Tejun Heo" <tj@kernel.org>,
Sebastian Andrzej Siewior <bigeasy@linutronix.de>,
Thomas Gleixner <tglx@linutronix.de>,
dschatzberg@meta.com, peterz@infradead.org,
linux-kernel@vger.kernel.org, linux-rt-devel@lists.linux.dev
Subject: Re: ~90s shutdown delay with v6.19 and PREEMPT_RT
Date: Tue, 24 Feb 2026 13:58:19 +0100 [thread overview]
Message-ID: <4570355cda2a669903e2f77bd14b55148fd0ed38.camel@web.de> (raw)
In-Reply-To: <e1375d364a2ec20b393b24740ee5df6d53e9f120.camel@web.de>
Am Dienstag, dem 24.02.2026 um 13:44 +0100 schrieb Bert Karwatzki:
> I've done some more monitoring with this debug patch which monitors
> cgroup_task_dead() and the function which calls it finish task switch.
> To avoid too many messages some printk()s are filtered by command name
> (a previous patch showed systemd to be the problematic process):
>
> diff --git a/kernel/cgroup/cgroup.c b/kernel/cgroup/cgroup.c
> index 5f0d33b04910..7bb6931a4d86 100644
> --- a/kernel/cgroup/cgroup.c
> +++ b/kernel/cgroup/cgroup.c
> @@ -6990,25 +6990,32 @@ static void do_cgroup_task_dead(struct task_struct *tsk)
> {
> struct css_set *cset;
> unsigned long flags;
> + printk(KERN_INFO "%s 0: task = %px\n", __func__, tsk);
>
> spin_lock_irqsave(&css_set_lock, flags);
>
> + printk(KERN_INFO "%s 1: task = %px\n", __func__, tsk);
> WARN_ON_ONCE(list_empty(&tsk->cg_list));
> cset = task_css_set(tsk);
> + printk(KERN_INFO "%s 2: task = %px\n", __func__, tsk);
> css_set_move_task(tsk, cset, NULL, false);
> + printk(KERN_INFO "%s 3: task = %px\n", __func__, tsk);
> cset->nr_tasks--;
> /* matches the signal->live check in css_task_iter_advance() */
> if (thread_group_leader(tsk) && atomic_read(&tsk->signal->live))
> list_add_tail(&tsk->cg_list, &cset->dying_tasks);
>
> + printk(KERN_INFO "%s 4: task = %px\n", __func__, tsk);
> if (dl_task(tsk))
> dec_dl_tasks_cs(tsk);
>
> + printk(KERN_INFO "%s 5: task = %px\n", __func__, tsk);
> WARN_ON_ONCE(cgroup_task_frozen(tsk));
> if (unlikely(!(tsk->flags & PF_KTHREAD) &&
> test_bit(CGRP_FREEZE, &task_dfl_cgroup(tsk)->flags)))
> cgroup_update_frozen(task_dfl_cgroup(tsk));
>
> + printk(KERN_INFO "%s 6: task = %px\n", __func__, tsk);
> spin_unlock_irqrestore(&css_set_lock, flags);
> }
>
> @@ -7029,9 +7036,11 @@ static void cgrp_dead_tasks_iwork_fn(struct irq_work *iwork)
> {
> struct llist_node *lnode;
> struct task_struct *task, *next;
> + printk(KERN_INFO "%s:\n", __func__);
>
> lnode = llist_del_all(this_cpu_ptr(&cgrp_dead_tasks));
> llist_for_each_entry_safe(task, next, lnode, cg_dead_lnode) {
> + printk(KERN_INFO "%s: %px %s", __func__, task, task->comm);
> do_cgroup_task_dead(task);
> put_task_struct(task);
> }
> @@ -7050,6 +7059,7 @@ static void __init cgroup_rt_init(void)
>
> void cgroup_task_dead(struct task_struct *task)
> {
> + printk(KERN_INFO "%s: task = %px (%s)\n", __func__, task, task->comm);
> get_task_struct(task);
> llist_add(&task->cg_dead_lnode, this_cpu_ptr(&cgrp_dead_tasks));
> irq_work_queue(this_cpu_ptr(&cgrp_dead_tasks_iwork));
> @@ -7059,6 +7069,7 @@ static void __init cgroup_rt_init(void) {}
>
> void cgroup_task_dead(struct task_struct *task)
> {
> + printk(KERN_INFO "%s: task = %px (%s)\n", __func__, task, task->comm);
> do_cgroup_task_dead(task);
> }
> #endif /* CONFIG_PREEMPT_RT */
> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index 854984967fe2..73e477d8cf1a 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -5078,6 +5078,8 @@ static struct rq *finish_task_switch(struct task_struct *prev)
> struct rq *rq = this_rq();
> struct mm_struct *mm = rq->prev_mm;
> unsigned int prev_state;
> + if (!strcmp(prev->comm, "systemd"))
> + printk(KERN_INFO "%s 0: %px\n", __func__, prev);
>
> /*
> * The previous task will have left us with a preempt_count of 2
> @@ -5144,15 +5146,18 @@ static struct rq *finish_task_switch(struct task_struct *prev)
> }
>
> if (unlikely(prev_state == TASK_DEAD)) {
> + printk(KERN_INFO "%s 1: %px (%s)\n", __func__, prev, prev->comm);
> if (prev->sched_class->task_dead)
> prev->sched_class->task_dead(prev);
>
> + printk(KERN_INFO "%s 2: %px (%s)\n", __func__, prev, prev->comm);
> /*
> * sched_ext_dead() must come before cgroup_task_dead() to
> * prevent cgroups from being removed while its member tasks are
> * visible to SCX schedulers.
> */
> sched_ext_dead(prev);
> + printk(KERN_INFO "%s 3: %px (%s)\n", __func__, prev, prev->comm);
> cgroup_task_dead(prev);
>
> /* Task is done with its stack. */
> @@ -5202,6 +5207,8 @@ static __always_inline struct rq *
> context_switch(struct rq *rq, struct task_struct *prev,
> struct task_struct *next, struct rq_flags *rf)
> {
> + if (!strcmp(prev->comm, "systemd"))
> + printk(KERN_INFO "%s 0: %px\n", __func__, prev);
> prepare_task_switch(rq, prev, next);
>
> /*
>
>
> I also tried monitoring the schedule_tail(), which is one of the two function calling
> finish_task_switch(), but that did get rid of the delay.
This is incorrect. Monitoring schedule_tail() does not undo the delayed shutdown, but
the delay probalbly has only 95% reproducability.
>
> The result from this is:
> 2026-02-24T13:13:21.739185+01:00 localhost 12,32039,34364889,-,caller=T2955;reboot
> [...]
> Here the delay section begins (all message here have comm == "systemd"):
> 2026-02-24T13:13:38.124013+01:00 localhost 6,45456,50748843,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.124234+01:00 localhost 6,45457,50748851,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.271984+01:00 localhost 6,45458,50896237,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.272255+01:00 localhost 6,45459,50896244,-,caller=T52;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.272556+01:00 localhost 6,45460,50896287,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.272759+01:00 localhost 6,45461,50896289,-,caller=T51;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.273225+01:00 localhost 6,45462,50896303,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.273406+01:00 localhost 6,45463,50896305,-,caller=T51;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.273819+01:00 localhost 6,45464,50896481,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.274025+01:00 localhost 6,45465,50896484,-,caller=T0;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:13:38.274465+01:00 localhost 6,45466,50896801,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.274635+01:00 localhost 6,45467,50896804,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.275034+01:00 localhost 6,45468,50897328,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.275254+01:00 localhost 6,45469,50897331,-,caller=T2077;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.275680+01:00 localhost 6,45470,50897600,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.275886+01:00 localhost 6,45471,50897602,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.276300+01:00 localhost 6,45472,50897936,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.276487+01:00 localhost 6,45473,50897939,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.276907+01:00 localhost 6,45474,50898225,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:13:38.279144+01:00 localhost 6,45475,50898228,-,caller=T68;finish_task_switch 0: ffff97fd40884300
>
> [...] 1505 similar lines removed
>
> 2026-02-24T13:14:54.000427+01:00 localhost 6,46981,126614226,-,caller=T44;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.000967+01:00 localhost 6,46982,126614420,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.001060+01:00 localhost 6,46983,126614422,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.001562+01:00 localhost 6,46984,126614462,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.001666+01:00 localhost 6,46985,126614463,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.002182+01:00 localhost 6,46986,126614533,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.002296+01:00 localhost 6,46987,126614534,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.002811+01:00 localhost 6,46988,126615219,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.002910+01:00 localhost 6,46989,126615221,-,caller=T42;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.003402+01:00 localhost 6,46990,126616376,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.003510+01:00 localhost 6,46991,126616378,-,caller=T0;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.004034+01:00 localhost 6,46992,126621884,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.004125+01:00 localhost 6,46993,126621887,-,caller=T0;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.004645+01:00 localhost 6,46994,126625311,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.004734+01:00 localhost 6,46995,126625314,-,caller=T235;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.013405+01:00 localhost 6,46996,126637601,-,caller=T1;context_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.013614+01:00 localhost 6,46997,126637603,-,caller=T0;finish_task_switch 0: ffff97fd40884300
> 2026-02-24T13:14:54.014165+01:00 localhost 6,46998,126638229,-,caller=T1573;context_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.014266+01:00 localhost 6,46999,126638232,-,caller=T44;finish_task_switch 0: ffff97fd46050000
> 2026-02-24T13:14:54.014774+01:00 localhost 6,47000,126638469,-,caller=T1573;context_switch 0: ffff97fd46050000 END
>
> So there's something strange going on here with the scheduler.
>
>
> Bert Karwatzki
next prev parent reply other threads:[~2026-02-24 12:58 UTC|newest]
Thread overview: 41+ messages / expand[flat|nested] mbox.gz Atom feed top
2025-11-04 18:11 DEBUG_ATOMIC_SLEEP spew in cgroup_task_dead() on next-20251104 Calvin Owens
2025-11-04 19:30 ` Tejun Heo
2025-11-05 15:16 ` Calvin Owens
2025-11-05 19:03 ` [PATCH cgroup/for-6.19] cgroup: Fix sleeping from invalid context warning on PREEMPT_RT Tejun Heo
2025-11-06 1:15 ` Calvin Owens
2025-11-06 17:36 ` Tejun Heo
2025-11-06 15:07 ` Sebastian Andrzej Siewior
2025-11-06 17:37 ` Tejun Heo
2025-11-06 17:46 ` Sebastian Andrzej Siewior
2025-11-06 17:55 ` Tejun Heo
2025-11-06 18:06 ` Sebastian Andrzej Siewior
2026-02-19 16:46 ` ~90s reboot delay with v6.19 and PREEMPT_RT Bert Karwatzki
2026-02-19 20:53 ` Calvin Owens
2026-02-19 23:10 ` Bert Karwatzki
2026-02-20 0:58 ` Steven Rostedt
2026-02-20 9:15 ` ~90s shutdown " Bert Karwatzki
2026-02-20 15:44 ` Steven Rostedt
2026-02-23 0:35 ` Bert Karwatzki
2026-02-23 8:22 ` Steven Rostedt
2026-02-23 13:36 ` Bert Karwatzki
2026-02-23 23:36 ` Bert Karwatzki
2026-02-24 12:44 ` Bert Karwatzki
2026-02-24 12:58 ` Bert Karwatzki [this message]
2026-02-24 14:20 ` Steven Rostedt
2026-02-24 15:45 ` ~90s reboot " Sebastian Andrzej Siewior
2026-02-25 15:43 ` Sebastian Andrzej Siewior
2026-02-25 16:37 ` Bert Karwatzki
2026-02-25 16:59 ` Sebastian Andrzej Siewior
2026-02-25 22:31 ` Sebastian Andrzej Siewior
2026-02-26 13:24 ` Bert Karwatzki
2026-02-26 13:46 ` Sebastian Andrzej Siewior
2026-02-26 16:37 ` Steven Rostedt
2026-02-27 14:13 ` Sebastian Andrzej Siewior
2026-02-27 22:57 ` Bert Karwatzki
2026-03-02 11:15 ` Sebastian Andrzej Siewior
2025-11-04 19:32 ` [PATCH cgroup/for-6.19 1/2] cgroup: Convert css_set_lock from spinlock_t to raw_spinlock_t Tejun Heo
2025-11-05 7:30 ` Sebastian Andrzej Siewior
2025-11-05 16:19 ` Tejun Heo
2025-11-05 8:50 ` Peter Zijlstra
2025-11-05 16:20 ` Tejun Heo
2025-11-04 19:32 ` [PATCH cgroup/for-6.19 2/2] cgroup: Convert css_set_lock locking to use cleanup guards Tejun Heo
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=4570355cda2a669903e2f77bd14b55148fd0ed38.camel@web.de \
--to=spasswolf@web.de \
--cc=bigeasy@linutronix.de \
--cc=calvin@wbinvd.org \
--cc=dschatzberg@meta.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-rt-devel@lists.linux.dev \
--cc=peterz@infradead.org \
--cc=rostedt@goodmis.org \
--cc=tglx@linutronix.de \
--cc=tj@kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
Powered by JetHome