[PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[MingTao Huang]

From: MingTao Huang <mintaohuang@tencent.com>

Commit f3f7ae68a4ea ("xfs: skip flushing log items during push")
introduced a fast path in xfsaild_push() that uses
test_bit(XFS_LI_FLUSHING) to skip log items already being
flushed.  However, the fast path jumps directly to the
next_item label, bypassing flushing++, count++, and the
ail_last_pushed_lsn update.  This causes three problems:

1. The loop exit condition "count > 1000" becomes much harder to
   trigger.  count was meant to track every item visited, but now it
   only increments for non-flushing items that enter
   xfsaild_push_item().  Each such item typically triggers an inode
   cluster flush that marks dozens of neighbouring inodes as flushing,
   so count effectively counts cluster flushes rather than individual
   items.  The threshold shifts from 1000 items to ~1000 clusters,
   letting the loop scan an order of magnitude more items per round.
   Each cluster flush adds a buffer to ail_buf_list, and the resulting
   oversized list causes xfs_buf_delwri_submit_nowait() -- which runs
   list_sort() plus per-buffer trylock and IO submission -- to take so
   long that the watchdog fires.

2. The timeout decision "(stuck + flushing) * 100 / count > 90" is
   computed without the fast-path flushing items, so the flushing ratio
   is severely under-reported.  When most of the AIL is flushing, the
   ratio appears near 0%.  xfsaild therefore selects
   "tout = 0" when it should select "tout = 20" (20 ms
   back-off to let IO complete).  The zero-backoff tight loop compounds
   the ail_buf_list accumulation across rounds.

3. ail_last_pushed_lsn is not advanced past flushing items, so the
   next push round restarts scanning from the same position, repeatedly
   traversing items that are still in-flight.

We hit this as a soft lockup during stress testing on an internal
kernel that includes commit f3f7ae68a4ea ("xfs: skip flushing log
items during push").  The xfsaild kthread was stuck for
22 seconds inside xfs_buf_delwri_submit_nowait(), called from
xfsaild_push(), processing an excessively large ail_buf_list:

  watchdog: BUG: soft lockup - CPU#48 stuck for 22s! [xfsaild/dm-1:4931]
  RIP: 0010:xfs_buf_delwri_submit_buffers+0xf2/0x250 [xfs]
  Call Trace:
   <TASK>
   xfsaild_push+0x19b/0x7d0 [xfs]
   xfsaild+0xb8/0x1a0 [xfs]
   kthread+0xcc/0x100
   ret_from_fork+0x5f/0xa0
   ret_from_fork_asm+0x1b/0x30
   </TASK>
  Kernel panic - not syncing: softlockup: hung tasks

Fix this by accounting for flushing items in the fast path -- increment
flushing and count, and update ail_last_pushed_lsn -- to match what the
XFS_ITEM_FLUSHING case in xfsaild_push_item() already does.  This
ensures the loop exit condition, the timeout ratio, and the resume
position all reflect the true state of the AIL.

Fixes: f3f7ae68a4ea ("xfs: skip flushing log items during push")
Signed-off-by: MingTao Huang <mintaohuang@tencent.com>
---
 fs/xfs/xfs_trans_ail.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/fs/xfs/xfs_trans_ail.c b/fs/xfs/xfs_trans_ail.c
index 99a9bf3762b7..0f72cd4e6983 100644
--- a/fs/xfs/xfs_trans_ail.c
+++ b/fs/xfs/xfs_trans_ail.c
@@ -580,8 +580,12 @@ xfsaild_push(
 	lsn = lip->li_lsn;
 	while ((XFS_LSN_CMP(lip->li_lsn, ailp->ail_target) <= 0)) {
 
-		if (test_bit(XFS_LI_FLUSHING, &lip->li_flags))
+		if (test_bit(XFS_LI_FLUSHING, &lip->li_flags)) {
+			flushing++;
+			count++;
+			ailp->ail_last_pushed_lsn = lsn;
 			goto next_item;
+		}
 
 		xfsaild_process_logitem(ailp, lip, &stuck, &flushing);
 		count++;
-- 
2.43.7

Re: [PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[Darrick J. Wong]

On Tue, Sep 22, 2026 at 04:14:29PM +0800, MingTao Huang wrote:
> From: MingTao Huang <mintaohuang@tencent.com>
> 
> Commit f3f7ae68a4ea ("xfs: skip flushing log items during push")
> introduced a fast path in xfsaild_push() that uses
> test_bit(XFS_LI_FLUSHING) to skip log items already being
> flushed.  However, the fast path jumps directly to the
> next_item label, bypassing flushing++, count++, and the
> ail_last_pushed_lsn update.  This causes three problems:
> 
> 1. The loop exit condition "count > 1000" becomes much harder to
>    trigger.  count was meant to track every item visited, but now it
>    only increments for non-flushing items that enter
>    xfsaild_push_item().  Each such item typically triggers an inode
>    cluster flush that marks dozens of neighbouring inodes as flushing,
>    so count effectively counts cluster flushes rather than individual
>    items.  The threshold shifts from 1000 items to ~1000 clusters,
>    letting the loop scan an order of magnitude more items per round.
>    Each cluster flush adds a buffer to ail_buf_list, and the resulting
>    oversized list causes xfs_buf_delwri_submit_nowait() -- which runs
>    list_sort() plus per-buffer trylock and IO submission -- to take so
>    long that the watchdog fires.
> 
> 2. The timeout decision "(stuck + flushing) * 100 / count > 90" is
>    computed without the fast-path flushing items, so the flushing ratio
>    is severely under-reported.  When most of the AIL is flushing, the
>    ratio appears near 0%.  xfsaild therefore selects
>    "tout = 0" when it should select "tout = 20" (20 ms
>    back-off to let IO complete).  The zero-backoff tight loop compounds
>    the ail_buf_list accumulation across rounds.
> 
> 3. ail_last_pushed_lsn is not advanced past flushing items, so the
>    next push round restarts scanning from the same position, repeatedly
>    traversing items that are still in-flight.
> 
> We hit this as a soft lockup during stress testing on an internal
> kernel that includes commit f3f7ae68a4ea ("xfs: skip flushing log
> items during push").  The xfsaild kthread was stuck for
> 22 seconds inside xfs_buf_delwri_submit_nowait(), called from
> xfsaild_push(), processing an excessively large ail_buf_list:
> 
>   watchdog: BUG: soft lockup - CPU#48 stuck for 22s! [xfsaild/dm-1:4931]
>   RIP: 0010:xfs_buf_delwri_submit_buffers+0xf2/0x250 [xfs]
>   Call Trace:
>    <TASK>
>    xfsaild_push+0x19b/0x7d0 [xfs]
>    xfsaild+0xb8/0x1a0 [xfs]
>    kthread+0xcc/0x100
>    ret_from_fork+0x5f/0xa0
>    ret_from_fork_asm+0x1b/0x30
>    </TASK>
>   Kernel panic - not syncing: softlockup: hung tasks
> 
> Fix this by accounting for flushing items in the fast path -- increment
> flushing and count, and update ail_last_pushed_lsn -- to match what the
> XFS_ITEM_FLUSHING case in xfsaild_push_item() already does.  This

Am I missing something?  xfsaild_push_item in 7.3-rc4 doesn't seem to
handle flushing.  Maybe you meant xfsaild_process_logitem?  In which
case bumping flushing/counted makes sense.  I /think/ bumping
ail_last_pushed_lsn makes sense too, but I want to think about that
more.

<confused>

--D

> ensures the loop exit condition, the timeout ratio, and the resume
> position all reflect the true state of the AIL.
> 
> Fixes: f3f7ae68a4ea ("xfs: skip flushing log items during push")
> Signed-off-by: MingTao Huang <mintaohuang@tencent.com>
> ---
>  fs/xfs/xfs_trans_ail.c | 6 +++++-
>  1 file changed, 5 insertions(+), 1 deletion(-)
> 
> diff --git a/fs/xfs/xfs_trans_ail.c b/fs/xfs/xfs_trans_ail.c
> index 99a9bf3762b7..0f72cd4e6983 100644
> --- a/fs/xfs/xfs_trans_ail.c
> +++ b/fs/xfs/xfs_trans_ail.c
> @@ -580,8 +580,12 @@ xfsaild_push(
>  	lsn = lip->li_lsn;
>  	while ((XFS_LSN_CMP(lip->li_lsn, ailp->ail_target) <= 0)) {
>  
> -		if (test_bit(XFS_LI_FLUSHING, &lip->li_flags))
> +		if (test_bit(XFS_LI_FLUSHING, &lip->li_flags)) {
> +			flushing++;
> +			count++;
> +			ailp->ail_last_pushed_lsn = lsn;
>  			goto next_item;
> +		}
>  
>  		xfsaild_process_logitem(ailp, lip, &stuck, &flushing);
>  		count++;
> -- 
> 2.43.7
> 
> 

Re: [PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[Dave Chinner]

On Tue, Sep 22, 2026 at 04:14:29PM +0800, MingTao Huang wrote:
> From: MingTao Huang <mintaohuang@tencent.com>
> 
> Commit f3f7ae68a4ea ("xfs: skip flushing log items during push")
> introduced a fast path in xfsaild_push() that uses
> test_bit(XFS_LI_FLUSHING) to skip log items already being
> flushed.  However, the fast path jumps directly to the
> next_item label, bypassing flushing++, count++, and the
> ail_last_pushed_lsn update.  This causes three problems:

Right, they get skipped because they are already flushing and we are
not doing anything with them. i.e. they've already been accounted as
flushing (e.g. inodes that were gathered into a single buffer flush
by xfs_iflush_cluster()) and the buffer is already either on the
delwri list for submission or under IO.

> 
> 1. The loop exit condition "count > 1000" becomes much harder to
>    trigger.  count was meant to track every item visited, but now it

No it isn't.

As the author of this code, I can say for certain that the intent of
'count' is to count the number of items we made pushing decisions
about, not count the number of items we have iterated. 

The purpose of 'flushing' is to account for the number of buffers we
accumulate on the delwri list before we submit it. As count is
incremented whenever flushing is incremented, it currently forms
an upper bound to the number of buffers that can be queued on the
delwri list in a single push iteration.

The purpose of 'stuck' is to account for items that could not be
placed on the delwri list because they were locked, pinned or
otherwise unavailable for flushing.

'success' is not directly counted, because there is no further
action that needs to be taken for them; they are simply counted,
and hence contribute to the flush/stuck ratio decisions later.

IOWs, every 'push decision' that could add a buffer to the delwri
list is accounted by 'count', and flushing/stuck indicate what
decision was made.

The point of LI_FLUSHING was simply to skip over all the items that
would not change either count, flushing or stuck because they have
already been accounted to 'count' and 'flushing' by a prior push
decision.

>    only increments for non-flushing items that enter
>    xfsaild_push_item().

Exactly - count is the number of items we made new pushing decsions
about.

>    Each such item typically triggers an inode
>    cluster flush that marks dozens of neighbouring inodes as flushing,
>    so count effectively counts cluster flushes rather than individual
>    items. 

Yes, that is exactly the intent - a single cluster buffer on the
delwri list covers up to 32 inode items on the AIL. That is -one IO-
for up to 32 items on the AIL, and it is -IO- that we are trying to
account for and optimise here, not log items.

>    The threshold shifts from 1000 items to ~1000 clusters,

No, the count has always been '1000 new buffer IO decisions made',
not '1000 items processed'.

>    letting the loop scan an order of magnitude more items per round.
>    Each cluster flush adds a buffer to ail_buf_list, and the resulting
>    oversized list causes xfs_buf_delwri_submit_nowait() -- which runs
>    list_sort() plus per-buffer trylock and IO submission -- to take so
>    long that the watchdog fires.

How? count bounds the delwri list to 1000 buffers at most. That's
very intentional, and the number is based on benchmarking results.

i.e.  A thousand items on a list takes a couple of milliseconds to
sort. I/O submission of that list takes a couple of milliseconds if
it doesn't block (i.e. the IO subsystem has to be faster than the
CPU IO submission loop to avoid block on a full queue), and if it
does block, we want all the IO submission to merge as effectively as
possible in the queue so that we use as few IO slots in the queue as
possible.

Hence the submission code should not be running around in a hard
loop for 22s because of a list that is too long. The buffer list
length is -bounded- by count, and that should prevent these sorts of
issues.

> 2. The timeout decision "(stuck + flushing) * 100 / count > 90" is
>    computed without the fast-path flushing items, so the flushing ratio
>    is severely under-reported.

No, the accounting this check is acting on is correct. The action we
take is based on the all the items we tried to push this iteration,
not the indirect LI_FLUSHING items that we didn't make a decision
about or are still in progress from the previous iteration.

>    When most of the AIL is flushing, the
>    ratio appears near 0%.

How did you get into a state where most of the AIL is flushing and
no progress is being made transitioning items out of flushing state?

i.e. if delwri submission is not making progress, then the ail push
will keep appending to the delwri list (by design, so we retry
flushing items until submission succeeds). This will result in
transitioning most of the AIL to flushing state and queued on the
delwri list. This is a symptom of the delwri submission not
making progress and rather than a problem with AIL flushing
accounting.

i.e. we need to know why delwri submission is not making progress,
as that is likely the real cause of the problem. i.e. it is unlikely
that this has anythign to do with how we account for item push
decisions, and it is likely your changes just slow down or change
the timing of item pushing sufficiently to avoid whatever issue is
occuring in delwri submission.

>    xfsaild therefore selects
>    "tout = 0" when it should select "tout = 20" (20 ms
>    back-off to let IO complete).  The zero-backoff tight loop compounds
>    the ail_buf_list accumulation across rounds.
> 
> 3. ail_last_pushed_lsn is not advanced past flushing items, so the
>    next push round restarts scanning from the same position, repeatedly
>    traversing items that are still in-flight.

This is why we do not account for flushing items that we skip. It will
walk over them as fast as possible until it reaches items that it
can push. Those items will then be accounted as
flushing/stuck/count. This will then move the last_lsn forwards
appropriately or trigger a log force or backoff sleep and so it
should not get stuck spinning for 22s in that case, either.

> We hit this as a soft lockup during stress testing on an internal
> kernel that includes commit f3f7ae68a4ea ("xfs: skip flushing log
> items during push").  The xfsaild kthread was stuck for
> 22 seconds inside xfs_buf_delwri_submit_nowait(), called from
> xfsaild_push(), processing an excessively large ail_buf_list:

Tell me how the delwri list got so long that it gets stuck inside
xfs_buf_delwri_submit_nowait(). Whatever caused that is the bug that
we need to understand and fix - changing accounting to make gross
behavioural changes that result in exceedingly inefficient CPU usage
and break IO optimisations is not the way to address a list length
that has apparently excceeded the bounds built into the code...

-Dave.


-- 
Dave Chinner
dgc@kernel.org

Re: [PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[Brian Foster]

On Wed, Sep 23, 2026 at 08:12:46AM +1000, Dave Chinner wrote:
> On Tue, Sep 22, 2026 at 04:14:29PM +0800, MingTao Huang wrote:
> > From: MingTao Huang <mintaohuang@tencent.com>
> > 
> > Commit f3f7ae68a4ea ("xfs: skip flushing log items during push")
> > introduced a fast path in xfsaild_push() that uses
> > test_bit(XFS_LI_FLUSHING) to skip log items already being
> > flushed.  However, the fast path jumps directly to the
> > next_item label, bypassing flushing++, count++, and the
> > ail_last_pushed_lsn update.  This causes three problems:
> 
> Right, they get skipped because they are already flushing and we are
> not doing anything with them. i.e. they've already been accounted as
> flushing (e.g. inodes that were gathered into a single buffer flush
> by xfs_iflush_cluster()) and the buffer is already either on the
> delwri list for submission or under IO.
> 
> > 
> > 1. The loop exit condition "count > 1000" becomes much harder to
> >    trigger.  count was meant to track every item visited, but now it
> 
> No it isn't.
> 
> As the author of this code, I can say for certain that the intent of
> 'count' is to count the number of items we made pushing decisions
> about, not count the number of items we have iterated. 
> 
> The purpose of 'flushing' is to account for the number of buffers we
> accumulate on the delwri list before we submit it. As count is
> incremented whenever flushing is incremented, it currently forms
> an upper bound to the number of buffers that can be queued on the
> delwri list in a single push iteration.
> 
> The purpose of 'stuck' is to account for items that could not be
> placed on the delwri list because they were locked, pinned or
> otherwise unavailable for flushing.
> 
> 'success' is not directly counted, because there is no further
> action that needs to be taken for them; they are simply counted,
> and hence contribute to the flush/stuck ratio decisions later.
> 
> IOWs, every 'push decision' that could add a buffer to the delwri
> list is accounted by 'count', and flushing/stuck indicate what
> decision was made.
> 
> The point of LI_FLUSHING was simply to skip over all the items that
> would not change either count, flushing or stuck because they have
> already been accounted to 'count' and 'flushing' by a prior push
> decision.
> 
> >    only increments for non-flushing items that enter
> >    xfsaild_push_item().
> 
> Exactly - count is the number of items we made new pushing decsions
> about.
> 
> >    Each such item typically triggers an inode
> >    cluster flush that marks dozens of neighbouring inodes as flushing,
> >    so count effectively counts cluster flushes rather than individual
> >    items. 
> 
> Yes, that is exactly the intent - a single cluster buffer on the
> delwri list covers up to 32 inode items on the AIL. That is -one IO-
> for up to 32 items on the AIL, and it is -IO- that we are trying to
> account for and optimise here, not log items.
> 
> >    The threshold shifts from 1000 items to ~1000 clusters,
> 
> No, the count has always been '1000 new buffer IO decisions made',
> not '1000 items processed'.
> 
> >    letting the loop scan an order of magnitude more items per round.
> >    Each cluster flush adds a buffer to ail_buf_list, and the resulting
> >    oversized list causes xfs_buf_delwri_submit_nowait() -- which runs
> >    list_sort() plus per-buffer trylock and IO submission -- to take so
> >    long that the watchdog fires.
> 
> How? count bounds the delwri list to 1000 buffers at most. That's
> very intentional, and the number is based on benchmarking results.
> 

I'm confused by some of the reasoning here. Maybe I'm missing something,
but that count check looks like it only limits the current pass. The
flushing value is basically just input into the thread throttling (i.e.
schedule timeout) behavior. So ISTM that if the majority of the AIL is
flushing, we'd historically want to schedule out and wait for I/O to
complete, whereas what this patch describes is a scenario where we now
spin around until enough items clear off the list in that particular
situation.

Prior to the optimization in ~2024, it looks like we'd account all these
flushing items and back off. Also FWIW, looking back at that commit it
doesn't say anything about bounding I/O (not to say this isn't a natural
side effect of xfaild throttling). That commit seems mainly focused on
reducing ->iop_push() call overhead and the implementation only focuses
on inode items, so altogether this strikes me as more of an (perfectly
valid) optimization than fundamental behavior change in how the
processing thread or ail accounting should work.

> i.e.  A thousand items on a list takes a couple of milliseconds to
> sort. I/O submission of that list takes a couple of milliseconds if
> it doesn't block (i.e. the IO subsystem has to be faster than the
> CPU IO submission loop to avoid block on a full queue), and if it
> does block, we want all the IO submission to merge as effectively as
> possible in the queue so that we use as few IO slots in the queue as
> possible.
> 
> Hence the submission code should not be running around in a hard
> loop for 22s because of a list that is too long. The buffer list
> length is -bounded- by count, and that should prevent these sorts of
> issues.
> 
> > 2. The timeout decision "(stuck + flushing) * 100 / count > 90" is
> >    computed without the fast-path flushing items, so the flushing ratio
> >    is severely under-reported.
> 
> No, the accounting this check is acting on is correct. The action we
> take is based on the all the items we tried to push this iteration,
> not the indirect LI_FLUSHING items that we didn't make a decision
> about or are still in progress from the previous iteration.
> 
> >    When most of the AIL is flushing, the
> >    ratio appears near 0%.
> 
> How did you get into a state where most of the AIL is flushing and
> no progress is being made transitioning items out of flushing state?
> 
> i.e. if delwri submission is not making progress, then the ail push
> will keep appending to the delwri list (by design, so we retry
> flushing items until submission succeeds). This will result in
> transitioning most of the AIL to flushing state and queued on the
> delwri list. This is a symptom of the delwri submission not
> making progress and rather than a problem with AIL flushing
> accounting.
> 
> i.e. we need to know why delwri submission is not making progress,
> as that is likely the real cause of the problem. i.e. it is unlikely
> that this has anythign to do with how we account for item push
> decisions, and it is likely your changes just slow down or change
> the timing of item pushing sufficiently to avoid whatever issue is
> occuring in delwri submission.
> 
> >    xfsaild therefore selects
> >    "tout = 0" when it should select "tout = 20" (20 ms
> >    back-off to let IO complete).  The zero-backoff tight loop compounds
> >    the ail_buf_list accumulation across rounds.
> > 
> > 3. ail_last_pushed_lsn is not advanced past flushing items, so the
> >    next push round restarts scanning from the same position, repeatedly
> >    traversing items that are still in-flight.
> 
> This is why we do not account for flushing items that we skip. It will
> walk over them as fast as possible until it reaches items that it
> can push. Those items will then be accounted as
> flushing/stuck/count. This will then move the last_lsn forwards
> appropriately or trigger a log force or backoff sleep and so it
> should not get stuck spinning for 22s in that case, either.
> 
> > We hit this as a soft lockup during stress testing on an internal
> > kernel that includes commit f3f7ae68a4ea ("xfs: skip flushing log
> > items during push").  The xfsaild kthread was stuck for
> > 22 seconds inside xfs_buf_delwri_submit_nowait(), called from
> > xfsaild_push(), processing an excessively large ail_buf_list:
> 
> Tell me how the delwri list got so long that it gets stuck inside
> xfs_buf_delwri_submit_nowait(). Whatever caused that is the bug that
> we need to understand and fix - changing accounting to make gross
> behavioural changes that result in exceedingly inefficient CPU usage
> and break IO optimisations is not the way to address a list length
> that has apparently excceeded the bounds built into the code...
> 

I think the presumption being made here is that the list is growing
excessively because xfsaild is failing to back off when the majority of
(inode) items on the list are in the flushing state.

I guess it would be interesting to know how long the buf list actually
is, and whether the soft lockup warning is purely due to buf list size,
or more of a combination of ail list size/state, buf list size, and
xfsaild thread spinning behavior (we also changed the default timeout to
0).

More of a side note to the discussion and related to the actual patch...
if we did go with something like this ISTM to make more sense to let
xfsaild_push_item() detect and return the flushing state (i.e. similar
to how we handle failed state) so the accounting all exists in one
place, rather than duplicating it for the optimization. Just my .02.

Brian

> -Dave.
> 
> 
> -- 
> Dave Chinner
> dgc@kernel.org
> 

Re: [PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[Dave Chinner]

On Wed, Sep 23, 2026 at 09:44:32AM -0400, Brian Foster wrote:
> On Wed, Sep 23, 2026 at 08:12:46AM +1000, Dave Chinner wrote:
> > On Tue, Sep 22, 2026 at 04:14:29PM +0800, MingTao Huang wrote:
> > > From: MingTao Huang <mintaohuang@tencent.com>
> > > 
> > > Commit f3f7ae68a4ea ("xfs: skip flushing log items during push")
> > > introduced a fast path in xfsaild_push() that uses
> > > test_bit(XFS_LI_FLUSHING) to skip log items already being
> > > flushed.  However, the fast path jumps directly to the
> > > next_item label, bypassing flushing++, count++, and the
> > > ail_last_pushed_lsn update.  This causes three problems:

[....]

> > >    letting the loop scan an order of magnitude more items per round.
> > >    Each cluster flush adds a buffer to ail_buf_list, and the resulting
> > >    oversized list causes xfs_buf_delwri_submit_nowait() -- which runs
> > >    list_sort() plus per-buffer trylock and IO submission -- to take so
> > >    long that the watchdog fires.
> > 
> > How? count bounds the delwri list to 1000 buffers at most. That's
> > very intentional, and the number is based on benchmarking results.
> > 
> 
> I'm confused by some of the reasoning here. Maybe I'm missing something,
> but that count check looks like it only limits the current pass.  The
> flushing value is basically just input into the thread throttling (i.e.
> schedule timeout) behavior.

It's much more complex than that.

The count bounds the number of buffers we can add to the list each
pass.  We also submit the entire list for IO once per pass, hence we
fill and drain the list once per pass. Hence in normal
circumstances, the AIL buffer list should never grow very much
beyond 1000 buffers.

Further, using xfs_buf_delwri_submit_nowait() doesn't mean that it
won't block, it just won't wait for IO completion.  We can still
block on IO submission when the request queue fills up.  i.e. the
AIL push algorithm is designed to throttle writeback processing at
IO submission time, not via the higher level backoff loops.

If the disk is really that fast, then all the items in FLUSHING
state should be completing -really fast- and being removed from the
AIL just as fast. Hence we should not be spinning on the same items
over and over again if we are never blocking in delwri buffer
submission. If we are spinning on the same items, that implies a
problem with IO completion (ie not removing flushing items), not the
AIL push algorithm.

The AIl control loop is also intended to sleep unconditionally when
it reaches the target LSN. Therefore, not sleeping for a long time
implies that the target is continually being moved forward faster
than the AIL can push items to the disk. This also implies that the
disk is sufficiently fast or has sufficiently deep request queues
that it never blocks on IO submission.

Spinning without AIL level backoff or IO submission blocking
occuring therefore implies journal reservations must be full (i.e.
lots of userspace modifcation concurrency on a small journal) or we
are under severe memory pressure triggering repeated full AIL
pushes.  These are really the only two ways to guarantee the push
target always keeps ahead of the aild pushing and so keeps it
permanently busy.

Hence my request for details about the workload, fs geometry, etc,
so I have some idea of how we are getting into this state in the
first place.

> So ISTM that if the majority of the AIL is
> flushing, we'd historically want to schedule out and wait for I/O to
> complete, whereas what this patch describes is a scenario where we now
> spin around until enough items clear off the list in that particular
> situation.

We will only "spin" if pushing is not making progress. If IO is
being submitted, the the LI_FLUSHING state is transient, and the
items will be removed from the AIL when the IO completes. We skip
over them because waiting on LI_FLUSHING items when we are not yet
at the push target LSN means leaving the disk idle when we could be
pushing more writeback to it. i.e. we take longer to submit all the
items we need to get to the target and so end up with lower disk
utilisation, longer journal reservation latency and lower
performance/throughput.

i.e. we only want to throttle processing on IO submission,
not on the number of items we have flushed to IO buffers. Only when
we hit AIL congestion do we want to back off at the AIL level.

> Prior to the optimization in ~2024, it looks like we'd account all these
> flushing items and back off.

Yes, that was broken behaviour, and not what I'd originally intended
for the flush accounting. That commit was when I realised that I'd
overlooked the fact that ITEM_FLUSHING was reporting two completely
different things for inode items. i.e. I realised that the
predominant behaviour being accounted was not the feedback metric
the control loop was designed to use.

The control loop attempts to maximise speed and efficiency of
IO submission - it is not intended to maximise/optimise the number
of items that get processed. Inodes reporting ITEM_FLUSHING when
XFS_IFLUSHING was set was essentially just counting the number of
inodes we attempt to push, and had nothing correlation to IO
submission behaviour.

When the inode is first pushed to the cluster buffer it has
XFS_IFLUSHING set, and if the buffer is successfully queued, it
returns ITEM_SUCCESS. However, if the buffer was already queued (i.e some
other inode has already been pushed to it this cycle), then it will
return ITEM_FLUSHING.

This ITEM_FLUSHING return value indicates that newly dirty inodes
have entered the AIL between when the inode cluster buffer was first
flushed and queued in this processing loop (and returned
ITEM_SUCESS) and now.

IOWs, ITEM_FLUSHING is supposed to be an indication that the the
item is under active modification (i.e. that it has been flushed
multiple times this processing loop), and so there is active
access/modification vs writeback contention on the item.

The other case that inode item push returns ITEM_FLUSHING is if the
inode already has XFS_IFLUSHING set on it. This indicates that the
inode has already been flushed to the cluster buffer via a another
inode push on the same cluster buffer, but by itself it tells us
-nothing- about whether that inode is being actively modified.

That is because xfs_iflush_cluster() gathers all inodes in the
buffer, regardless of where they are in the AIL. So may be older,
some newer, and so encountering a XFS_IFLUSHING inode carries no
signal about whether it is being actively modified, nor does it tell
us that the queued cluster buffer has been updated whilst it was
already queued.

Hence, from the POV of the AIL control loop, this latter
ITEM_FLUSHING metric is pure noise. We did not queue new IO, we did
not update a buffer already queued for IO, and we do not know if the
item has been recently modified, yet we still accounted it as
"flushing".

Hence the LI_FLUSHING tag: it separates the signal the control loop
wants (how many objects we pushed multiple times in this processing
loop) from the noise (how many inodes we've encountered that are
already either queued for submission, under IO or queued for
completion processing from the current and/or any previous
processing loop iteration).

IOWs, the AIL push loop backoffs are not really about waiting for IO
completion - IO completion occurs as a side effect of backing off.
The purpose is to reduce the amount of unnecessary writeback and log
forces we do for objects in the AIL that are under active
modification.

By allowing time for such objects to be relogged and moved forward
in the AIL instead of written back, we minimise the amount of
repeated metadata IO we will need to reach the target LSN. Relogging
is far more IO efficient (sequential journal IO) that metadata
writeback (random small write IO), and this is one of the key IO
optimisations the back-offs are trying to achieve.

TL;DR: the flush backoff is supposed to address the case where the
AIL is contending with active modifications to items that need
writeback. It backs off to allow the IO to complete and allow the
actively modified objects to be relogged and moved well away from
the current LSN the AIL is processing. This avoids repeated
mod->journal->writeback->mod->journal->writeback... cycles,
encouraging mod->journal->mod->journal->... behaviour instead.

> Also FWIW, looking back at that commit it
> doesn't say anything about bounding I/O (not to say this isn't a natural
> side effect of xfaild throttling).

It's not a side effect of xfsaild throttling. It's a natural
behaviour from the 1:1 "fill queue, drain queue" IO processing loop.
I thought that was obvious from the "block on IO submission" part of
the commit message and never needed more explanation, but I guess it
wasn't.

> That commit seems mainly focused on
> reducing ->iop_push() call overhead and the implementation only focuses
> on inode items, so altogether this strikes me as more of an (perfectly
> valid) optimization than fundamental behavior change in how the
> processing thread or ail accounting should work.

Commit messages can never tell the whole story. They have to walk a
line between describing the problem being solved and reviewers
needing to understand all the subtle intricacies of how a tiny tweak
fixes a problem with a complex algorithm....

Reading that commit message back now, the iop_push() cpu consumption
was the measurable symptom that exposed the issue (i.e excessive CPU
usage processing a million 'no-op' ITEM_FLUSHING pushes every
second). However, the second half of the commit message is all about
how the LI_FLUSHING accounting change exposed other mitigations we'd
made to handle the noise the inode flushing accounting generated,
and why they weren't necessary anymore.

> > > We hit this as a soft lockup during stress testing on an internal
> > > kernel that includes commit f3f7ae68a4ea ("xfs: skip flushing log
> > > items during push").  The xfsaild kthread was stuck for
> > > 22 seconds inside xfs_buf_delwri_submit_nowait(), called from
> > > xfsaild_push(), processing an excessively large ail_buf_list:
> > 
> > Tell me how the delwri list got so long that it gets stuck inside
> > xfs_buf_delwri_submit_nowait(). Whatever caused that is the bug that
> > we need to understand and fix - changing accounting to make gross
> > behavioural changes that result in exceedingly inefficient CPU usage
> > and break IO optimisations is not the way to address a list length
> > that has apparently excceeded the bounds built into the code...
> > 
> 
> I think the presumption being made here is that the list is growing
> excessively because xfsaild is failing to back off when the majority of
> (inode) items on the list are in the flushing state.

I don't want to presume anything.

i.e. I don't know how the problem manifests yet, and the proposed
solution is not viable. We need to find the root cause of the issue
before going any further.

> I guess it would be interesting to know how long the buf list actually
> is, and whether the soft lockup warning is purely due to buf list size,
> or more of a combination of ail list size/state, buf list size, and
> xfsaild thread spinning behavior (we also changed the default timeout to
> 0).

Yes.

> More of a side note to the discussion and related to the actual patch...
> if we did go with something like this ISTM to make more sense to let
> xfsaild_push_item() detect and return the flushing state (i.e. similar
> to how we handle failed state) so the accounting all exists in one
> place, rather than duplicating it for the optimization. Just my .02.

I'm not sure it does - see my comment above about ITEM_FLUSHING
being returned by inode items meaning two very different things, and
LI_FLUSHING being used to remove the noisy/useless one from the
control loop.

Cheers,

Dave.
-- 
Dave Chinner
dgc@kernel.org

Re: [PATCH] xfs: fix skipped flushing items not counted in xfsaild_push()

[MingTao Huang]

Hi Dave,

Thank you for the detailed explanation.

> As the author of this code, I can say for certain that the
> intent of 'count' is to count the number of items we made
> pushing decisions about, not count the number of items we
> have iterated.

I wasn't aware that count tracks push decisions rather than
items visited. Thank you for clarifying this.

> Tell me how the delwri list got so long that it gets stuck
> inside xfs_buf_delwri_submit_nowait(). Whatever caused that
> is the bug that we need to understand and fix

I think your point is well taken. I will continue investigating
the root cause of this soft lockup and follow up when I have
more evidence.

Thanks,
MingTao