[BUG] sched/delayacct: blkio_start recorded on the wrong task when a delayed task is blocked from pick

[kiln]

Hi,

I think there's a delay accounting bug that came in with DELAY_DEQUEUE.
__block_task() calls delayacct_blkio_start(), and that helper always
writes current->delays->blkio_start. That's fine when __block_task() runs
from __schedule() for prev, but when the task was delayed and gets
blocked later from pick_next_task_fair() -> pick_next_entity() ->
dequeue_entities() -> __block_task(), current is whoever is scheduling on
that CPU, not p. So p's blkio_start is never set (or is left over from
an older sleep), and when the I/O completes ttwu() calls
delayacct_blkio_end(p), which adds local_clock() - blkio_start to p's
blkio_delay. For a fresh thread blkio_start is 0, so the thread gets
charged the whole time since boot in one go.

How I ran into it: per-thread blkio delay (taskstats, and field 42 of
/proc/<pid>/task/<tid>/stat) on some hosts showed threads that were a
couple of seconds old with ~7,070,000 s of block I/O delay, which was
exactly the host uptime. Always freshly created threads of a headless
Chrome (ThreadPoolForeg, Chrome_IOThread, Compositor and so on); Chrome
creates lots of short-lived threads that soon wait on ext4 journal I/O.

Kernel: a distro 6.6.102 kernel that carries the EEVDF / DELAY_DEQUEUE
backport (Alibaba Cloud Linux 4, 6.6.102-7.alnx4). I have not reproduced
it on mainline yet, but as far as I can tell the code there is the same:
__block_task() in kernel/sched/sched.h still calls delayacct_blkio_start()
with no task argument, in v6.12 and current master.

What I measured with bpftrace while starting Chrome a few times
(roughly 70 s per run):

kprobe:dequeue_entities    { @in_de[tid] = 1; }
kretprobe:dequeue_entities { delete(@in_de[tid]); }
kprobe:__delayacct_blkio_start {
  @start[@in_de[tid] ? "from dequeue_entities" : "from __schedule",
         curtask->in_iowait] = count();
}
kprobe:__delayacct_blkio_end {
  $p = (struct task_struct *)arg0;
  if ($p->delays->blkio_start == 0) { @zero[$p->comm] = count(); }
}

With DELAY_DEQUEUE on (two runs):
  from __schedule, current in_iowait=1:        11081 / 8691
  from __schedule, current in_iowait=0:            0 / 0
  from dequeue_entities, current in_iowait=1:     50 / 61
  from dequeue_entities, current in_iowait=0:     52 / 103
  blkio_end with blkio_start == 0:                 3 / 10 (all Chrome threads)

With NO_DELAY_DEQUEUE (two runs, same workload):
  from dequeue_entities:                         0 / 2
  blkio_end with blkio_start == 0:               0 / 0
  starts vs ends: 12057 vs 12056, 9612 vs 9610

So on the dequeue_entities path about half of the starts land on a task
that isn't even in iowait. A kernel stack for one of the zero-start ends:

  __delayacct_blkio_end+1
  try_to_wake_up+1509
  wake_bit_function+57
  __wake_up_common+118
  __wake_up_common_lock+129
  wake_up_bit+127
  journal_end_buffer_io_sync+48
  end_bio_bh_io_sync+38

This looks like the mirror image of c96f5471ce7d ("delayacct: Account
blkio completion on the correct task"), which fixed the end side the same
way. The obvious fix would be to pass p down, something like
delayacct_blkio_start(p) setting p->delays->blkio_start (checking
p->delays rather than current->delays). Happy to send a patch if that
direction is okay.

Thanks
kiln