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

[sashiko-bot@kernel.org]

Thank you for your contribution! Sashiko AI review found 1 potential
issue to consider:
- [High] writeback: hung task wakeup interval exceeds timeout in
  writeback_sb_inodes()
--

commit f3edfd7b6ff429943317ab66c7dd1c29f9226156
Author: Breno Leitao <leitao@debian.org>

writeback: report a slow writeback wait once per timeout

This commit rate-limits the slow writeback report in
wb_wait_for_completion_cb() to once per hung_task_timeout_secs, initializes
done->progress_stamp when waiting starts, and increases the progress wakeup
interval in writeback_sb_inodes() from half the timeout to the full timeout.

> diff --git a/fs/fs-writeback.c b/fs/fs-writeback.c
> index e2da4781b5e00..fcb7fb0196208 100644
> --- a/fs/fs-writeback.c
> +++ b/fs/fs-writeback.c
> @@ -203,12 +203,13 @@ static bool wb_wait_for_completion_cb(struct wb_completion *done,
>  	unsigned long waited_secs = (jiffies - done->wait_start) / HZ;
>  	int left = atomic_read(&done->cnt);
>  
> -	done->progress_stamp = jiffies;
> -	if (left && timeout && (waited_secs > timeout))
> +	if (left && timeout &&
> +	    time_after(jiffies, done->progress_stamp + timeout * HZ))
>  		pr_info("INFO: The task %s:%d has been waiting for writeback "
>  			"completion for more than %lu seconds (bdi %s, work items left: %d).\n",
>  			current->comm, current->pid, waited_secs,
>  			bdi_dev_name(bdi), left);
> +	done->progress_stamp = jiffies;
>  
>  	return !left;
>  }
> @@ -230,6 +231,7 @@ void wb_wait_for_completion(struct wb_completion *done,
>  	unsigned long timeout, waited;
>  
>  	done->wait_start = jiffies;
> +	done->progress_stamp = done->wait_start;
>  	atomic_dec(&done->cnt);		/* put down the initial count */
>  	wait_event(*done->waitq, wb_wait_for_completion_cb(done, bdi));
>  
> @@ -2135,7 +2137,7 @@ static long writeback_sb_inodes(struct super_block *sb,
>  
>  		/* Report progress to inform the hung task detector of the progress. */
>  		if (work->done && work->done->progress_stamp && timeout &&
> -		   (jiffies - work->done->progress_stamp) > HZ * timeout / 2)
> +		   (jiffies - work->done->progress_stamp) > HZ * timeout)
>  			wake_up_all(work->done->waitq);

[Severity: High]
Does raising the wakeup threshold from HZ * timeout / 2 to HZ * timeout cause
khungtaskd to report false-positive hung tasks (or panic when
sysctl_hung_task_panic is set) during slow writeback?

In kernel/hung_task.c, task_is_hung() stamps t->last_switch_time with the
time of the scan that first notices a new switch_count, not the time the
task actually scheduled:

kernel/hung_task.c:task_is_hung() {
    ...
	if (switch_count != t->last_switch_count) {
		t->last_switch_count = switch_count;
		t->last_switch_time = jiffies;
		return false;
	}
	if (time_is_after_jiffies(t->last_switch_time + timeout * HZ))
		return false;

	return true;
}

Because writeback_sb_inodes() only checks the threshold after
__writeback_single_inode() finishes, consecutive wakeups are spaced by
HZ * timeout plus the time spent writing the next inode.  That wakeup period
is strictly longer than khungtaskd's timeout * HZ detection window, so a scan
that runs right after a wakeup can be followed by the next scan at
last_switch_time + timeout * HZ before the next wakeup happens, defeating
1888635532fb ("writeback: Wake up waiting tasks when finishing the writeback
of a chunk.").

Keeping the wakeup threshold at HZ * timeout / 2 while tracking the last
pr_info() timestamp separately from done->progress_stamp (or only updating
done->progress_stamp when logging) would avoid waking the waiter late.

-- 
Sashiko AI review · https://sashiko.dev/#/patchset/20261110-writeback_stall_report-v2-0-9e0ed75074ca@debian.org?part=4