On Thu, Mar 20, 2025 at 10:42:44PM +0000, Christian Loehle wrote:

Did this happen on mainline? Any chance it's reproducible?

We have the following back-ported on top of 6.13:

sched/fair: Adhere to place_entity() constraints (not upstreamed, see https://lore.kernel.org/all/20250207111141.GD7145@noisy.programming.kicks-as...) a430d99e3490 sched/fair: Fix value reported by hot tasks pulled in /proc/schedstat 2a77e4be12cb sched/fair: Untangle NEXT_BUDDY and pick_next_task()

We don't have a repro, but the crash in pick_task_fair happens more often than MCE crashes with our limited deployment of 6.13.

On Mon, Mar 24, 2025 at 12:56:13PM +0100, Peter Zijlstra wrote:

Does something like:

https://lkml.kernel.org/r/20250128143949.GD7145@noisy.programming.kicks-ass....

help?

To clarify- are you asking about if we've tried reverting 4423af84b297? We have not tried that yet.

Or if we've included "sched/fair: Adhere to place_entity() constraints", which we have already done- https://lore.kernel.org/all/20250207-tunneling-tested-koel-c59d33@leitao/

On Tue, Mar 25, 2025 at 07:59:07PM +0100, Peter Zijlstra wrote:

...

To clarify- are you asking about if we've tried reverting 4423af84b297? We have not tried that yet.

Or if we've included "sched/fair: Adhere to place_entity() constraints", which we have already done- https://lore.kernel.org/all/20250207-tunneling-tested-koel-c59d33@leitao/

This; it seems it got lost. I'll try and get it queued up.

Given that we've already included the patch in what we're running, and we're seeing this null pointer exception, any suggestions for how to proceed?

On Wed, Apr 09, 2025 at 10:29:43AM -0400, Rik van Riel wrote:

On Wed, 2025-04-02 at 20:07 +0200, Peter Zijlstra wrote:

...

Anyway, seeing how your min_vruntime is weird, let me ask you to try the below; it removes the old min_vruntime and instead tracks zero vruntime as the 'current' avg_vruntime. We don't need the monotinicity filter, all we really need is something 'near' all the other vruntimes in order to compute this relative key so we can preserve order across the wrap.

This *should* get us near minimal sized keys. If you can still reproduce, you should probably add something like that patch I send you privately earlier, that checks the overflows.

Our trouble workload still makes the scheduler crash with this patch.

I'll go put the debugging patch on our kernel.

Should I try to get debugging data with this patch part of the mix, or with the debugging patch just on top of what's in 6.13 already?

Whatever is more convenient I suppose.

If you can dump the full tree that would be useful. Typically the se::{vruntime,weight} and cfs_rq::{zero_vruntime,avg_vruntime,avg_load} such that we can do full manual validation of the numbers.

On Fri, Apr 11, 2025 at 10:51:34AM -0400, Rik van Riel wrote:

On Wed, 9 Apr 2025 17:27:03 +0200 Peter Zijlstra peterz@infradead.org wrote:

...

On Wed, Apr 09, 2025 at 10:29:43AM -0400, Rik van Riel wrote:

...

Our trouble workload still makes the scheduler crash with this patch.

I'll go put the debugging patch on our kernel.

Should I try to get debugging data with this patch part of the mix, or with the debugging patch just on top of what's in 6.13 already?

Whatever is more convenient I suppose.

If you can dump the full tree that would be useful. Typically the se::{vruntime,weight} and cfs_rq::{zero_vruntime,avg_vruntime,avg_load} such that we can do full manual validation of the numbers.

Here is a dump of the scheduler tree of the crashing CPU.

Unfortunately the CPU crashed in pick_next_entity, and not in your debugging code. I'll add two more calls to avg_vruntime_validate(), one from avg_vruntime_update(), and one rfom __update_min_vruntime() when we skip the call to avg_vruntime_update(). The line numbers in the backtrace could be a clue.

I have edited the cgroup names to make things more readable, but everything else is untouched.

Hmm, I didn't think you guys used the cgroup stuff.

Anyway, given cgroups, which group pick is the one that went boom? Also, what is curr (for that cgroup).

curr lives outside of the tree, but is included in the eligibility consideration (when still on_rq and all that).

nr_running = 3 min_vruntime = 107772371139014 avg_vruntime = -1277161882867784752 avg_load = 786 tasks_timeline = [ { cgroup /A weight = 10230 => 9

No vruntime, I'll assume !on_rq, but that makes avg_load above not match :/ So something is off here.

rq = {
  nr_running = 0
  min_vruntime = 458975898004
  avg_vruntime = 0
  avg_load = 0
  tasks_timeline = [
  ]
}

}, { cgroup /B vruntime = 18445226958208703357 weight = 319394 => 311 rq = { nr_running = 2 min_vruntime = 27468255210769 avg_vruntime = 0 avg_load = 93 tasks_timeline = [ { cgroup /B/a vruntime = 27468255210769 weight = 51569 => 50 rq = { nr_running = 1 min_vruntime = 820449693961 avg_vruntime = 0 avg_load = 15 tasks_timeline = [ { task = 3653382 (fc0) vruntime = 820449693961 weight = 15360 => 15 }, ] } }, { cgroup /B/b vruntime = 27468255210769 weight = 44057 => 43 rq = { nr_running = 1 min_vruntime = 563178567930 avg_vruntime = 0 avg_load = 15 tasks_timeline = [ { task = 3706454 (fc0) vruntime = 563178567930 weight = 15360 => 15 }, ] } }, ] } }, { cgroup /C vruntime = 18445539757376619550 weight = 477855 => 466 rq = { nr_running = 0 min_vruntime = 17163581720739 avg_vruntime = 0 avg_load = 0 tasks_timeline = [ ] } }, ]

So given the above, I've created the below files, and that gives:

$ ./vruntime < root.txt k: 0 w: 311 k*w: 0 k: 312799167916193 w: 466 k*w: 145764412248945938 v': 107772371139014 = v: 18445226958208703357 + d: 1624887871987273 V': -1116773464285165183 = V: 145764412248945938 - d: 1624887871987273 * W: 777 min_vruntime: 107772371139014 avg_vruntime: -1116773464285165183 avg_load: 777

One thing that stands out to me is how the vruntime of each of the entities on the CPU's cfs_rq are really large negative numbers.

vruntime = 18429030910682621789 equals 0xffc111f8d9ee675d

I do not know how those se->vruntime numbers got to that point, but they are a suggestive cause of the overflow.

I'll go comb through the se->vruntime updating code to see how those large numbers could end up as the vruntime for these sched entities.

As you can see from the output here, the large negative is the result of min_vruntime being significantly ahead of the actual entities.

This can happen due to that monotonicity filter the thing has -- it doesn't want to go backwards. Whereas the 0-lag point can move backwards, seeing how it is the weighted average, and inserting a task with positive lag will insert a task left of middle, moving the middle left.

The zero_vruntime patch I gave earlier should avoid this particular issue.

$ ./vruntime < B.txt k: 0 w: 50 k*w: 0 k: 0 w: 43 k*w: 0 v': 27468255210769 = v: 27468255210769 + d: 0 V': 0 = V: 0 - d: 0 * W: 93 min_vruntime: 27468255210769 avg_vruntime: 0 avg_load: 93

C, B/a and B/b are not really interesting, they're single entries where min_vruntime == vruntime and boring.

---8<---(root.txt)---8<--- entity 18445226958208703357 319394 entity 18445539757376619550 477855 group 107772371139014

---8<---(B.txt)---8<--- entity 27468255210769 51569 entity 27468255210769 44057 group 27468255210769

---8<---(vruntime.c)---8<---

#include <stdio.h> #include <stdlib.h> #include <stdbool.h> #include <string.h>

int main (int argc, char **argv) { unsigned long V, W; unsigned long V0; bool init = false;

for (;;) { unsigned long vruntime, weight; char type[32];

int r = scanf("%s\t%lu\t%lu\n", &type, &vruntime, &weight); if (r == EOF) break;

if (!strcmp(type, "entity")) { if (!init) { V = W = 0; V0 = vruntime; init = true; }

unsigned long k = vruntime - V0; unsigned long w = weight / 1024;

V += k * w; W += w;

printf(" k: %ld w: %lu k*w: %ld\n", k, w, k*w); }

if (!strcmp(type, "group")) { unsigned long d = vruntime - V0;

printf(" v': %lu = v: %lu + d: %lu\n", V0 + d, V0, d); printf(" V': %ld = V: %ld - d: %ld * W: %lu\n", V - d * W, V, d, W);

V0 += d; V -= d * W; } }

printf("min_vruntime: %lu\n", V0); printf("avg_vruntime: %ld\n", V); printf("avg_load: %lu\n", W);

return 0; }

On Mon, Apr 14, 2025 at 11:38:15AM -0400, Chris Mason wrote:

On 4/14/25 5:08 AM, Peter Zijlstra wrote:

[ math and such ]

...

The zero_vruntime patch I gave earlier should avoid this particular issue.

Here's a crash with the zero runtime patch.

And indeed it doesn't have these massive (negative) avg_vruntime values.

I'm trying to reproduce this outside of prod so we can crank up the iteration speed a bit.

Thanks.

Could you add which pick went boom for the next dump?

I am however, slightly confused by this output format.

It looks like it dumps the cfs_rq the first time it encounters it, either through curr or through the tree.

So if I read this correct the root is something like:

nr_running = 2 zero_vruntime = 19194347104893960 avg_vruntime = 6044054790 avg_load = 2 curr = { cgroup urgent vruntime = 24498183812106172 weight = 3561684 => 3478 } tasks_timeline = [ { cgroup optional vruntime = 19194350126921355 weight = 1168 => 2 }, ]

group 19194347104893960 curr 24498183812106172 3561684 entity 19194350126921355 1168

But if I run those numbers, I get avg_load == 1, seeing how 1168/1024 = 1. But the thing says it should be 2.

Similarly, my avg_vruntime is exactly half of what it says.

avg_vruntime: 3022027395 avg_load: 1

(seeing how 19194350126921355-19194347104893960 = 3022027395)

Anyway, with curr being significantly to the right of that, the 0-lag point is well right of where optional sits. So this pick should be fine, and result in 'optional' getting selected (curr is no longer eligible).

All the urgent/* groups have nr_running == 0, so are not interesting, we'll not pick there.

NOTE: I'm inferring curr is on_rq, because nr_running == 2 and the tree only has 1 entity in it.

NOTE: if we ignore curr, then optional sits at exactly the 0-lag point, with either sets of numbers and so should be eligible.

This then leaves us the optional/* groups.

cgroup optional
rq = {
  nr_running = 2
  zero_vruntime = 440280059357029
  avg_vruntime = 476
  avg_load = 688
  tasks_timeline = [
    {
      cgroup optional/-610613050111295488
      vruntime = 440280059333960
      weight = 291271 => 284
    },
    {
      cgroup optional/-610609318858457088
      vruntime = 440280059373247
      weight = 413911 => 404
    },

group 440280059357029 entity 440280059333960 291271 entity 440280059373247 413911

Which gives:

avg_vruntime: 476 avg_load: 688

And that matches.

Next we have:

      cgroup optional/-610613050111295488
      rq = {
        nr_running = 5
        zero_vruntime = 65179829005
        avg_vruntime = 0
        avg_load = 75
        tasks_timeline = [
          {
            task = 261672 (fc0)
            vruntime = 65189926507
            weight = 15360 => 15
          },
          {
            task = 261332 (fc0)
            vruntime = 65189480962
            weight = 15360 => 15
          },
          {
            task = 261329 (enc1:0:vp9_fbv)
            vruntime = 65165843516
            weight = 15360 => 15
          },
          {
            task = 261334 (dec0:0:hevc_fbv)
            vruntime = 65174065035
            weight = 15360 => 15
          },
          {
            task = 261868 (fc0)
            vruntime = 65179829005
            weight = 15360 => 15
          },
        ]
      }

avg_vruntime: 0 avg_load: 75

This again matches, leaving the bottom 3 tasks eligible.

And finally:

      cgroup optional/-610609318858457088
      rq = {
        nr_running = 1
        zero_vruntime = 22819875784
        avg_vruntime = 0
        avg_load = 15
        tasks_timeline = [
          {
            task = 273291 (fc0)
            vruntime = 22819875784
            weight = 15360 => 15
          },
        ]
      }

Rather boring indeed, but the numbers appear correct.

So I'm not immediately seeing where it would go boom, but seeing how the root group is the one with dodgy numbers, I would suspect that -- but I'm not immediately seeing how... :-(