Re: [PATCH 10/24] sched/uclamg: Handle delayed dequeue

Dietmar Eggemann
2024-09-12T20:44:58Z

On 12/09/2024 14:58, Luis Machado wrote:
> On 9/11/24 10:10, Mike Galbraith wrote:
>> On Wed, 2024-09-11 at 10:45 +0200, Peter Zijlstra wrote:
>>> On Wed, Sep 11, 2024 at 09:35:16AM +0100, Luis Machado wrote:

[...]

> Ok, I seem to have narrowed this down to scheduler class switching. In particular
> switched_from_fair.
>
> Valentin's patch (75b6499024a6c1a4ef0288f280534a5c54269076
> sched/fair: Properly deactivate sched_delayed task upon class change) introduced
> finish_delayed_dequeue_entity, which takes care of cleaning up the state of delayed-dequeue
> tasks during class change. Things work fine (minus delayed task accounting) up to this point.
>
> When Peter introduced his patch to do h_nr_delayed accounting, we modified
> finish_delayed_dequeue_entity to also call clear_delayed, instead of simply
> zeroing se->sched_delayed.
>
> The call to clear_delayed decrements the rq's h_nr_delayed, and it gets used elsewhere
> to cleanup the state of delayed-dequeue tasks, in order to share some common code.
>
> With that said, my testing on Android shows that when we hit switched_from_fair during
> switching sched classes (due to some RT task), we're in a state where...
>
> 1 - We already called into dequeue_entities for this delayed task.
> 2 - We tested true for the !task_sleep && !task_delayed condition.
> 3 - se->sched_delayed is true, so h_nr_delayed == 1.
> 4 - We carry on executing the rest of dequeue_entities and decrement the rq's h_nr_running by 1.
>
> In switched_from_fair, after the above events, we call into finish_delayed_dequeue_entity -> clear_delayed
> and do yet another decrement to the rq's h_nr_delayed, now potentially making it negative. As
> a consequence, we probably misuse the negative value and adjust the frequencies incorrectly. I
> think this is the issue I'm seeing.
>
> It is worth pointing out that even with the Android setup, things only go bad when there is enough
> competition and switching of classes (lots of screen events etc).
>
> My suggestion of a fix (below), still under testing, is to inline the delayed-dequeue and the lag zeroing
> cleanup within switched_from_fair instead of calling finish_delayed_dequeue_entity. Or maybe
> drop finish_delayed_dequeue_entity and inline its contents into its callers.
>
> The rest of Peter's patch introducing h_nr_delayed seems OK as far as I could test.
>
>
> diff --git a/kernel/sched/fair.c b/kernel/sched/fair.c
> index f993ac282a83..f8df2f8d2e11 100644
> --- a/kernel/sched/fair.c
> +++ b/kernel/sched/fair.c
> @@ -13168,7 +13168,9 @@ static void switched_from_fair(struct rq *rq, struct task_struct *p)
> * related to sched_delayed being true and that wasn't done
> * due to the generic dequeue not using DEQUEUE_DELAYED.
> */
> - finish_delayed_dequeue_entity(&p->se);
> + p->se.sched_delayed = 0;
> + if (sched_feat(DELAY_ZERO) && p->se.vlag > 0)
> + p->se.vlag = 0;
> p->se.rel_deadline = 0;
> __block_task(rq, p);
> }

I could recreate this on QEMU with:

@@ -5473,6 +5473,7 @@ static void clear_delayed(struct sched_entity *se)
for_each_sched_entity(se) {
struct cfs_rq *cfs_rq = cfs_rq_of(se);
cfs_rq->h_nr_delayed--;
+ BUG_ON((int)cfs_rq->h_nr_delayed < 0);
if (cfs_rq_throttled(cfs_rq))
break;
}
running:

# while(true); do chrt -rr -p 50 $$; chrt -o -p 0 $$; done

in one shell and:

# hackbench

in another.

[ 318.490522] ------------[ cut here ]------------
[ 318.490969] kernel BUG at kernel/sched/fair.c:5476!
[ 318.491411] Oops: invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
[ 318.491964] CPU: 3 UID: 0 PID: 68053 Comm: chrt Not tainted 6.11.0-rc1-00066-g2e05f6c71d36-dirty #23
[ 318.492604] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.4
[ 318.494192] RIP: 0010:switched_from_fair+0x67/0xe0
[ 318.494899] Code: ff ff c6 85 d1 00 00 00 00 48 85 db 75 0e eb 1c 48 8b 9b 98 00 00 00 48 85 db 74 10 48 8b 0
[ 318.496491] RSP: 0018:ffffb1154bc63e20 EFLAGS: 00010097
[ 318.496991] RAX: 0000000000000001 RBX: ffff92668844e200 RCX: ffff9266fddadea8
[ 318.497681] RDX: ffff926684213e00 RSI: ffff9266fddadea8 RDI: ffff92668844e608
[ 318.498339] RBP: ffff92668844e180 R08: ffff92668106c44c R09: ffff92668119c0b8
[ 318.498940] R10: ffff926681f42000 R11: ffffffffb1e155d0 R12: ffff9266fddad640
[ 318.499525] R13: ffffb1154bc63ed8 R14: 0000000000000078 R15: ffff9266fddad640
[ 318.500234] FS: 00007f68f52bf740(0000) GS:ffff9266fdd80000(0000) knlGS:0000000000000000
[ 318.500837] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 318.501261] CR2: 00007f68f53afdd0 CR3: 0000000006a58002 CR4: 0000000000370ef0
[ 318.501798] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 318.502385] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 318.502919] Call Trace:
[ 318.503118] <TASK>
[ 318.503284] ? die+0x32/0x90
[ 318.503508] ? do_trap+0xd8/0x100
[ 318.503770] ? switched_from_fair+0x67/0xe0
[ 318.504085] ? do_error_trap+0x60/0x80
[ 318.504374] ? switched_from_fair+0x67/0xe0
[ 318.504652] ? exc_invalid_op+0x53/0x70
[ 318.504995] ? switched_from_fair+0x67/0xe0
[ 318.505270] ? asm_exc_invalid_op+0x1a/0x20
[ 318.505588] ? switched_from_fair+0x67/0xe0
[ 318.505929] check_class_changed+0x2a/0x80
[ 318.506236] __sched_setscheduler+0x1f3/0x920
[ 318.506526] do_sched_setscheduler+0xfd/0x1c0
[ 318.506867] ? do_sys_openat2+0x7c/0xc0
[ 318.507141] __x64_sys_sched_setscheduler+0x1a/0x30
[ 318.507462] do_syscall_64+0x9e/0x1a0
[ 318.507722] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 318.508127] RIP: 0033:0x7f68f53c3719
[ 318.508369] Code: 08 89 e8 5b 5d c3 66 2e 0f 1f 84 00 00 00 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 8
[ 318.509941] RSP: 002b:00007fff8d920578 EFLAGS: 00000246 ORIG_RAX: 0000000000000090
[ 318.511178] RAX: ffffffffffffffda RBX: 00007fff8d920610 RCX: 00007f68f53c3719
[ 318.512105] RDX: 00007fff8d92058c RSI: 0000000000000002 RDI: 0000000000000103
[ 318.512676] RBP: 0000000000000103 R08: 0000000000000000 R09: 0000000000000000
[ 318.513296] R10: 1999999999999999 R11: 0000000000000246 R12: 0000000000000002
[ 318.513917] R13: 0000000000000002 R14: 0000000000000032 R15: 0000000000000103
[ 318.514617] </TASK>
[ 318.514861] Modules linked in:
[ 318.515132] ---[ end trace 0000000000000000 ]---
[ 318.515466] RIP: 0010:switched_from_fair+0x67/0xe0
[ 318.515942] Code: ff ff c6 85 d1 00 00 00 00 48 85 db 75 0e eb 1c 48 8b 9b 98 00 00 00 48 85 db 74 10 48 8b 0
[ 318.517411] RSP: 0018:ffffb1154bc63e20 EFLAGS: 00010097
[ 318.517819] RAX: 0000000000000001 RBX: ffff92668844e200 RCX: ffff9266fddadea8
[ 318.518354] RDX: ffff926684213e00 RSI: ffff9266fddadea8 RDI: ffff92668844e608
[ 318.518946] RBP: ffff92668844e180 R08: ffff92668106c44c R09: ffff92668119c0b8
[ 318.519527] R10: ffff926681f42000 R11: ffffffffb1e155d0 R12: ffff9266fddad640
[ 318.520138] R13: ffffb1154bc63ed8 R14: 0000000000000078 R15: ffff9266fddad640
[ 318.520684] FS: 00007f68f52bf740(0000) GS:ffff9266fdd80000(0000) knlGS:0000000000000000
[ 318.521350] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 318.521745] CR2: 00007f68f53afdd0 CR3: 0000000006a58002 CR4: 0000000000370ef0
[ 318.522306] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 318.522896] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 318.523388] note: chrt[68053] exited with irqs disabled

With your proposed fix the issue goes away.

Tested-by: Dietmar Eggemann <dietmar.eggemann@arm.com>