Re: ~90s shutdown delay with v6.19 and PREEMPT_RT
From: Bert Karwatzki
Date: Mon Feb 23 2026 - 18:43:20 EST
As the bisection in suggested that commit9311e6c29b34 ("cgroup: Fix sleeping from invalid context warning on PREEMPT_RT")
is somehow causing the problem I put some printk()s in the code changed by this
commit and captured the output via netconsole (I tried using trace_printk() to
use the persistent ringbuffer but got no output).
This is the debug patch (for v6.19):
commit 655ad0d7ce2d03b1b8bfbc2a3e6c36b46a4604c5
Author: Bert Karwatzki <spasswolf@xxxxxx>
Date: Mon Feb 23 21:49:47 2026 +0100
cgroup: add printk() cgroup_task_dead for PREEMPT_RT
Signed-off-by: Bert Karwatzki <spasswolf@xxxxxx>
diff --git a/kernel/cgroup/cgroup.c b/kernel/cgroup/cgroup.c
index 5f0d33b04910..16bb40df5dd0 100644
--- a/kernel/cgroup/cgroup.c
+++ b/kernel/cgroup/cgroup.c
@@ -7029,6 +7029,7 @@ 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) {
@@ -7050,6 +7051,7 @@ static void __init cgroup_rt_init(void)
void cgroup_task_dead(struct task_struct *task)
{
+ printk(KERN_INFO "%s: task = %s\n", __func__, 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));
This is the output captured via netconsole after rebooting via
# echo reboot > /dev/kmsg && reboot
2026-02-24T00:17:38.836655+01:00 localhost 12,5335,211298089,-,caller=T3211;reboot
2026-02-24T00:17:38.848658+01:00 localhost 6,5336,211309667,-,caller=T0;cgroup_task_dead: task = reboot
2026-02-24T00:17:38.848658+01:00 localhost 6,5337,211310223,-,caller=T50;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:38.852694+01:00 localhost 6,5338,211313770,-,caller=T0;cgroup_task_dead: task = gmain
2026-02-24T00:17:38.852694+01:00 localhost 6,5339,211313776,-,caller=T0;cgroup_task_dead: task = xfce4-sess:cs0
2026-02-24T00:17:38.852694+01:00 localhost 6,5340,211313798,-,caller=T0;cgroup_task_dead: task = xfce4-sess:sh0
2026-02-24T00:17:38.852694+01:00 localhost 6,5341,211313810,-,caller=T0;cgroup_task_dead: task = xfce4-:sh_opt0
2026-02-24T00:17:38.852694+01:00 localhost 6,5342,211313830,-,caller=T0;cgroup_task_dead: task = xfce4-:traceq0
2026-02-24T00:17:38.852694+01:00 localhost 6,5343,211313840,-,caller=T0;cgroup_task_dead: task = pool-spawner
2026-02-24T00:17:38.852694+01:00 localhost 6,5344,211313839,-,caller=T0;cgroup_task_dead: task = xfce4-:traceq0
2026-02-24T00:17:38.852694+01:00 localhost 6,5345,211313868,-,caller=T0;cgroup_task_dead: task = xfce4-session
2026-02-24T00:17:38.852694+01:00 localhost 6,5346,211313871,-,caller=T0;cgroup_task_dead: task = xfce4-:traceq0
2026-02-24T00:17:38.852694+01:00 localhost 6,5347,211313874,-,caller=T0;cgroup_task_dead: task = xfce4-s:disk$0
[...]
Here comes the part which shows the delay (I did not remove any message here):
2026-02-24T00:17:40.964180+01:00 localhost 6,6838,213423568,-,caller=T0;cgroup_task_dead: task = (sd-close)
2026-02-24T00:17:40.964244+01:00 localhost 6,6839,213423756,-,caller=T0;cgroup_task_dead: task = systemctl
2026-02-24T00:17:40.964576+01:00 localhost 6,6840,213424221,-,caller=T34;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:40.964649+01:00 localhost 6,6841,213424221,-,caller=T23;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:40.964969+01:00 localhost 6,6842,213424435,-,caller=T0;cgroup_task_dead: task = (sd-close)
2026-02-24T00:17:40.965057+01:00 localhost 6,6843,213425219,-,caller=T50;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:44.025094+01:00 localhost 6,6844,216485806,-,caller=T0;cgroup_task_dead: task = (udev-worker)
2026-02-24T00:17:44.025094+01:00 localhost 6,6845,216485810,-,caller=T0;cgroup_task_dead: task = (udev-worker)
2026-02-24T00:17:44.025387+01:00 localhost 6,6846,216485816,-,caller=T0;cgroup_task_dead: task = (udev-worker)
2026-02-24T00:17:44.025642+01:00 localhost 6,6847,216486228,-,caller=T66;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:44.025718+01:00 localhost 6,6848,216486239,-,caller=T122;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:17:44.025923+01:00 localhost 6,6849,216486239,-,caller=T82;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:19:11.070444+01:00 localhost 6,6850,303512419,-,caller=T0;cgroup_task_dead: task = systemd
2026-02-24T00:19:11.070444+01:00 localhost 6,6851,303513238,-,caller=T34;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:19:11.070725+01:00 localhost 6,6852,303513728,-,caller=T0;cgroup_task_dead: task = (sd-pam)
2026-02-24T00:19:11.070888+01:00 localhost 6,6853,303514010,-,caller=T0;cgroup_task_dead: task = (sd-close)
2026-02-24T00:19:11.071192+01:00 localhost 6,6854,303514221,-,caller=T90;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:19:11.071291+01:00 localhost 6,6855,303514238,-,caller=T50;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:19:11.071626+01:00 localhost 6,6856,303514629,-,caller=T0;cgroup_task_dead: task = (sd-close)
2026-02-24T00:19:11.072139+01:00 localhost 6,6857,303515237,-,caller=T50;cgrp_dead_tasks_iwork_fn:
2026-02-24T00:19:11.107473+01:00 localhost 6,6858,303549400,-,caller=T0;cgroup_task_dead: task = psimon
2026-02-24T00:19:11.107473+01:00 localhost 6,6859,303550244,-,caller=T66;cgrp_dead_tasks_iwork_fn:
[...]
I've tried this several times and the function calls just before the delay are always the same.
Bert Karwatzki