Re: [PATCH 4/4] writeback: report a slow writeback wait once per timeout

[Breno Leitao]

On Fri, Nov 06, 2026 at 03:37:45PM +0100, Jan Kara wrote:
> On Fri 06-11-26 04:26:34, Breno Leitao wrote:
> > The slow writeback report is printed on every wakeup of the waiter past
> > hung_task_timeout_secs, and the waiter is woken more often than that.
> > 
> > Each flusher working for it wakes it once it has not run for half the
> > timeout. All waiters on a bdi share bdi->wb_waitq, so a wakeup meant for
> > one of them reaches all of them.
> > 
> > A sync of files dirtied from two cgroups, on a throttled null_blk device
> > with the timeout set to 5 seconds, gets a report every half timeout,
> > each printed twice, 18 reports for a 29 second wait:
> > 
> >   [   10.327992] INFO: The task sync:276 has been waiting for writeback completion for more than 8 seconds.
> >   [   10.328000]       bdi 252:0, work items left: 2
> >   [   10.328003] INFO: The task sync:276 has been waiting for writeback completion for more than 8 seconds.
> >   [   10.328004]       bdi 252:0, work items left: 2
> >   [   12.888187] INFO: The task sync:276 has been waiting for writeback completion for more than 10 seconds.
> >   [   12.888195]       bdi 252:0, work items left: 2
> >   [   12.888197] INFO: The task sync:276 has been waiting for writeback completion for more than 10 seconds.
> >   [   12.888198]       bdi 252:0, work items left: 2
> >   ...
> > 
> > Remember when the waiter last reported, and report again only once
> > another timeout has passed. The wakeups do not change, so the hung task
> > detector still sees the waiter making progress. The same test now
> > prints 5 reports:
> > 
> >   [    7.661129] INFO: The task sync:277 has been waiting for writeback completion for more than 5 seconds.
> >   [    7.661136]       bdi 252:0, work items left: 2
> >   [   13.241102] INFO: The task sync:277 has been waiting for writeback completion for more than 11 seconds.
> >   [   13.241109]       bdi 252:0, work items left: 2
> >   ...
> >   [   31.801068] The task sync:277 waited 29 seconds for writeback completion on bdi 252:0
> > 
> > Signed-off-by: Breno Leitao <leitao@xxxxxxxxxx>
> 
> Now I'm waiting for someone to complain it gets written out too
> infrequently :). 

Once per timeout is also how often the hung task detector checks by
default, and patch 3 logs the total once the wait ends, so maybe that is
exactly what people need? Not sure.

> Is this change substantially different from
> writeback_sb_inodes() waking up done->waitq less frequently?

You mean the ->progress_stamp field? That is not used for reporting
purposes, right? Should it be?

It could drop the duplicates: a wakeup with work left runs the
wait_event() condition twice (since 84654c7f4730, it is checked right
after schedule() and again after prepare_to_wait_event()), and the
second check would find ->progress_stamp just refreshed by the first.

But the waiter refreshes ->progress_stamp on every wakeup, so it cannot
space the reports further apart than the wakeups, and those have to
come more often than the hung task timeout.

So it is a choice between a report every half timeout with no new
field, or once per timeout with report_stamp. Which one do you prefer?

Thanks for the review,
--breno