Severe RT task scheduling delays due to repeated self-targeted scheduler push activity
Issue
- The issue appears as severe scheduling delays affecting real-time application tasks under high RT load.
- In the affected captures, application-task scheduling latency reached approximately 1–2 seconds, which was sufficient to trigger the application watchdog and terminate the container.
- The analysis of the scheduler trace data identifies a plausible scenario leading to the issue.
-
The trace directly confirms involvement of the rto_* path and shows rto_next_cpu() repeatedly selecting the current CPU when called from rto_push_irq_work_func(). This causes the push irq_work to be triggered repeatedly without successfully moving the RT task away.
-
For example:
<idle>-0 [017] dn.h3.. 282857.005584: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
and immediately again:
<idle>-0 [017] dn.h3.. 282857.005588: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
- A particularly clear consecutive block starts here:
<idle>-0 [017] dn.h2.. 282857.010700: rto_irq: (rto_push_irq_work_func+0x0/0x100)
<idle>-0 [017] dn.h3.. 282857.010701: pnpt: (push_rt_task.part.0+0x1e/0x3f0 <- pick_next_pushable_task) task=0xff21fc074291a340 pid=1298609 comm="rt_task_A" md=0 prio=49
<idle>-0 [017] dn.h3.. 282857.010702: rto_ent: (rto_next_cpu+0x0/0xa0) loop=-607552051 loopnext=-607552044 rtocpu=17 rtocount=1
<idle>-0 [017] dn.h3.. 282857.010703: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
<idle>-0 [017] dn.h2.. 282857.010704: rto_irq: (rto_push_irq_work_func+0x0/0x100)
<idle>-0 [017] dn.h3.. 282857.010705: pnpt: (push_rt_task.part.0+0x1e/0x3f0 <- pick_next_pushable_task) task=0xff21fc074291a340 pid=1298609 comm="rt_task_A" md=0 prio=49
<idle>-0 [017] dn.h3.. 282857.010706: rto_ent: (rto_next_cpu+0x0/0xa0) loop=-607552043 loopnext=-607552040 rtocpu=17 rtocount=2
<idle>-0 [017] dn.h3.. 282857.010707: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
<idle>-0 [017] dn.h2.. 282857.010709: rto_irq: (rto_push_irq_work_func+0x0/0x100)
<idle>-0 [017] dn.h3.. 282857.010709: pnpt: (push_rt_task.part.0+0x1e/0x3f0 <- pick_next_pushable_task) task=0xff21fc074291a340 pid=1298609 comm="rt_task_A" md=0 prio=49
<idle>-0 [017] dn.h3.. 282857.010709: rto_ent: (rto_next_cpu+0x0/0xa0) loop=-607552040 loopnext=-607552038 rtocpu=17 rtocount=1
<idle>-0 [017] dn.h3.. 282857.010710: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
and this continues repeatedly until:
<idle>-0 [017] dn.h3.. 282857.010743: rto_ent: (rto_next_cpu+0x0/0xa0) loop=-607551994 loopnext=-607551993 rtocpu=17 rtocount=1
<idle>-0 [017] dn.h3.. 282857.010743: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=17
<idle>-0 [017] dn.h2.. 282857.010744: rto_irq: (rto_push_irq_work_func+0x0/0x100)
<idle>-0 [017] dn.h3.. 282857.010744: pnpt: (push_rt_task.part.0+0x1e/0x3f0 <- pick_next_pushable_task) task=0xff21fc074291a340 pid=1298609 comm="rt_task_A" md=0 prio=49
<idle>-0 [017] dn.h3.. 282857.010745: rto_ent: (rto_next_cpu+0x0/0xa0) loop=-607551993 loopnext=-607551992 rtocpu=17 rtocount=2
<idle>-0 [017] dn.h3.. 282857.010746: rto_cpu: (rto_push_irq_work_func+0x73/0x100 <- rto_next_cpu) cpu=27
- The pattern involving "trace CPU: [017] rto_ent: rtocpu=17 rto_cpu: cpu=17" repeated many times.
Environment
- Red Hat OpenShift Container Platform 4.20
- Red Hat CoreOS 9.6.z branch RT kernels e.g., kernel-rt-core-5.14.0-570.76.1.el9_6
- Red Hat Enterprise Linux 9
Subscriber exclusive content
A Red Hat subscription provides unlimited access to our knowledgebase, tools, and much more.