[PATCH v3 0/3] xfs: fix some log stalling problems in defer ops

[PATCH v3 0/3] xfs: fix some log stalling problems in defer ops

[Darrick J. Wong]

Hi all,

This series tries to fix some structural problems in the defer ops code.
The defer ops code has been finishing items in the wrong order -- if a
top level defer op creates items A and B, and finishing item A creates
more defer ops A1 and A2, we'll put the new items on the end of the chain
and process them in the order A B A1 A2.  This is kind of weird, since
it's convenient for programmers to be able to think of A and B as an
ordered sequence where all the work for A must finish before we move on
to B, e.g. A A1 A2 D.

That isn't how the defer ops actually works, but so far we've been lucky
that this hasn't ever caused serious problems.  This /will/, however,
when we get to the atomic extent swap code, where for refcounting
purposes it actually /does/ matter that unmap and map child intents
execute in that order, and complete before we move on to the next extent
in the files.  This also causes a very long chain of intent items to
build up, which can exhaust memory.

We need to teach defer ops to finish all the sub-work associated with
each defer op that the caller gave us, to minimize the length of the
defer ops chains; and then we need to teach it to relog items
periodically to avoid pinning the log tail.

v2: combine all the relog patches into one, and base the decision to
relog an iten dependent on whether or not it's in an old checkpoint
v3: fix backwards logic, don't relog items in the same checkpoint,
and split up the changes

If you're going to start using this mess, you probably ought to just
pull from my git trees, which are linked below.

This is an extraordinary way to destroy everything.  Enjoy!
Comments and questions are, as always, welcome.

--D

kernel git tree:
https://git.kernel.org/cgit/linux/kernel/git/djwong/xfs-linux.git/log/?h=defer-ops-stalls

xfsprogs git tree:
https://git.kernel.org/cgit/linux/kernel/git/djwong/xfsprogs-dev.git/log/?h=defer-ops-stalls
---
 fs/xfs/libxfs/xfs_defer.c  |   63 +++++++++++++++++++++++++++++++++++++++++++-
 fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++
 fs/xfs/xfs_extfree_item.c  |   29 ++++++++++++++++++++
 fs/xfs/xfs_log.c           |   41 ++++++++++++++++++++++-------
 fs/xfs/xfs_log.h           |    2 +
 fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++
 fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++
 fs/xfs/xfs_trace.h         |    1 +
 fs/xfs/xfs_trans.h         |   10 +++++++
 9 files changed, 216 insertions(+), 11 deletions(-)

[PATCH 1/3] xfs: change the order in which child and parent defer ops are finished

[Darrick J. Wong]

From: Darrick J. Wong <darrick.wong@oracle.com>

The defer ops code has been finishing items in the wrong order -- if a
top level defer op creates items A and B, and finishing item A creates
more defer ops A1 and A2, we'll put the new items on the end of the
chain and process them in the order A B A1 A2.  This is kind of weird,
since it's convenient for programmers to be able to think of A and B as
an ordered sequence where all the sub-tasks for A must finish before we
move on to B, e.g. A A1 A2 D.

Right now, our log intent items are not so complex that this matters,
but this will become important for the atomic extent swapping patchset.
In order to maintain correct reference counting of extents, we have to
unmap and remap extents in that order, and we want to complete that work
before moving on to the next range that the user wants to swap.  This
patch fixes defer ops to satsify that requirement.

The primary symptom of the incorrect order was noticed in an early
performance analysis of the atomic extent swap code.  An astonishingly
large number of deferred work items accumulated when userspace requested
an atomic update of two very fragmented files.  The cause of this was
traced to the same ordering bug in the inner loop of
xfs_defer_finish_noroll.

If the ->finish_item method of a deferred operation queues new deferred
operations, those new deferred ops are appended to the tail of the
pending work list.  To illustrate, say that a caller creates a
transaction t0 with four deferred operations D0-D3.  The first thing
defer ops does is roll the transaction to t1, leaving us with:

t1: D0(t0), D1(t0), D2(t0), D3(t0)

Let's say that finishing each of D0-D3 will create two new deferred ops.
After finish D0 and roll, we'll have the following chain:

t2: D1(t0), D2(t0), D3(t0), d4(t1), d5(t1)

d4 and d5 were logged to t1.  Notice that while we're about to start
work on D1, we haven't actually completed all the work implied by D0
being finished.  So far we've been careful (or lucky) to structure the
dfops callers such that D1 doesn't depend on d4 or d5 being finished,
but this is a potential logic bomb.

There's a second problem lurking.  Let's see what happens as we finish
D1-D3:

t3: D2(t0), D3(t0), d4(t1), d5(t1), d6(t2), d7(t2)
t4: D3(t0), d4(t1), d5(t1), d6(t2), d7(t2), d8(t3), d9(t3)
t5: d4(t1), d5(t1), d6(t2), d7(t2), d8(t3), d9(t3), d10(t4), d11(t4)

Let's say that d4-d11 are simple work items that don't queue any other
operations, which means that we can complete each d4 and roll to t6:

t6: d5(t1), d6(t2), d7(t2), d8(t3), d9(t3), d10(t4), d11(t4)
t7: d6(t2), d7(t2), d8(t3), d9(t3), d10(t4), d11(t4)
...
t11: d10(t4), d11(t4)
t12: d11(t4)
<done>

When we try to roll to transaction #12, we're holding defer op d11,
which we logged way back in t4.  This means that the tail of the log is
pinned at t4.  If the log is very small or there are a lot of other
threads updating metadata, this means that we might have wrapped the log
and cannot get roll to t11 because there isn't enough space left before
we'd run into t4.

Let's shift back to the original failure.  I mentioned before that I
discovered this flaw while developing the atomic file update code.  In
that scenario, we have a defer op (D0) that finds a range of file blocks
to remap, creates a handful of new defer ops to do that, and then asks
to be continued with however much work remains.

So, D0 is the original swapext deferred op.  The first thing defer ops
does is rolls to t1:

t1: D0(t0)

We try to finish D0, logging d1 and d2 in the process, but can't get all
the work done.  We log a done item and a new intent item for the work
that D0 still has to do, and roll to t2:

t2: D0'(t1), d1(t1), d2(t1)

We roll and try to finish D0', but still can't get all the work done, so
we log a done item and a new intent item for it, requeue D0 a second
time, and roll to t3:

t3: D0''(t2), d1(t1), d2(t1), d3(t2), d4(t2)

If it takes 48 more rolls to complete D0, then we'll finally dispense
with D0 in t50:

t50: D<fifty primes>(t49), d1(t1), ..., d102(t50)

We then try to roll again to get a chain like this:

t51: d1(t1), d2(t1), ..., d101(t50), d102(t50)
...
t152: d102(t50)
<done>

Notice that in rolling to transaction #51, we're holding on to a log
intent item for d1 that was logged in transaction #1.  This means that
the tail of the log is pinned at t1.  If the log is very small or there
are a lot of other threads updating metadata, this means that we might
have wrapped the log and cannot roll to t51 because there isn't enough
space left before we'd run into t1.  This is of course problem #2 again.

But notice the third problem with this scenario: we have 102 defer ops
tied to this transaction!  Each of these items are backed by pinned
kernel memory, which means that we risk OOM if the chains get too long.

Yikes.  Problem #1 is a subtle logic bomb that could hit someone in the
future; problem #2 applies (rarely) to the current upstream, and problem
#3 applies to work under development.

This is not how incremental deferred operations were supposed to work.
The dfops design of logging in the same transaction an intent-done item
and a new intent item for the work remaining was to make it so that we
only have to juggle enough deferred work items to finish that one small
piece of work.  Deferred log item recovery will find that first
unfinished work item and restart it, no matter how many other intent
items might follow it in the log.  Therefore, it's ok to put the new
intents at the start of the dfops chain.

For the first example, the chains look like this:

t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
t3: d5(t1), D1(t0), D2(t0), D3(t0)
...
t9: d9(t7), D3(t0)
t10: D3(t0)
t11: d10(t10), d11(t10)
t12: d11(t10)

For the second example, the chains look like this:

t1: D0(t0)
t2: d1(t1), d2(t1), D0'(t1)
t3: d2(t1), D0'(t1)
t4: D0'(t1)
t5: d1(t4), d2(t4), D0''(t4)
...
t148: D0<50 primes>(t147)
t149: d101(t148), d102(t148)
t150: d102(t148)
<done>

This actually sucks more for pinning the log tail (we try to roll to t10
while holding an intent item that was logged in t1) but we've solved
problem #1.  We've also reduced the maximum chain length from:

    sum(all the new items) + nr_original_items

to:

    max(new items that each original item creates) + nr_original_items

This solves problem #3 by sharply reducing the number of defer ops that
can be attached to a transaction at any given time.  The change makes
the problem of log tail pinning worse, but is improvement we need to
solve problem #2.  Actually solving #2, however, is left to the next
patch.

Note that a subsequent analysis of some hard-to-trigger reflink and COW
livelocks on extremely fragmented filesystems (or systems running a lot
of IO threads) showed the same symptoms -- uncomfortably large numbers
of incore deferred work items and occasional stalls in the transaction
grant code while waiting for log reservations.  I think this patch and
the next one will also solve these problems.

As originally written, the code used list_splice_tail_init instead of
list_splice_init, so change that, and leave a short comment explaining
our actions.

Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
Reviewed-by: Dave Chinner <dchinner@redhat.com>
Reviewed-by: Brian Foster <bfoster@redhat.com>
---
 fs/xfs/libxfs/xfs_defer.c |   11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)


diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
index 97523b394932..84a70edd0da1 100644
--- a/fs/xfs/libxfs/xfs_defer.c
+++ b/fs/xfs/libxfs/xfs_defer.c
@@ -431,8 +431,17 @@ xfs_defer_finish_noroll(
 
 	/* Until we run out of pending work to finish... */
 	while (!list_empty(&dop_pending) || !list_empty(&(*tp)->t_dfops)) {
+		/*
+		 * Deferred items that are created in the process of finishing
+		 * other deferred work items should be queued at the head of
+		 * the pending list, which puts them ahead of the deferred work
+		 * that was created by the caller.  This keeps the number of
+		 * pending work items to a minimum, which decreases the amount
+		 * of time that any one intent item can stick around in memory,
+		 * pinning the log tail.
+		 */
 		xfs_defer_create_intents(*tp);
-		list_splice_tail_init(&(*tp)->t_dfops, &dop_pending);
+		list_splice_init(&(*tp)->t_dfops, &dop_pending);
 
 		error = xfs_defer_trans_roll(tp);
 		if (error)

[PATCH 2/3] xfs: expose the log push threshold

[Darrick J. Wong]

From: Darrick J. Wong <darrick.wong@oracle.com>

Separate the computation of the log push threshold and the push logic in
xlog_grant_push_ail.  This enables higher level code to determine (for
example) that it is holding on to a logged intent item and the log is so
busy that it is more than 75% full.  In that case, it would be desirable
to move the log item towards the head to release the tail, which we will
cover in the next patch.

Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
---
 fs/xfs/xfs_log.c |   41 +++++++++++++++++++++++++++++++----------
 fs/xfs/xfs_log.h |    2 ++
 2 files changed, 33 insertions(+), 10 deletions(-)


diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
index ad0c69ee8947..62c9e0aaa7df 100644
--- a/fs/xfs/xfs_log.c
+++ b/fs/xfs/xfs_log.c
@@ -1475,14 +1475,15 @@ xlog_commit_record(
 }
 
 /*
- * Push on the buffer cache code if we ever use more than 75% of the on-disk
- * log space.  This code pushes on the lsn which would supposedly free up
- * the 25% which we want to leave free.  We may need to adopt a policy which
- * pushes on an lsn which is further along in the log once we reach the high
- * water mark.  In this manner, we would be creating a low water mark.
+ * Compute the LSN push target needed to push on the buffer cache code if we
+ * ever use more than 75% of the on-disk log space.  This code pushes on the
+ * lsn which would supposedly free up the 25% which we want to leave free.  We
+ * may need to adopt a policy which pushes on an lsn which is further along in
+ * the log once we reach the high water mark.  In this manner, we would be
+ * creating a low water mark.
  */
-STATIC void
-xlog_grant_push_ail(
+xfs_lsn_t
+xlog_grant_push_threshold(
 	struct xlog	*log,
 	int		need_bytes)
 {
@@ -1508,7 +1509,7 @@ xlog_grant_push_ail(
 	free_threshold = max(free_threshold, (log->l_logBBsize >> 2));
 	free_threshold = max(free_threshold, 256);
 	if (free_blocks >= free_threshold)
-		return;
+		return NULLCOMMITLSN;
 
 	xlog_crack_atomic_lsn(&log->l_tail_lsn, &threshold_cycle,
 						&threshold_block);
@@ -1528,13 +1529,33 @@ xlog_grant_push_ail(
 	if (XFS_LSN_CMP(threshold_lsn, last_sync_lsn) > 0)
 		threshold_lsn = last_sync_lsn;
 
+	return threshold_lsn;
+}
+
+/*
+ * Push on the buffer cache code if we ever use more than 75% of the on-disk
+ * log space.  This code pushes on the lsn which would supposedly free up
+ * the 25% which we want to leave free.  We may need to adopt a policy which
+ * pushes on an lsn which is further along in the log once we reach the high
+ * water mark.  In this manner, we would be creating a low water mark.
+ */
+STATIC void
+xlog_grant_push_ail(
+	struct xlog	*log,
+	int		need_bytes)
+{
+	xfs_lsn_t	threshold_lsn;
+
+	threshold_lsn = xlog_grant_push_threshold(log, need_bytes);
+	if (threshold_lsn == NULLCOMMITLSN || XLOG_FORCED_SHUTDOWN(log))
+		return;
+
 	/*
 	 * Get the transaction layer to kick the dirty buffers out to
 	 * disk asynchronously. No point in trying to do this if
 	 * the filesystem is shutting down.
 	 */
-	if (!XLOG_FORCED_SHUTDOWN(log))
-		xfs_ail_push(log->l_ailp, threshold_lsn);
+	xfs_ail_push(log->l_ailp, threshold_lsn);
 }
 
 /*
diff --git a/fs/xfs/xfs_log.h b/fs/xfs/xfs_log.h
index 1412d6993f1e..58c3fcbec94a 100644
--- a/fs/xfs/xfs_log.h
+++ b/fs/xfs/xfs_log.h
@@ -141,4 +141,6 @@ void	xfs_log_quiesce(struct xfs_mount *mp);
 bool	xfs_log_check_lsn(struct xfs_mount *, xfs_lsn_t);
 bool	xfs_log_in_recovery(struct xfs_mount *);
 
+xfs_lsn_t xlog_grant_push_threshold(struct xlog *log, int need_bytes);
+
 #endif	/* __XFS_LOG_H__ */

Re: [PATCH 2/3] xfs: expose the log push threshold

[Brian Foster]

On Tue, Sep 22, 2020 at 10:33:13PM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <darrick.wong@oracle.com>
> 
> Separate the computation of the log push threshold and the push logic in
> xlog_grant_push_ail.  This enables higher level code to determine (for
> example) that it is holding on to a logged intent item and the log is so
> busy that it is more than 75% full.  In that case, it would be desirable
> to move the log item towards the head to release the tail, which we will
> cover in the next patch.
> 
> Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> ---
>  fs/xfs/xfs_log.c |   41 +++++++++++++++++++++++++++++++----------
>  fs/xfs/xfs_log.h |    2 ++
>  2 files changed, 33 insertions(+), 10 deletions(-)
> 
> 
> diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> index ad0c69ee8947..62c9e0aaa7df 100644
> --- a/fs/xfs/xfs_log.c
> +++ b/fs/xfs/xfs_log.c
> @@ -1475,14 +1475,15 @@ xlog_commit_record(
>  }
>  
>  /*
> - * Push on the buffer cache code if we ever use more than 75% of the on-disk
> - * log space.  This code pushes on the lsn which would supposedly free up
> - * the 25% which we want to leave free.  We may need to adopt a policy which
> - * pushes on an lsn which is further along in the log once we reach the high
> - * water mark.  In this manner, we would be creating a low water mark.
> + * Compute the LSN push target needed to push on the buffer cache code if we
> + * ever use more than 75% of the on-disk log space.  This code pushes on the
> + * lsn which would supposedly free up the 25% which we want to leave free.  We
> + * may need to adopt a policy which pushes on an lsn which is further along in
> + * the log once we reach the high water mark.  In this manner, we would be
> + * creating a low water mark.
>   */

Probably no need to duplicate so much of the original comment between
the two functions. I'd just put something like "calculate the AIL push
target based on the provided log reservation requirement ..." or
otherwise just remove it. That aside, LGTM:

Reviewed-by: Brian Foster <bfoster@redhat.com>

> -STATIC void
> -xlog_grant_push_ail(
> +xfs_lsn_t
> +xlog_grant_push_threshold(
>  	struct xlog	*log,
>  	int		need_bytes)
>  {
> @@ -1508,7 +1509,7 @@ xlog_grant_push_ail(
>  	free_threshold = max(free_threshold, (log->l_logBBsize >> 2));
>  	free_threshold = max(free_threshold, 256);
>  	if (free_blocks >= free_threshold)
> -		return;
> +		return NULLCOMMITLSN;
>  
>  	xlog_crack_atomic_lsn(&log->l_tail_lsn, &threshold_cycle,
>  						&threshold_block);
> @@ -1528,13 +1529,33 @@ xlog_grant_push_ail(
>  	if (XFS_LSN_CMP(threshold_lsn, last_sync_lsn) > 0)
>  		threshold_lsn = last_sync_lsn;
>  
> +	return threshold_lsn;
> +}
> +
> +/*
> + * Push on the buffer cache code if we ever use more than 75% of the on-disk
> + * log space.  This code pushes on the lsn which would supposedly free up
> + * the 25% which we want to leave free.  We may need to adopt a policy which
> + * pushes on an lsn which is further along in the log once we reach the high
> + * water mark.  In this manner, we would be creating a low water mark.
> + */
> +STATIC void
> +xlog_grant_push_ail(
> +	struct xlog	*log,
> +	int		need_bytes)
> +{
> +	xfs_lsn_t	threshold_lsn;
> +
> +	threshold_lsn = xlog_grant_push_threshold(log, need_bytes);
> +	if (threshold_lsn == NULLCOMMITLSN || XLOG_FORCED_SHUTDOWN(log))
> +		return;
> +
>  	/*
>  	 * Get the transaction layer to kick the dirty buffers out to
>  	 * disk asynchronously. No point in trying to do this if
>  	 * the filesystem is shutting down.
>  	 */
> -	if (!XLOG_FORCED_SHUTDOWN(log))
> -		xfs_ail_push(log->l_ailp, threshold_lsn);
> +	xfs_ail_push(log->l_ailp, threshold_lsn);
>  }
>  
>  /*
> diff --git a/fs/xfs/xfs_log.h b/fs/xfs/xfs_log.h
> index 1412d6993f1e..58c3fcbec94a 100644
> --- a/fs/xfs/xfs_log.h
> +++ b/fs/xfs/xfs_log.h
> @@ -141,4 +141,6 @@ void	xfs_log_quiesce(struct xfs_mount *mp);
>  bool	xfs_log_check_lsn(struct xfs_mount *, xfs_lsn_t);
>  bool	xfs_log_in_recovery(struct xfs_mount *);
>  
> +xfs_lsn_t xlog_grant_push_threshold(struct xlog *log, int need_bytes);
> +
>  #endif	/* __XFS_LOG_H__ */
> 

Re: [PATCH 2/3] xfs: expose the log push threshold

[Darrick J. Wong]

On Fri, Sep 25, 2020 at 07:15:11AM -0400, Brian Foster wrote:
> On Tue, Sep 22, 2020 at 10:33:13PM -0700, Darrick J. Wong wrote:
> > From: Darrick J. Wong <darrick.wong@oracle.com>
> > 
> > Separate the computation of the log push threshold and the push logic in
> > xlog_grant_push_ail.  This enables higher level code to determine (for
> > example) that it is holding on to a logged intent item and the log is so
> > busy that it is more than 75% full.  In that case, it would be desirable
> > to move the log item towards the head to release the tail, which we will
> > cover in the next patch.
> > 
> > Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> > ---
> >  fs/xfs/xfs_log.c |   41 +++++++++++++++++++++++++++++++----------
> >  fs/xfs/xfs_log.h |    2 ++
> >  2 files changed, 33 insertions(+), 10 deletions(-)
> > 
> > 
> > diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> > index ad0c69ee8947..62c9e0aaa7df 100644
> > --- a/fs/xfs/xfs_log.c
> > +++ b/fs/xfs/xfs_log.c
> > @@ -1475,14 +1475,15 @@ xlog_commit_record(
> >  }
> >  
> >  /*
> > - * Push on the buffer cache code if we ever use more than 75% of the on-disk
> > - * log space.  This code pushes on the lsn which would supposedly free up
> > - * the 25% which we want to leave free.  We may need to adopt a policy which
> > - * pushes on an lsn which is further along in the log once we reach the high
> > - * water mark.  In this manner, we would be creating a low water mark.
> > + * Compute the LSN push target needed to push on the buffer cache code if we
> > + * ever use more than 75% of the on-disk log space.  This code pushes on the
> > + * lsn which would supposedly free up the 25% which we want to leave free.  We
> > + * may need to adopt a policy which pushes on an lsn which is further along in
> > + * the log once we reach the high water mark.  In this manner, we would be
> > + * creating a low water mark.
> >   */
> 
> Probably no need to duplicate so much of the original comment between
> the two functions. I'd just put something like "calculate the AIL push
> target based on the provided log reservation requirement ..." or
> otherwise just remove it. That aside, LGTM:

Hmm, how about this for xlog_grant_push_threshold:

/*
 * Compute the LSN that we'd need to push the log tail towards in order
 * to have (a) enough on-disk log space to log the number of bytes
 * specified, (b) at least 25% of the log space free, and (c) at least
 * 256 blocks free.  If the log free space already meets all three
 * thresholds, this function returns NULLCOMMITLSN.
 */

and then this for xlog_grant_push_ail:

/*
 * Push the tail of the log if we need to do so to maintain the free log
 * space thresholds set out by xlog_grant_push_threshold.  We may need
 * to adopt a policy which pushes on an lsn which is further along in
 * the log once we reach the high water mark.  In this manner, we would
 * be creating a low water mark.
 */

> Reviewed-by: Brian Foster <bfoster@redhat.com>

Thanks for the review!

--D

> > -STATIC void
> > -xlog_grant_push_ail(
> > +xfs_lsn_t
> > +xlog_grant_push_threshold(
> >  	struct xlog	*log,
> >  	int		need_bytes)
> >  {
> > @@ -1508,7 +1509,7 @@ xlog_grant_push_ail(
> >  	free_threshold = max(free_threshold, (log->l_logBBsize >> 2));
> >  	free_threshold = max(free_threshold, 256);
> >  	if (free_blocks >= free_threshold)
> > -		return;
> > +		return NULLCOMMITLSN;
> >  
> >  	xlog_crack_atomic_lsn(&log->l_tail_lsn, &threshold_cycle,
> >  						&threshold_block);
> > @@ -1528,13 +1529,33 @@ xlog_grant_push_ail(
> >  	if (XFS_LSN_CMP(threshold_lsn, last_sync_lsn) > 0)
> >  		threshold_lsn = last_sync_lsn;
> >  
> > +	return threshold_lsn;
> > +}
> > +
> > +/*
> > + * Push on the buffer cache code if we ever use more than 75% of the on-disk
> > + * log space.  This code pushes on the lsn which would supposedly free up
> > + * the 25% which we want to leave free.  We may need to adopt a policy which
> > + * pushes on an lsn which is further along in the log once we reach the high
> > + * water mark.  In this manner, we would be creating a low water mark.
> > + */
> > +STATIC void
> > +xlog_grant_push_ail(
> > +	struct xlog	*log,
> > +	int		need_bytes)
> > +{
> > +	xfs_lsn_t	threshold_lsn;
> > +
> > +	threshold_lsn = xlog_grant_push_threshold(log, need_bytes);
> > +	if (threshold_lsn == NULLCOMMITLSN || XLOG_FORCED_SHUTDOWN(log))
> > +		return;
> > +
> >  	/*
> >  	 * Get the transaction layer to kick the dirty buffers out to
> >  	 * disk asynchronously. No point in trying to do this if
> >  	 * the filesystem is shutting down.
> >  	 */
> > -	if (!XLOG_FORCED_SHUTDOWN(log))
> > -		xfs_ail_push(log->l_ailp, threshold_lsn);
> > +	xfs_ail_push(log->l_ailp, threshold_lsn);
> >  }
> >  
> >  /*
> > diff --git a/fs/xfs/xfs_log.h b/fs/xfs/xfs_log.h
> > index 1412d6993f1e..58c3fcbec94a 100644
> > --- a/fs/xfs/xfs_log.h
> > +++ b/fs/xfs/xfs_log.h
> > @@ -141,4 +141,6 @@ void	xfs_log_quiesce(struct xfs_mount *mp);
> >  bool	xfs_log_check_lsn(struct xfs_mount *, xfs_lsn_t);
> >  bool	xfs_log_in_recovery(struct xfs_mount *);
> >  
> > +xfs_lsn_t xlog_grant_push_threshold(struct xlog *log, int need_bytes);
> > +
> >  #endif	/* __XFS_LOG_H__ */
> > 
> 

[PATCH 3/3] xfs: periodically relog deferred intent items

[Darrick J. Wong]

From: Darrick J. Wong <darrick.wong@oracle.com>

There's a subtle design flaw in the deferred log item code that can lead
to pinning the log tail.  Taking up the defer ops chain examples from
the previous commit, we can get trapped in sequences like this:

Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
chain will look like the following if the transaction rolls succeed:

t1: D0(t0), D1(t0), D2(t0), D3(t0)
t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
t3: d5(t1), D1(t0), D2(t0), D3(t0)
...
t9: d9(t7), D3(t0)
t10: D3(t0)
t11: d10(t10), d11(t10)
t12: d11(t10)

In transaction 9, we finish d9 and try to roll to t10 while holding onto
an intent item for D3 that we logged in t0.

The previous commit changed the order in which we place new defer ops in
the defer ops processing chain to reduce the maximum chain length.  Now
make xfs_defer_finish_noroll capable of relogging the entire chain
periodically so that we can always move the log tail forward.  Most
chains will never get relogged, except for operations that generate very
long chains (large extents containing many blocks with different sharing
levels) or are on filesystems with small logs and a lot of ongoing
metadata updates.

Callers are now required to ensure that the transaction reservation is
large enough to handle logging done items and new intent items for the
maximum possible chain length.  Most callers are careful to keep the
chain lengths low, so the overhead should be minimal.

The decision to relog an intent item is made based on whether or not the
intent was added to the current checkpoint.  If so, the checkpoint is
still open and there's no point in relogging.  Otherwise, the old
checkpoint is closed and we relog the intent to add it to the current
one.

Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
---
 fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
 fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
 fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
 fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
 fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
 fs/xfs/xfs_trace.h         |    1 +
 fs/xfs/xfs_trans.h         |   10 ++++++++
 7 files changed, 173 insertions(+)


diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
index 84a70edd0da1..c601cc2af254 100644
--- a/fs/xfs/libxfs/xfs_defer.c
+++ b/fs/xfs/libxfs/xfs_defer.c
@@ -17,6 +17,7 @@
 #include "xfs_inode_item.h"
 #include "xfs_trace.h"
 #include "xfs_icache.h"
+#include "xfs_log.h"
 
 /*
  * Deferred Operations in XFS
@@ -361,6 +362,52 @@ xfs_defer_cancel_list(
 	}
 }
 
+/*
+ * Prevent a log intent item from pinning the tail of the log by logging a
+ * done item to release the intent item; and then log a new intent item.
+ * The caller should provide a fresh transaction and roll it after we're done.
+ */
+static int
+xfs_defer_relog(
+	struct xfs_trans		**tpp,
+	struct list_head		*dfops)
+{
+	struct xfs_defer_pending	*dfp;
+	xfs_lsn_t			threshold_lsn;
+
+	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
+
+	/*
+	 * Figure out where we need the tail to be in order to maintain the
+	 * minimum required free space in the log.
+	 */
+	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
+	if (threshold_lsn == NULLCOMMITLSN)
+		return 0;
+
+	list_for_each_entry(dfp, dfops, dfp_list) {
+		/*
+		 * If the log intent item for this deferred op is behind the
+		 * desired log tail threshold and is not a part of the current
+		 * log checkpoint, relog the intent item to keep the log tail
+		 * moving forward.  We're ok with this being racy because an
+		 * incorrect decision means we'll be a little slower at pushing
+		 * the tail.
+		 */
+		if (dfp->dfp_intent == NULL ||
+		    XFS_LSN_CMP(dfp->dfp_intent->li_lsn, threshold_lsn) >= 0 ||
+		    xfs_log_item_in_current_chkpt(dfp->dfp_intent))
+			continue;
+
+		trace_xfs_defer_relog_intent((*tpp)->t_mountp, dfp);
+		dfp->dfp_intent = xfs_trans_item_relog(dfp->dfp_intent, *tpp);
+	}
+
+	if ((*tpp)->t_flags & XFS_TRANS_DIRTY)
+		return xfs_defer_trans_roll(tpp);
+	return 0;
+}
+
 /*
  * Log an intent-done item for the first pending intent, and finish the work
  * items.
@@ -447,6 +494,11 @@ xfs_defer_finish_noroll(
 		if (error)
 			goto out_shutdown;
 
+		/* Every few rolls we relog all the intent items. */
+		error = xfs_defer_relog(tp, &dop_pending);
+		if (error)
+			goto out_shutdown;
+
 		dfp = list_first_entry(&dop_pending, struct xfs_defer_pending,
 				       dfp_list);
 		error = xfs_defer_finish_one(*tp, dfp);
diff --git a/fs/xfs/xfs_bmap_item.c b/fs/xfs/xfs_bmap_item.c
index 008436ef5bce..6317fdf4a3a0 100644
--- a/fs/xfs/xfs_bmap_item.c
+++ b/fs/xfs/xfs_bmap_item.c
@@ -532,6 +532,32 @@ xfs_bui_item_match(
 	return BUI_ITEM(lip)->bui_format.bui_id == intent_id;
 }
 
+/* Relog an intent item to push the log tail forward. */
+static struct xfs_log_item *
+xfs_bui_item_relog(
+	struct xfs_log_item		*intent,
+	struct xfs_trans		*tp)
+{
+	struct xfs_bud_log_item		*budp;
+	struct xfs_bui_log_item		*buip;
+	struct xfs_map_extent		*extp;
+	unsigned int			count;
+
+	count = BUI_ITEM(intent)->bui_format.bui_nextents;
+	extp = BUI_ITEM(intent)->bui_format.bui_extents;
+
+	tp->t_flags |= XFS_TRANS_DIRTY;
+	budp = xfs_trans_get_bud(tp, BUI_ITEM(intent));
+	set_bit(XFS_LI_DIRTY, &budp->bud_item.li_flags);
+
+	buip = xfs_bui_init(tp->t_mountp);
+	memcpy(buip->bui_format.bui_extents, extp, count * sizeof(*extp));
+	atomic_set(&buip->bui_next_extent, count);
+	xfs_trans_add_item(tp, &buip->bui_item);
+	set_bit(XFS_LI_DIRTY, &buip->bui_item.li_flags);
+	return &buip->bui_item;
+}
+
 static const struct xfs_item_ops xfs_bui_item_ops = {
 	.iop_size	= xfs_bui_item_size,
 	.iop_format	= xfs_bui_item_format,
@@ -539,6 +565,7 @@ static const struct xfs_item_ops xfs_bui_item_ops = {
 	.iop_release	= xfs_bui_item_release,
 	.iop_recover	= xfs_bui_item_recover,
 	.iop_match	= xfs_bui_item_match,
+	.iop_relog	= xfs_bui_item_relog,
 };
 
 /*
diff --git a/fs/xfs/xfs_extfree_item.c b/fs/xfs/xfs_extfree_item.c
index 337fae015bca..30a53f3913d1 100644
--- a/fs/xfs/xfs_extfree_item.c
+++ b/fs/xfs/xfs_extfree_item.c
@@ -642,6 +642,34 @@ xfs_efi_item_match(
 	return EFI_ITEM(lip)->efi_format.efi_id == intent_id;
 }
 
+/* Relog an intent item to push the log tail forward. */
+static struct xfs_log_item *
+xfs_efi_item_relog(
+	struct xfs_log_item		*intent,
+	struct xfs_trans		*tp)
+{
+	struct xfs_efd_log_item		*efdp;
+	struct xfs_efi_log_item		*efip;
+	struct xfs_extent		*extp;
+	unsigned int			count;
+
+	count = EFI_ITEM(intent)->efi_format.efi_nextents;
+	extp = EFI_ITEM(intent)->efi_format.efi_extents;
+
+	tp->t_flags |= XFS_TRANS_DIRTY;
+	efdp = xfs_trans_get_efd(tp, EFI_ITEM(intent), count);
+	efdp->efd_next_extent = count;
+	memcpy(efdp->efd_format.efd_extents, extp, count * sizeof(*extp));
+	set_bit(XFS_LI_DIRTY, &efdp->efd_item.li_flags);
+
+	efip = xfs_efi_init(tp->t_mountp, count);
+	memcpy(efip->efi_format.efi_extents, extp, count * sizeof(*extp));
+	atomic_set(&efip->efi_next_extent, count);
+	xfs_trans_add_item(tp, &efip->efi_item);
+	set_bit(XFS_LI_DIRTY, &efip->efi_item.li_flags);
+	return &efip->efi_item;
+}
+
 static const struct xfs_item_ops xfs_efi_item_ops = {
 	.iop_size	= xfs_efi_item_size,
 	.iop_format	= xfs_efi_item_format,
@@ -649,6 +677,7 @@ static const struct xfs_item_ops xfs_efi_item_ops = {
 	.iop_release	= xfs_efi_item_release,
 	.iop_recover	= xfs_efi_item_recover,
 	.iop_match	= xfs_efi_item_match,
+	.iop_relog	= xfs_efi_item_relog,
 };
 
 /*
diff --git a/fs/xfs/xfs_refcount_item.c b/fs/xfs/xfs_refcount_item.c
index c78412755b8a..cf0205fdc607 100644
--- a/fs/xfs/xfs_refcount_item.c
+++ b/fs/xfs/xfs_refcount_item.c
@@ -560,6 +560,32 @@ xfs_cui_item_match(
 	return CUI_ITEM(lip)->cui_format.cui_id == intent_id;
 }
 
+/* Relog an intent item to push the log tail forward. */
+static struct xfs_log_item *
+xfs_cui_item_relog(
+	struct xfs_log_item		*intent,
+	struct xfs_trans		*tp)
+{
+	struct xfs_cud_log_item		*cudp;
+	struct xfs_cui_log_item		*cuip;
+	struct xfs_phys_extent		*extp;
+	unsigned int			count;
+
+	count = CUI_ITEM(intent)->cui_format.cui_nextents;
+	extp = CUI_ITEM(intent)->cui_format.cui_extents;
+
+	tp->t_flags |= XFS_TRANS_DIRTY;
+	cudp = xfs_trans_get_cud(tp, CUI_ITEM(intent));
+	set_bit(XFS_LI_DIRTY, &cudp->cud_item.li_flags);
+
+	cuip = xfs_cui_init(tp->t_mountp, count);
+	memcpy(cuip->cui_format.cui_extents, extp, count * sizeof(*extp));
+	atomic_set(&cuip->cui_next_extent, count);
+	xfs_trans_add_item(tp, &cuip->cui_item);
+	set_bit(XFS_LI_DIRTY, &cuip->cui_item.li_flags);
+	return &cuip->cui_item;
+}
+
 static const struct xfs_item_ops xfs_cui_item_ops = {
 	.iop_size	= xfs_cui_item_size,
 	.iop_format	= xfs_cui_item_format,
@@ -567,6 +593,7 @@ static const struct xfs_item_ops xfs_cui_item_ops = {
 	.iop_release	= xfs_cui_item_release,
 	.iop_recover	= xfs_cui_item_recover,
 	.iop_match	= xfs_cui_item_match,
+	.iop_relog	= xfs_cui_item_relog,
 };
 
 /*
diff --git a/fs/xfs/xfs_rmap_item.c b/fs/xfs/xfs_rmap_item.c
index c1a1fd62ca74..3237243d375d 100644
--- a/fs/xfs/xfs_rmap_item.c
+++ b/fs/xfs/xfs_rmap_item.c
@@ -583,6 +583,32 @@ xfs_rui_item_match(
 	return RUI_ITEM(lip)->rui_format.rui_id == intent_id;
 }
 
+/* Relog an intent item to push the log tail forward. */
+static struct xfs_log_item *
+xfs_rui_item_relog(
+	struct xfs_log_item		*intent,
+	struct xfs_trans		*tp)
+{
+	struct xfs_rud_log_item		*rudp;
+	struct xfs_rui_log_item		*ruip;
+	struct xfs_map_extent		*extp;
+	unsigned int			count;
+
+	count = RUI_ITEM(intent)->rui_format.rui_nextents;
+	extp = RUI_ITEM(intent)->rui_format.rui_extents;
+
+	tp->t_flags |= XFS_TRANS_DIRTY;
+	rudp = xfs_trans_get_rud(tp, RUI_ITEM(intent));
+	set_bit(XFS_LI_DIRTY, &rudp->rud_item.li_flags);
+
+	ruip = xfs_rui_init(tp->t_mountp, count);
+	memcpy(ruip->rui_format.rui_extents, extp, count * sizeof(*extp));
+	atomic_set(&ruip->rui_next_extent, count);
+	xfs_trans_add_item(tp, &ruip->rui_item);
+	set_bit(XFS_LI_DIRTY, &ruip->rui_item.li_flags);
+	return &ruip->rui_item;
+}
+
 static const struct xfs_item_ops xfs_rui_item_ops = {
 	.iop_size	= xfs_rui_item_size,
 	.iop_format	= xfs_rui_item_format,
@@ -590,6 +616,7 @@ static const struct xfs_item_ops xfs_rui_item_ops = {
 	.iop_release	= xfs_rui_item_release,
 	.iop_recover	= xfs_rui_item_recover,
 	.iop_match	= xfs_rui_item_match,
+	.iop_relog	= xfs_rui_item_relog,
 };
 
 /*
diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
index a3a35a2d8ed9..362c155be525 100644
--- a/fs/xfs/xfs_trace.h
+++ b/fs/xfs/xfs_trace.h
@@ -2533,6 +2533,7 @@ DEFINE_DEFER_PENDING_EVENT(xfs_defer_create_intent);
 DEFINE_DEFER_PENDING_EVENT(xfs_defer_cancel_list);
 DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_finish);
 DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_abort);
+DEFINE_DEFER_PENDING_EVENT(xfs_defer_relog_intent);
 
 #define DEFINE_BMAP_FREE_DEFERRED_EVENT DEFINE_PHYS_EXTENT_DEFERRED_EVENT
 DEFINE_BMAP_FREE_DEFERRED_EVENT(xfs_bmap_free_defer);
diff --git a/fs/xfs/xfs_trans.h b/fs/xfs/xfs_trans.h
index 995c1513693c..e838e8327510 100644
--- a/fs/xfs/xfs_trans.h
+++ b/fs/xfs/xfs_trans.h
@@ -78,6 +78,8 @@ struct xfs_item_ops {
 	int (*iop_recover)(struct xfs_log_item *lip,
 			   struct xfs_defer_capture **dfcp);
 	bool (*iop_match)(struct xfs_log_item *item, uint64_t id);
+	struct xfs_log_item *(*iop_relog)(struct xfs_log_item *intent,
+			struct xfs_trans *tp);
 };
 
 /*
@@ -239,4 +241,12 @@ void		xfs_trans_buf_copy_type(struct xfs_buf *dst_bp,
 
 extern kmem_zone_t	*xfs_trans_zone;
 
+static inline struct xfs_log_item *
+xfs_trans_item_relog(
+	struct xfs_log_item	*lip,
+	struct xfs_trans	*tp)
+{
+	return lip->li_ops->iop_relog(lip, tp);
+}
+
 #endif	/* __XFS_TRANS_H__ */

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Brian Foster]

On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <darrick.wong@oracle.com>
> 
> There's a subtle design flaw in the deferred log item code that can lead
> to pinning the log tail.  Taking up the defer ops chain examples from
> the previous commit, we can get trapped in sequences like this:
> 
> Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
> chain will look like the following if the transaction rolls succeed:
> 
> t1: D0(t0), D1(t0), D2(t0), D3(t0)
> t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
> t3: d5(t1), D1(t0), D2(t0), D3(t0)
> ...
> t9: d9(t7), D3(t0)
> t10: D3(t0)
> t11: d10(t10), d11(t10)
> t12: d11(t10)
> 
> In transaction 9, we finish d9 and try to roll to t10 while holding onto
> an intent item for D3 that we logged in t0.
> 
> The previous commit changed the order in which we place new defer ops in
> the defer ops processing chain to reduce the maximum chain length.  Now
> make xfs_defer_finish_noroll capable of relogging the entire chain
> periodically so that we can always move the log tail forward.  Most
> chains will never get relogged, except for operations that generate very
> long chains (large extents containing many blocks with different sharing
> levels) or are on filesystems with small logs and a lot of ongoing
> metadata updates.
> 
> Callers are now required to ensure that the transaction reservation is
> large enough to handle logging done items and new intent items for the
> maximum possible chain length.  Most callers are careful to keep the
> chain lengths low, so the overhead should be minimal.
> 
> The decision to relog an intent item is made based on whether or not the
> intent was added to the current checkpoint.  If so, the checkpoint is
> still open and there's no point in relogging.  Otherwise, the old
> checkpoint is closed and we relog the intent to add it to the current
> one.
> 

Looks like this last bit needs to be updated.

> Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> ---
>  fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
>  fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
>  fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_trace.h         |    1 +
>  fs/xfs/xfs_trans.h         |   10 ++++++++
>  7 files changed, 173 insertions(+)
> 
> 
> diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
> index 84a70edd0da1..c601cc2af254 100644
> --- a/fs/xfs/libxfs/xfs_defer.c
> +++ b/fs/xfs/libxfs/xfs_defer.c
...
> @@ -447,6 +494,11 @@ xfs_defer_finish_noroll(
>  		if (error)
>  			goto out_shutdown;
>  
> +		/* Every few rolls we relog all the intent items. */

Stale comment?

Those nits aside:

Reviewed-by: Brian Foster <bfoster@redhat.com>

> +		error = xfs_defer_relog(tp, &dop_pending);
> +		if (error)
> +			goto out_shutdown;
> +
>  		dfp = list_first_entry(&dop_pending, struct xfs_defer_pending,
>  				       dfp_list);
>  		error = xfs_defer_finish_one(*tp, dfp);
> diff --git a/fs/xfs/xfs_bmap_item.c b/fs/xfs/xfs_bmap_item.c
> index 008436ef5bce..6317fdf4a3a0 100644
> --- a/fs/xfs/xfs_bmap_item.c
> +++ b/fs/xfs/xfs_bmap_item.c
> @@ -532,6 +532,32 @@ xfs_bui_item_match(
>  	return BUI_ITEM(lip)->bui_format.bui_id == intent_id;
>  }
>  
> +/* Relog an intent item to push the log tail forward. */
> +static struct xfs_log_item *
> +xfs_bui_item_relog(
> +	struct xfs_log_item		*intent,
> +	struct xfs_trans		*tp)
> +{
> +	struct xfs_bud_log_item		*budp;
> +	struct xfs_bui_log_item		*buip;
> +	struct xfs_map_extent		*extp;
> +	unsigned int			count;
> +
> +	count = BUI_ITEM(intent)->bui_format.bui_nextents;
> +	extp = BUI_ITEM(intent)->bui_format.bui_extents;
> +
> +	tp->t_flags |= XFS_TRANS_DIRTY;
> +	budp = xfs_trans_get_bud(tp, BUI_ITEM(intent));
> +	set_bit(XFS_LI_DIRTY, &budp->bud_item.li_flags);
> +
> +	buip = xfs_bui_init(tp->t_mountp);
> +	memcpy(buip->bui_format.bui_extents, extp, count * sizeof(*extp));
> +	atomic_set(&buip->bui_next_extent, count);
> +	xfs_trans_add_item(tp, &buip->bui_item);
> +	set_bit(XFS_LI_DIRTY, &buip->bui_item.li_flags);
> +	return &buip->bui_item;
> +}
> +
>  static const struct xfs_item_ops xfs_bui_item_ops = {
>  	.iop_size	= xfs_bui_item_size,
>  	.iop_format	= xfs_bui_item_format,
> @@ -539,6 +565,7 @@ static const struct xfs_item_ops xfs_bui_item_ops = {
>  	.iop_release	= xfs_bui_item_release,
>  	.iop_recover	= xfs_bui_item_recover,
>  	.iop_match	= xfs_bui_item_match,
> +	.iop_relog	= xfs_bui_item_relog,
>  };
>  
>  /*
> diff --git a/fs/xfs/xfs_extfree_item.c b/fs/xfs/xfs_extfree_item.c
> index 337fae015bca..30a53f3913d1 100644
> --- a/fs/xfs/xfs_extfree_item.c
> +++ b/fs/xfs/xfs_extfree_item.c
> @@ -642,6 +642,34 @@ xfs_efi_item_match(
>  	return EFI_ITEM(lip)->efi_format.efi_id == intent_id;
>  }
>  
> +/* Relog an intent item to push the log tail forward. */
> +static struct xfs_log_item *
> +xfs_efi_item_relog(
> +	struct xfs_log_item		*intent,
> +	struct xfs_trans		*tp)
> +{
> +	struct xfs_efd_log_item		*efdp;
> +	struct xfs_efi_log_item		*efip;
> +	struct xfs_extent		*extp;
> +	unsigned int			count;
> +
> +	count = EFI_ITEM(intent)->efi_format.efi_nextents;
> +	extp = EFI_ITEM(intent)->efi_format.efi_extents;
> +
> +	tp->t_flags |= XFS_TRANS_DIRTY;
> +	efdp = xfs_trans_get_efd(tp, EFI_ITEM(intent), count);
> +	efdp->efd_next_extent = count;
> +	memcpy(efdp->efd_format.efd_extents, extp, count * sizeof(*extp));
> +	set_bit(XFS_LI_DIRTY, &efdp->efd_item.li_flags);
> +
> +	efip = xfs_efi_init(tp->t_mountp, count);
> +	memcpy(efip->efi_format.efi_extents, extp, count * sizeof(*extp));
> +	atomic_set(&efip->efi_next_extent, count);
> +	xfs_trans_add_item(tp, &efip->efi_item);
> +	set_bit(XFS_LI_DIRTY, &efip->efi_item.li_flags);
> +	return &efip->efi_item;
> +}
> +
>  static const struct xfs_item_ops xfs_efi_item_ops = {
>  	.iop_size	= xfs_efi_item_size,
>  	.iop_format	= xfs_efi_item_format,
> @@ -649,6 +677,7 @@ static const struct xfs_item_ops xfs_efi_item_ops = {
>  	.iop_release	= xfs_efi_item_release,
>  	.iop_recover	= xfs_efi_item_recover,
>  	.iop_match	= xfs_efi_item_match,
> +	.iop_relog	= xfs_efi_item_relog,
>  };
>  
>  /*
> diff --git a/fs/xfs/xfs_refcount_item.c b/fs/xfs/xfs_refcount_item.c
> index c78412755b8a..cf0205fdc607 100644
> --- a/fs/xfs/xfs_refcount_item.c
> +++ b/fs/xfs/xfs_refcount_item.c
> @@ -560,6 +560,32 @@ xfs_cui_item_match(
>  	return CUI_ITEM(lip)->cui_format.cui_id == intent_id;
>  }
>  
> +/* Relog an intent item to push the log tail forward. */
> +static struct xfs_log_item *
> +xfs_cui_item_relog(
> +	struct xfs_log_item		*intent,
> +	struct xfs_trans		*tp)
> +{
> +	struct xfs_cud_log_item		*cudp;
> +	struct xfs_cui_log_item		*cuip;
> +	struct xfs_phys_extent		*extp;
> +	unsigned int			count;
> +
> +	count = CUI_ITEM(intent)->cui_format.cui_nextents;
> +	extp = CUI_ITEM(intent)->cui_format.cui_extents;
> +
> +	tp->t_flags |= XFS_TRANS_DIRTY;
> +	cudp = xfs_trans_get_cud(tp, CUI_ITEM(intent));
> +	set_bit(XFS_LI_DIRTY, &cudp->cud_item.li_flags);
> +
> +	cuip = xfs_cui_init(tp->t_mountp, count);
> +	memcpy(cuip->cui_format.cui_extents, extp, count * sizeof(*extp));
> +	atomic_set(&cuip->cui_next_extent, count);
> +	xfs_trans_add_item(tp, &cuip->cui_item);
> +	set_bit(XFS_LI_DIRTY, &cuip->cui_item.li_flags);
> +	return &cuip->cui_item;
> +}
> +
>  static const struct xfs_item_ops xfs_cui_item_ops = {
>  	.iop_size	= xfs_cui_item_size,
>  	.iop_format	= xfs_cui_item_format,
> @@ -567,6 +593,7 @@ static const struct xfs_item_ops xfs_cui_item_ops = {
>  	.iop_release	= xfs_cui_item_release,
>  	.iop_recover	= xfs_cui_item_recover,
>  	.iop_match	= xfs_cui_item_match,
> +	.iop_relog	= xfs_cui_item_relog,
>  };
>  
>  /*
> diff --git a/fs/xfs/xfs_rmap_item.c b/fs/xfs/xfs_rmap_item.c
> index c1a1fd62ca74..3237243d375d 100644
> --- a/fs/xfs/xfs_rmap_item.c
> +++ b/fs/xfs/xfs_rmap_item.c
> @@ -583,6 +583,32 @@ xfs_rui_item_match(
>  	return RUI_ITEM(lip)->rui_format.rui_id == intent_id;
>  }
>  
> +/* Relog an intent item to push the log tail forward. */
> +static struct xfs_log_item *
> +xfs_rui_item_relog(
> +	struct xfs_log_item		*intent,
> +	struct xfs_trans		*tp)
> +{
> +	struct xfs_rud_log_item		*rudp;
> +	struct xfs_rui_log_item		*ruip;
> +	struct xfs_map_extent		*extp;
> +	unsigned int			count;
> +
> +	count = RUI_ITEM(intent)->rui_format.rui_nextents;
> +	extp = RUI_ITEM(intent)->rui_format.rui_extents;
> +
> +	tp->t_flags |= XFS_TRANS_DIRTY;
> +	rudp = xfs_trans_get_rud(tp, RUI_ITEM(intent));
> +	set_bit(XFS_LI_DIRTY, &rudp->rud_item.li_flags);
> +
> +	ruip = xfs_rui_init(tp->t_mountp, count);
> +	memcpy(ruip->rui_format.rui_extents, extp, count * sizeof(*extp));
> +	atomic_set(&ruip->rui_next_extent, count);
> +	xfs_trans_add_item(tp, &ruip->rui_item);
> +	set_bit(XFS_LI_DIRTY, &ruip->rui_item.li_flags);
> +	return &ruip->rui_item;
> +}
> +
>  static const struct xfs_item_ops xfs_rui_item_ops = {
>  	.iop_size	= xfs_rui_item_size,
>  	.iop_format	= xfs_rui_item_format,
> @@ -590,6 +616,7 @@ static const struct xfs_item_ops xfs_rui_item_ops = {
>  	.iop_release	= xfs_rui_item_release,
>  	.iop_recover	= xfs_rui_item_recover,
>  	.iop_match	= xfs_rui_item_match,
> +	.iop_relog	= xfs_rui_item_relog,
>  };
>  
>  /*
> diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
> index a3a35a2d8ed9..362c155be525 100644
> --- a/fs/xfs/xfs_trace.h
> +++ b/fs/xfs/xfs_trace.h
> @@ -2533,6 +2533,7 @@ DEFINE_DEFER_PENDING_EVENT(xfs_defer_create_intent);
>  DEFINE_DEFER_PENDING_EVENT(xfs_defer_cancel_list);
>  DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_finish);
>  DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_abort);
> +DEFINE_DEFER_PENDING_EVENT(xfs_defer_relog_intent);
>  
>  #define DEFINE_BMAP_FREE_DEFERRED_EVENT DEFINE_PHYS_EXTENT_DEFERRED_EVENT
>  DEFINE_BMAP_FREE_DEFERRED_EVENT(xfs_bmap_free_defer);
> diff --git a/fs/xfs/xfs_trans.h b/fs/xfs/xfs_trans.h
> index 995c1513693c..e838e8327510 100644
> --- a/fs/xfs/xfs_trans.h
> +++ b/fs/xfs/xfs_trans.h
> @@ -78,6 +78,8 @@ struct xfs_item_ops {
>  	int (*iop_recover)(struct xfs_log_item *lip,
>  			   struct xfs_defer_capture **dfcp);
>  	bool (*iop_match)(struct xfs_log_item *item, uint64_t id);
> +	struct xfs_log_item *(*iop_relog)(struct xfs_log_item *intent,
> +			struct xfs_trans *tp);
>  };
>  
>  /*
> @@ -239,4 +241,12 @@ void		xfs_trans_buf_copy_type(struct xfs_buf *dst_bp,
>  
>  extern kmem_zone_t	*xfs_trans_zone;
>  
> +static inline struct xfs_log_item *
> +xfs_trans_item_relog(
> +	struct xfs_log_item	*lip,
> +	struct xfs_trans	*tp)
> +{
> +	return lip->li_ops->iop_relog(lip, tp);
> +}
> +
>  #endif	/* __XFS_TRANS_H__ */
> 

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Darrick J. Wong]

On Fri, Sep 25, 2020 at 07:15:40AM -0400, Brian Foster wrote:
> On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > From: Darrick J. Wong <darrick.wong@oracle.com>
> > 
> > There's a subtle design flaw in the deferred log item code that can lead
> > to pinning the log tail.  Taking up the defer ops chain examples from
> > the previous commit, we can get trapped in sequences like this:
> > 
> > Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
> > chain will look like the following if the transaction rolls succeed:
> > 
> > t1: D0(t0), D1(t0), D2(t0), D3(t0)
> > t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
> > t3: d5(t1), D1(t0), D2(t0), D3(t0)
> > ...
> > t9: d9(t7), D3(t0)
> > t10: D3(t0)
> > t11: d10(t10), d11(t10)
> > t12: d11(t10)
> > 
> > In transaction 9, we finish d9 and try to roll to t10 while holding onto
> > an intent item for D3 that we logged in t0.
> > 
> > The previous commit changed the order in which we place new defer ops in
> > the defer ops processing chain to reduce the maximum chain length.  Now
> > make xfs_defer_finish_noroll capable of relogging the entire chain
> > periodically so that we can always move the log tail forward.  Most
> > chains will never get relogged, except for operations that generate very
> > long chains (large extents containing many blocks with different sharing
> > levels) or are on filesystems with small logs and a lot of ongoing
> > metadata updates.
> > 
> > Callers are now required to ensure that the transaction reservation is
> > large enough to handle logging done items and new intent items for the
> > maximum possible chain length.  Most callers are careful to keep the
> > chain lengths low, so the overhead should be minimal.
> > 
> > The decision to relog an intent item is made based on whether or not the
> > intent was added to the current checkpoint.  If so, the checkpoint is
> > still open and there's no point in relogging.  Otherwise, the old
> > checkpoint is closed and we relog the intent to add it to the current
> > one.
> > 
> 
> Looks like this last bit needs to be updated.

Yep.  The next version will replace that paragraph with the following:

"The decision to relog an intent item is made based on two factors: (a)
whether the intent was logged in a previous checkpoint, and (b) if the
log has hit the 75% full threshold.  There's no point in relogging an
intent into the same checkpoint, and there's no need to relog if there's
plenty of free space in the log."

> > Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> > ---
> >  fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
> >  fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
> >  fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_trace.h         |    1 +
> >  fs/xfs/xfs_trans.h         |   10 ++++++++
> >  7 files changed, 173 insertions(+)
> > 
> > 
> > diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
> > index 84a70edd0da1..c601cc2af254 100644
> > --- a/fs/xfs/libxfs/xfs_defer.c
> > +++ b/fs/xfs/libxfs/xfs_defer.c
> ...
> > @@ -447,6 +494,11 @@ xfs_defer_finish_noroll(
> >  		if (error)
> >  			goto out_shutdown;
> >  
> > +		/* Every few rolls we relog all the intent items. */
> 
> Stale comment?

Yes.  Change that to:

/* Possibly relog intent items to keep the log tail moving. */

> Those nits aside:
> 
> Reviewed-by: Brian Foster <bfoster@redhat.com>

Thanks for the review!

--D

> > +		error = xfs_defer_relog(tp, &dop_pending);
> > +		if (error)
> > +			goto out_shutdown;
> > +
> >  		dfp = list_first_entry(&dop_pending, struct xfs_defer_pending,
> >  				       dfp_list);
> >  		error = xfs_defer_finish_one(*tp, dfp);
> > diff --git a/fs/xfs/xfs_bmap_item.c b/fs/xfs/xfs_bmap_item.c
> > index 008436ef5bce..6317fdf4a3a0 100644
> > --- a/fs/xfs/xfs_bmap_item.c
> > +++ b/fs/xfs/xfs_bmap_item.c
> > @@ -532,6 +532,32 @@ xfs_bui_item_match(
> >  	return BUI_ITEM(lip)->bui_format.bui_id == intent_id;
> >  }
> >  
> > +/* Relog an intent item to push the log tail forward. */
> > +static struct xfs_log_item *
> > +xfs_bui_item_relog(
> > +	struct xfs_log_item		*intent,
> > +	struct xfs_trans		*tp)
> > +{
> > +	struct xfs_bud_log_item		*budp;
> > +	struct xfs_bui_log_item		*buip;
> > +	struct xfs_map_extent		*extp;
> > +	unsigned int			count;
> > +
> > +	count = BUI_ITEM(intent)->bui_format.bui_nextents;
> > +	extp = BUI_ITEM(intent)->bui_format.bui_extents;
> > +
> > +	tp->t_flags |= XFS_TRANS_DIRTY;
> > +	budp = xfs_trans_get_bud(tp, BUI_ITEM(intent));
> > +	set_bit(XFS_LI_DIRTY, &budp->bud_item.li_flags);
> > +
> > +	buip = xfs_bui_init(tp->t_mountp);
> > +	memcpy(buip->bui_format.bui_extents, extp, count * sizeof(*extp));
> > +	atomic_set(&buip->bui_next_extent, count);
> > +	xfs_trans_add_item(tp, &buip->bui_item);
> > +	set_bit(XFS_LI_DIRTY, &buip->bui_item.li_flags);
> > +	return &buip->bui_item;
> > +}
> > +
> >  static const struct xfs_item_ops xfs_bui_item_ops = {
> >  	.iop_size	= xfs_bui_item_size,
> >  	.iop_format	= xfs_bui_item_format,
> > @@ -539,6 +565,7 @@ static const struct xfs_item_ops xfs_bui_item_ops = {
> >  	.iop_release	= xfs_bui_item_release,
> >  	.iop_recover	= xfs_bui_item_recover,
> >  	.iop_match	= xfs_bui_item_match,
> > +	.iop_relog	= xfs_bui_item_relog,
> >  };
> >  
> >  /*
> > diff --git a/fs/xfs/xfs_extfree_item.c b/fs/xfs/xfs_extfree_item.c
> > index 337fae015bca..30a53f3913d1 100644
> > --- a/fs/xfs/xfs_extfree_item.c
> > +++ b/fs/xfs/xfs_extfree_item.c
> > @@ -642,6 +642,34 @@ xfs_efi_item_match(
> >  	return EFI_ITEM(lip)->efi_format.efi_id == intent_id;
> >  }
> >  
> > +/* Relog an intent item to push the log tail forward. */
> > +static struct xfs_log_item *
> > +xfs_efi_item_relog(
> > +	struct xfs_log_item		*intent,
> > +	struct xfs_trans		*tp)
> > +{
> > +	struct xfs_efd_log_item		*efdp;
> > +	struct xfs_efi_log_item		*efip;
> > +	struct xfs_extent		*extp;
> > +	unsigned int			count;
> > +
> > +	count = EFI_ITEM(intent)->efi_format.efi_nextents;
> > +	extp = EFI_ITEM(intent)->efi_format.efi_extents;
> > +
> > +	tp->t_flags |= XFS_TRANS_DIRTY;
> > +	efdp = xfs_trans_get_efd(tp, EFI_ITEM(intent), count);
> > +	efdp->efd_next_extent = count;
> > +	memcpy(efdp->efd_format.efd_extents, extp, count * sizeof(*extp));
> > +	set_bit(XFS_LI_DIRTY, &efdp->efd_item.li_flags);
> > +
> > +	efip = xfs_efi_init(tp->t_mountp, count);
> > +	memcpy(efip->efi_format.efi_extents, extp, count * sizeof(*extp));
> > +	atomic_set(&efip->efi_next_extent, count);
> > +	xfs_trans_add_item(tp, &efip->efi_item);
> > +	set_bit(XFS_LI_DIRTY, &efip->efi_item.li_flags);
> > +	return &efip->efi_item;
> > +}
> > +
> >  static const struct xfs_item_ops xfs_efi_item_ops = {
> >  	.iop_size	= xfs_efi_item_size,
> >  	.iop_format	= xfs_efi_item_format,
> > @@ -649,6 +677,7 @@ static const struct xfs_item_ops xfs_efi_item_ops = {
> >  	.iop_release	= xfs_efi_item_release,
> >  	.iop_recover	= xfs_efi_item_recover,
> >  	.iop_match	= xfs_efi_item_match,
> > +	.iop_relog	= xfs_efi_item_relog,
> >  };
> >  
> >  /*
> > diff --git a/fs/xfs/xfs_refcount_item.c b/fs/xfs/xfs_refcount_item.c
> > index c78412755b8a..cf0205fdc607 100644
> > --- a/fs/xfs/xfs_refcount_item.c
> > +++ b/fs/xfs/xfs_refcount_item.c
> > @@ -560,6 +560,32 @@ xfs_cui_item_match(
> >  	return CUI_ITEM(lip)->cui_format.cui_id == intent_id;
> >  }
> >  
> > +/* Relog an intent item to push the log tail forward. */
> > +static struct xfs_log_item *
> > +xfs_cui_item_relog(
> > +	struct xfs_log_item		*intent,
> > +	struct xfs_trans		*tp)
> > +{
> > +	struct xfs_cud_log_item		*cudp;
> > +	struct xfs_cui_log_item		*cuip;
> > +	struct xfs_phys_extent		*extp;
> > +	unsigned int			count;
> > +
> > +	count = CUI_ITEM(intent)->cui_format.cui_nextents;
> > +	extp = CUI_ITEM(intent)->cui_format.cui_extents;
> > +
> > +	tp->t_flags |= XFS_TRANS_DIRTY;
> > +	cudp = xfs_trans_get_cud(tp, CUI_ITEM(intent));
> > +	set_bit(XFS_LI_DIRTY, &cudp->cud_item.li_flags);
> > +
> > +	cuip = xfs_cui_init(tp->t_mountp, count);
> > +	memcpy(cuip->cui_format.cui_extents, extp, count * sizeof(*extp));
> > +	atomic_set(&cuip->cui_next_extent, count);
> > +	xfs_trans_add_item(tp, &cuip->cui_item);
> > +	set_bit(XFS_LI_DIRTY, &cuip->cui_item.li_flags);
> > +	return &cuip->cui_item;
> > +}
> > +
> >  static const struct xfs_item_ops xfs_cui_item_ops = {
> >  	.iop_size	= xfs_cui_item_size,
> >  	.iop_format	= xfs_cui_item_format,
> > @@ -567,6 +593,7 @@ static const struct xfs_item_ops xfs_cui_item_ops = {
> >  	.iop_release	= xfs_cui_item_release,
> >  	.iop_recover	= xfs_cui_item_recover,
> >  	.iop_match	= xfs_cui_item_match,
> > +	.iop_relog	= xfs_cui_item_relog,
> >  };
> >  
> >  /*
> > diff --git a/fs/xfs/xfs_rmap_item.c b/fs/xfs/xfs_rmap_item.c
> > index c1a1fd62ca74..3237243d375d 100644
> > --- a/fs/xfs/xfs_rmap_item.c
> > +++ b/fs/xfs/xfs_rmap_item.c
> > @@ -583,6 +583,32 @@ xfs_rui_item_match(
> >  	return RUI_ITEM(lip)->rui_format.rui_id == intent_id;
> >  }
> >  
> > +/* Relog an intent item to push the log tail forward. */
> > +static struct xfs_log_item *
> > +xfs_rui_item_relog(
> > +	struct xfs_log_item		*intent,
> > +	struct xfs_trans		*tp)
> > +{
> > +	struct xfs_rud_log_item		*rudp;
> > +	struct xfs_rui_log_item		*ruip;
> > +	struct xfs_map_extent		*extp;
> > +	unsigned int			count;
> > +
> > +	count = RUI_ITEM(intent)->rui_format.rui_nextents;
> > +	extp = RUI_ITEM(intent)->rui_format.rui_extents;
> > +
> > +	tp->t_flags |= XFS_TRANS_DIRTY;
> > +	rudp = xfs_trans_get_rud(tp, RUI_ITEM(intent));
> > +	set_bit(XFS_LI_DIRTY, &rudp->rud_item.li_flags);
> > +
> > +	ruip = xfs_rui_init(tp->t_mountp, count);
> > +	memcpy(ruip->rui_format.rui_extents, extp, count * sizeof(*extp));
> > +	atomic_set(&ruip->rui_next_extent, count);
> > +	xfs_trans_add_item(tp, &ruip->rui_item);
> > +	set_bit(XFS_LI_DIRTY, &ruip->rui_item.li_flags);
> > +	return &ruip->rui_item;
> > +}
> > +
> >  static const struct xfs_item_ops xfs_rui_item_ops = {
> >  	.iop_size	= xfs_rui_item_size,
> >  	.iop_format	= xfs_rui_item_format,
> > @@ -590,6 +616,7 @@ static const struct xfs_item_ops xfs_rui_item_ops = {
> >  	.iop_release	= xfs_rui_item_release,
> >  	.iop_recover	= xfs_rui_item_recover,
> >  	.iop_match	= xfs_rui_item_match,
> > +	.iop_relog	= xfs_rui_item_relog,
> >  };
> >  
> >  /*
> > diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
> > index a3a35a2d8ed9..362c155be525 100644
> > --- a/fs/xfs/xfs_trace.h
> > +++ b/fs/xfs/xfs_trace.h
> > @@ -2533,6 +2533,7 @@ DEFINE_DEFER_PENDING_EVENT(xfs_defer_create_intent);
> >  DEFINE_DEFER_PENDING_EVENT(xfs_defer_cancel_list);
> >  DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_finish);
> >  DEFINE_DEFER_PENDING_EVENT(xfs_defer_pending_abort);
> > +DEFINE_DEFER_PENDING_EVENT(xfs_defer_relog_intent);
> >  
> >  #define DEFINE_BMAP_FREE_DEFERRED_EVENT DEFINE_PHYS_EXTENT_DEFERRED_EVENT
> >  DEFINE_BMAP_FREE_DEFERRED_EVENT(xfs_bmap_free_defer);
> > diff --git a/fs/xfs/xfs_trans.h b/fs/xfs/xfs_trans.h
> > index 995c1513693c..e838e8327510 100644
> > --- a/fs/xfs/xfs_trans.h
> > +++ b/fs/xfs/xfs_trans.h
> > @@ -78,6 +78,8 @@ struct xfs_item_ops {
> >  	int (*iop_recover)(struct xfs_log_item *lip,
> >  			   struct xfs_defer_capture **dfcp);
> >  	bool (*iop_match)(struct xfs_log_item *item, uint64_t id);
> > +	struct xfs_log_item *(*iop_relog)(struct xfs_log_item *intent,
> > +			struct xfs_trans *tp);
> >  };
> >  
> >  /*
> > @@ -239,4 +241,12 @@ void		xfs_trans_buf_copy_type(struct xfs_buf *dst_bp,
> >  
> >  extern kmem_zone_t	*xfs_trans_zone;
> >  
> > +static inline struct xfs_log_item *
> > +xfs_trans_item_relog(
> > +	struct xfs_log_item	*lip,
> > +	struct xfs_trans	*tp)
> > +{
> > +	return lip->li_ops->iop_relog(lip, tp);
> > +}
> > +
> >  #endif	/* __XFS_TRANS_H__ */
> > 
> 

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Dave Chinner]

On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <darrick.wong@oracle.com>
> 
> There's a subtle design flaw in the deferred log item code that can lead
> to pinning the log tail.  Taking up the defer ops chain examples from
> the previous commit, we can get trapped in sequences like this:
> 
> Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
> chain will look like the following if the transaction rolls succeed:
> 
> t1: D0(t0), D1(t0), D2(t0), D3(t0)
> t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
> t3: d5(t1), D1(t0), D2(t0), D3(t0)
> ...
> t9: d9(t7), D3(t0)
> t10: D3(t0)
> t11: d10(t10), d11(t10)
> t12: d11(t10)
> 
> In transaction 9, we finish d9 and try to roll to t10 while holding onto
> an intent item for D3 that we logged in t0.
> 
> The previous commit changed the order in which we place new defer ops in
> the defer ops processing chain to reduce the maximum chain length.  Now
> make xfs_defer_finish_noroll capable of relogging the entire chain
> periodically so that we can always move the log tail forward.  Most
> chains will never get relogged, except for operations that generate very
> long chains (large extents containing many blocks with different sharing
> levels) or are on filesystems with small logs and a lot of ongoing
> metadata updates.
> 
> Callers are now required to ensure that the transaction reservation is
> large enough to handle logging done items and new intent items for the
> maximum possible chain length.  Most callers are careful to keep the
> chain lengths low, so the overhead should be minimal.
> 
> The decision to relog an intent item is made based on whether or not the
> intent was added to the current checkpoint.  If so, the checkpoint is
> still open and there's no point in relogging.  Otherwise, the old
> checkpoint is closed and we relog the intent to add it to the current
> one.
> 
> Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> ---
>  fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
>  fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
>  fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
>  fs/xfs/xfs_trace.h         |    1 +
>  fs/xfs/xfs_trans.h         |   10 ++++++++
>  7 files changed, 173 insertions(+)
> 
> 
> diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
> index 84a70edd0da1..c601cc2af254 100644
> --- a/fs/xfs/libxfs/xfs_defer.c
> +++ b/fs/xfs/libxfs/xfs_defer.c
> @@ -17,6 +17,7 @@
>  #include "xfs_inode_item.h"
>  #include "xfs_trace.h"
>  #include "xfs_icache.h"
> +#include "xfs_log.h"
>  
>  /*
>   * Deferred Operations in XFS
> @@ -361,6 +362,52 @@ xfs_defer_cancel_list(
>  	}
>  }
>  
> +/*
> + * Prevent a log intent item from pinning the tail of the log by logging a
> + * done item to release the intent item; and then log a new intent item.
> + * The caller should provide a fresh transaction and roll it after we're done.
> + */
> +static int
> +xfs_defer_relog(
> +	struct xfs_trans		**tpp,
> +	struct list_head		*dfops)
> +{
> +	struct xfs_defer_pending	*dfp;
> +	xfs_lsn_t			threshold_lsn;
> +
> +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> +
> +	/*
> +	 * Figure out where we need the tail to be in order to maintain the
> +	 * minimum required free space in the log.
> +	 */
> +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> +	if (threshold_lsn == NULLCOMMITLSN)
> +		return 0;

This smells of premature optimisation.

When we are in a tail-pushing scenario (i.e. any sort of
sustained metadata workload) this will always return true, and so we
will relog every intent that isn't in the current checkpoint every
time this is called.  Under light load, we don't care if we add a
little bit of relogging overhead as the CIL slowly flushes/pushes -
it will have neglible impact on performance because there is little
load on the journal.

However, when we are under heavy load the code will now be reading
the grant head and log position accounting variables during every
commit, hence greatly increasing the number and temporal
distribution of accesses to the hotest cachelines in the log. We
currently never access these cache lines during commit unless the
unit reservation has run out and we have to regrant physical log
space for the transaction to continue (i.e. we are into slow path
commit code). IOWs, this is like causing far more than double the
number of accesses to the grant head, the log tail, the
last_sync_lsn, etc, all of which is unnecessary exactly when we care
about minimising contention on the log space accounting variables...

Given that it is a redundant check under heavy load journal load
when access to the log grant/head/tail are already contended,
I think we should just be checking the "in current checkpoint" logic
and not making it conditional on the log being near full.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Darrick J. Wong]

On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > From: Darrick J. Wong <darrick.wong@oracle.com>
> > 
> > There's a subtle design flaw in the deferred log item code that can lead
> > to pinning the log tail.  Taking up the defer ops chain examples from
> > the previous commit, we can get trapped in sequences like this:
> > 
> > Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
> > chain will look like the following if the transaction rolls succeed:
> > 
> > t1: D0(t0), D1(t0), D2(t0), D3(t0)
> > t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
> > t3: d5(t1), D1(t0), D2(t0), D3(t0)
> > ...
> > t9: d9(t7), D3(t0)
> > t10: D3(t0)
> > t11: d10(t10), d11(t10)
> > t12: d11(t10)
> > 
> > In transaction 9, we finish d9 and try to roll to t10 while holding onto
> > an intent item for D3 that we logged in t0.
> > 
> > The previous commit changed the order in which we place new defer ops in
> > the defer ops processing chain to reduce the maximum chain length.  Now
> > make xfs_defer_finish_noroll capable of relogging the entire chain
> > periodically so that we can always move the log tail forward.  Most
> > chains will never get relogged, except for operations that generate very
> > long chains (large extents containing many blocks with different sharing
> > levels) or are on filesystems with small logs and a lot of ongoing
> > metadata updates.
> > 
> > Callers are now required to ensure that the transaction reservation is
> > large enough to handle logging done items and new intent items for the
> > maximum possible chain length.  Most callers are careful to keep the
> > chain lengths low, so the overhead should be minimal.
> > 
> > The decision to relog an intent item is made based on whether or not the
> > intent was added to the current checkpoint.  If so, the checkpoint is
> > still open and there's no point in relogging.  Otherwise, the old
> > checkpoint is closed and we relog the intent to add it to the current
> > one.
> > 
> > Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> > ---
> >  fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
> >  fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
> >  fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_trace.h         |    1 +
> >  fs/xfs/xfs_trans.h         |   10 ++++++++
> >  7 files changed, 173 insertions(+)
> > 
> > 
> > diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
> > index 84a70edd0da1..c601cc2af254 100644
> > --- a/fs/xfs/libxfs/xfs_defer.c
> > +++ b/fs/xfs/libxfs/xfs_defer.c
> > @@ -17,6 +17,7 @@
> >  #include "xfs_inode_item.h"
> >  #include "xfs_trace.h"
> >  #include "xfs_icache.h"
> > +#include "xfs_log.h"
> >  
> >  /*
> >   * Deferred Operations in XFS
> > @@ -361,6 +362,52 @@ xfs_defer_cancel_list(
> >  	}
> >  }
> >  
> > +/*
> > + * Prevent a log intent item from pinning the tail of the log by logging a
> > + * done item to release the intent item; and then log a new intent item.
> > + * The caller should provide a fresh transaction and roll it after we're done.
> > + */
> > +static int
> > +xfs_defer_relog(
> > +	struct xfs_trans		**tpp,
> > +	struct list_head		*dfops)
> > +{
> > +	struct xfs_defer_pending	*dfp;
> > +	xfs_lsn_t			threshold_lsn;
> > +
> > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > +
> > +	/*
> > +	 * Figure out where we need the tail to be in order to maintain the
> > +	 * minimum required free space in the log.
> > +	 */
> > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > +	if (threshold_lsn == NULLCOMMITLSN)
> > +		return 0;
> 
> This smells of premature optimisation.
> 
> When we are in a tail-pushing scenario (i.e. any sort of
> sustained metadata workload) this will always return true, and so we
> will relog every intent that isn't in the current checkpoint every
> time this is called.  Under light load, we don't care if we add a
> little bit of relogging overhead as the CIL slowly flushes/pushes -
> it will have neglible impact on performance because there is little
> load on the journal.
> 
> However, when we are under heavy load the code will now be reading
> the grant head and log position accounting variables during every
> commit, hence greatly increasing the number and temporal
> distribution of accesses to the hotest cachelines in the log. We
> currently never access these cache lines during commit unless the
> unit reservation has run out and we have to regrant physical log
> space for the transaction to continue (i.e. we are into slow path
> commit code). IOWs, this is like causing far more than double the
> number of accesses to the grant head, the log tail, the
> last_sync_lsn, etc, all of which is unnecessary exactly when we care
> about minimising contention on the log space accounting variables...
> 
> Given that it is a redundant check under heavy load journal load
> when access to the log grant/head/tail are already contended,
> I think we should just be checking the "in current checkpoint" logic
> and not making it conditional on the log being near full.

<nod> FWIW I broke this patch up again into the first part that
only does relogging if the checkpoints don't match, and a second part
that does the LSN push target check to see if I could observe any
difference.

Across a ~4h fstests run I noticed that there was about ~20% fewer
relogs, but OTOH the total runtime didn't change noticeably.  I kind of
wondered if the increased cacheline contention would at least slow down
the frontend a bit to give the log a chance to push things out, but
haven't had time to dig any further than "ran fstests, recorded runtimes
and grep | wc -l'd the ftrace log".

Anyway, I was about to resend with all these patches rebased against
something resembling the 5.10 branch, so expect to see this broken out a
bit.

--D

> Cheers,
> 
> Dave.
> -- 
> Dave Chinner
> david@fromorbit.com

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Dave Chinner]

On Sun, Sep 27, 2020 at 04:30:25PM -0700, Darrick J. Wong wrote:
> On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> > On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > > @@ -361,6 +362,52 @@ xfs_defer_cancel_list(
> > >  	}
> > >  }
> > >  
> > > +/*
> > > + * Prevent a log intent item from pinning the tail of the log by logging a
> > > + * done item to release the intent item; and then log a new intent item.
> > > + * The caller should provide a fresh transaction and roll it after we're done.
> > > + */
> > > +static int
> > > +xfs_defer_relog(
> > > +	struct xfs_trans		**tpp,
> > > +	struct list_head		*dfops)
> > > +{
> > > +	struct xfs_defer_pending	*dfp;
> > > +	xfs_lsn_t			threshold_lsn;
> > > +
> > > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > > +
> > > +	/*
> > > +	 * Figure out where we need the tail to be in order to maintain the
> > > +	 * minimum required free space in the log.
> > > +	 */
> > > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > > +	if (threshold_lsn == NULLCOMMITLSN)
> > > +		return 0;
> > 
> > This smells of premature optimisation.
> > 
> > When we are in a tail-pushing scenario (i.e. any sort of
> > sustained metadata workload) this will always return true, and so we
> > will relog every intent that isn't in the current checkpoint every
> > time this is called.  Under light load, we don't care if we add a
> > little bit of relogging overhead as the CIL slowly flushes/pushes -
> > it will have neglible impact on performance because there is little
> > load on the journal.
> > 
> > However, when we are under heavy load the code will now be reading
> > the grant head and log position accounting variables during every
> > commit, hence greatly increasing the number and temporal
> > distribution of accesses to the hotest cachelines in the log. We
> > currently never access these cache lines during commit unless the
> > unit reservation has run out and we have to regrant physical log
> > space for the transaction to continue (i.e. we are into slow path
> > commit code). IOWs, this is like causing far more than double the
> > number of accesses to the grant head, the log tail, the
> > last_sync_lsn, etc, all of which is unnecessary exactly when we care
> > about minimising contention on the log space accounting variables...
> > 
> > Given that it is a redundant check under heavy load journal load
> > when access to the log grant/head/tail are already contended,
> > I think we should just be checking the "in current checkpoint" logic
> > and not making it conditional on the log being near full.
> 
> <nod> FWIW I broke this patch up again into the first part that
> only does relogging if the checkpoints don't match, and a second part
> that does the LSN push target check to see if I could observe any
> difference.
> 
> Across a ~4h fstests run I noticed that there was about ~20% fewer
> relogs, but OTOH the total runtime didn't change noticeably.  I kind of
> wondered if the increased cacheline contention would at least slow down
> the frontend a bit to give the log a chance to push things out, but
> haven't had time to dig any further than "ran fstests, recorded runtimes
> and grep | wc -l'd the ftrace log".

fstests doesn't generate anywhere near the load necessary to measure
log space accounting cacheline contention. That's one of the things
I use fsmark workloads for.

One of the things that "20% reduction" tells me, though, is that 80%
of the time that relogging is happening with this patch we are in a
tail pushing situation. i.e. the log is more often full than it is
empty when we are relogging.

That tends to support my statements that this is optimising the
wrong case.

FWIW, it seems to me that we need real stats for the deferops (i.e.
exposed in /proc/fs/xfs/stat) so we can monitor in realtime the
breakdown of work that is being done. Being able to see things like
how many defer rolls a transaction takes under a given workload is
very interesting information, and would give us insight into things
like whether the log count for transaction reservations is
reasonable or not....

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Brian Foster]

On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > From: Darrick J. Wong <darrick.wong@oracle.com>
> > 
> > There's a subtle design flaw in the deferred log item code that can lead
> > to pinning the log tail.  Taking up the defer ops chain examples from
> > the previous commit, we can get trapped in sequences like this:
> > 
> > Caller hands us a transaction t0 with D0-D3 attached.  The defer ops
> > chain will look like the following if the transaction rolls succeed:
> > 
> > t1: D0(t0), D1(t0), D2(t0), D3(t0)
> > t2: d4(t1), d5(t1), D1(t0), D2(t0), D3(t0)
> > t3: d5(t1), D1(t0), D2(t0), D3(t0)
> > ...
> > t9: d9(t7), D3(t0)
> > t10: D3(t0)
> > t11: d10(t10), d11(t10)
> > t12: d11(t10)
> > 
> > In transaction 9, we finish d9 and try to roll to t10 while holding onto
> > an intent item for D3 that we logged in t0.
> > 
> > The previous commit changed the order in which we place new defer ops in
> > the defer ops processing chain to reduce the maximum chain length.  Now
> > make xfs_defer_finish_noroll capable of relogging the entire chain
> > periodically so that we can always move the log tail forward.  Most
> > chains will never get relogged, except for operations that generate very
> > long chains (large extents containing many blocks with different sharing
> > levels) or are on filesystems with small logs and a lot of ongoing
> > metadata updates.
> > 
> > Callers are now required to ensure that the transaction reservation is
> > large enough to handle logging done items and new intent items for the
> > maximum possible chain length.  Most callers are careful to keep the
> > chain lengths low, so the overhead should be minimal.
> > 
> > The decision to relog an intent item is made based on whether or not the
> > intent was added to the current checkpoint.  If so, the checkpoint is
> > still open and there's no point in relogging.  Otherwise, the old
> > checkpoint is closed and we relog the intent to add it to the current
> > one.
> > 
> > Signed-off-by: Darrick J. Wong <darrick.wong@oracle.com>
> > ---
> >  fs/xfs/libxfs/xfs_defer.c  |   52 ++++++++++++++++++++++++++++++++++++++++++++
> >  fs/xfs/xfs_bmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_extfree_item.c  |   29 +++++++++++++++++++++++++
> >  fs/xfs/xfs_refcount_item.c |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_rmap_item.c     |   27 +++++++++++++++++++++++
> >  fs/xfs/xfs_trace.h         |    1 +
> >  fs/xfs/xfs_trans.h         |   10 ++++++++
> >  7 files changed, 173 insertions(+)
> > 
> > 
> > diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
> > index 84a70edd0da1..c601cc2af254 100644
> > --- a/fs/xfs/libxfs/xfs_defer.c
> > +++ b/fs/xfs/libxfs/xfs_defer.c
> > @@ -17,6 +17,7 @@
> >  #include "xfs_inode_item.h"
> >  #include "xfs_trace.h"
> >  #include "xfs_icache.h"
> > +#include "xfs_log.h"
> >  
> >  /*
> >   * Deferred Operations in XFS
> > @@ -361,6 +362,52 @@ xfs_defer_cancel_list(
> >  	}
> >  }
> >  
> > +/*
> > + * Prevent a log intent item from pinning the tail of the log by logging a
> > + * done item to release the intent item; and then log a new intent item.
> > + * The caller should provide a fresh transaction and roll it after we're done.
> > + */
> > +static int
> > +xfs_defer_relog(
> > +	struct xfs_trans		**tpp,
> > +	struct list_head		*dfops)
> > +{
> > +	struct xfs_defer_pending	*dfp;
> > +	xfs_lsn_t			threshold_lsn;
> > +
> > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > +
> > +	/*
> > +	 * Figure out where we need the tail to be in order to maintain the
> > +	 * minimum required free space in the log.
> > +	 */
> > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > +	if (threshold_lsn == NULLCOMMITLSN)
> > +		return 0;
> 
> This smells of premature optimisation.
> 
> When we are in a tail-pushing scenario (i.e. any sort of
> sustained metadata workload) this will always return true, and so we
> will relog every intent that isn't in the current checkpoint every
> time this is called.  Under light load, we don't care if we add a
> little bit of relogging overhead as the CIL slowly flushes/pushes -
> it will have neglible impact on performance because there is little
> load on the journal.
> 

That seems like an overly broad and not necessarily correct assumption.
The threshold above is tail relative and hardcoded (with the zero param)
to the default AIL pushing threshold, which is 25% of the log. If we
assume sustained tail pushing conditions, a committed intent doesn't
trigger relog again until it falls within that threshold in the on-disk
log. The current CIL (nonblocking) size threshold is half that at 12.5%.
So relative to a given rolling transaction processing an intent chain,
there's a decent number of full CIL checkpoints that can occur before
any of those intents need to relog again (if at all), regardless of log
size.

Without that logic, we're changing behavior to relog the entire chain in
every CIL checkpoint. That's a fairly significant change in behavior
with less predictable breakdown conditions. Do we know how long a single
chain is going to be? Do we know how many CPUs are concurrently
processing "long chain" operations? Do we know whether an external
workload is causing even more frequent checkpoints than governed by the
CIL size limit? The examples in the commit logs in this series refer to
chains of of hundreds of intents with hundreds of transaction rolls.
Those types of scenarios are hard enough to reason about, particularly
when we consider boxes with hundreds of CPUs, so I'm somewhat skeptical
of us accurately predicting performance/behavior over an implementation
that bounds processing more explicitly.

ISTM that these are all essentially undefined contributing factors. For
those reasons, I don't really consider this is an optimization at all.
Rather IMO it's a component of sane/predictable functional behavior. I
don't think concerns over cacheline contention on the log tail field
justify removing it entirely.

> However, when we are under heavy load the code will now be reading
> the grant head and log position accounting variables during every
> commit, hence greatly increasing the number and temporal
> distribution of accesses to the hotest cachelines in the log. We
> currently never access these cache lines during commit unless the
> unit reservation has run out and we have to regrant physical log
> space for the transaction to continue (i.e. we are into slow path
> commit code). IOWs, this is like causing far more than double the
> number of accesses to the grant head, the log tail, the
> last_sync_lsn, etc, all of which is unnecessary exactly when we care
> about minimising contention on the log space accounting variables...
> 

If we're under sustained tail pushing pressure, blocking transactions
have already hit this cacheline as well, FWIW.

But if we're concerned about cacheline access in the commit path
specifically, I'm sure we could come up with any number of optimizations
to address that directly. E.g., we could sample the threshold
occasionally instead of on every roll, wait until the current
transaction has consumed all logres units (where we'll be hitting that
line anyways), shift state tracking over to xfsaild via setting a flag
on log items with an ->iop_relog() handler set that happen to pin the
tail, etc. etc. That said, I do think any such added complexity should
be justified with some accompanying profiling data (and I like the idea
of new stats counters mentioned in the separate mail).

Brian

> Given that it is a redundant check under heavy load journal load
> when access to the log grant/head/tail are already contended,
> I think we should just be checking the "in current checkpoint" logic
> and not making it conditional on the log being near full.
> 
> Cheers,
> 
> Dave.
> -- 
> Dave Chinner
> david@fromorbit.com
> 

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Dave Chinner]

On Mon, Sep 28, 2020 at 11:16:27AM -0400, Brian Foster wrote:
> On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> > On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > > +xfs_defer_relog(
> > > +	struct xfs_trans		**tpp,
> > > +	struct list_head		*dfops)
> > > +{
> > > +	struct xfs_defer_pending	*dfp;
> > > +	xfs_lsn_t			threshold_lsn;
> > > +
> > > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > > +
> > > +	/*
> > > +	 * Figure out where we need the tail to be in order to maintain the
> > > +	 * minimum required free space in the log.
> > > +	 */
> > > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > > +	if (threshold_lsn == NULLCOMMITLSN)
> > > +		return 0;
> > 
> > This smells of premature optimisation.
> > 
> > When we are in a tail-pushing scenario (i.e. any sort of
> > sustained metadata workload) this will always return true, and so we
> > will relog every intent that isn't in the current checkpoint every
> > time this is called.  Under light load, we don't care if we add a
> > little bit of relogging overhead as the CIL slowly flushes/pushes -
> > it will have neglible impact on performance because there is little
> > load on the journal.
> > 
> 
> That seems like an overly broad and not necessarily correct assumption.
> The threshold above is tail relative and hardcoded (with the zero param)
> to the default AIL pushing threshold, which is 25% of the log. If we

The pushing threshold is 75% of the log space has been reserved by
the grant head, not that there's only 25% of the log free. The
reservation is typically much, much larger than the change that is
actually written to the log, and so we can be tail pushing even when
the log is largely empty and the CIL hasn't reached it's threshold
for pushing.

Think about it - if we have a log with a 256kB log stripe unit,
a itruncate reservation is somewhere around 1.5MB in size (700kB *
2), and if we have reflink/rmap enabled, it's closer to 6MB in size.
Yet a typical modification will not use any of the 512kB*8 space
reserved for the LSU (because CIL!) and might only use 10kB of new
log space in the CIL because that's all that was newly dirtied.

That means we reserve 6MB of log space for each itruncate
transaction in flight, (directory ops are almost as heavyweight) so
it only takes 16 transactions in flight to consume 100MB of reserve
grant head space. If we've got a log smaller than 130MB in this
situation, we are into tail pushing -even if the physical log is
empty-.

IOWs, tail pushing is not triggered by how much physical log space
has been consumed - it is triggered by reservation pressure. And we
can trivially drive the system into reservation pressure with
concurrent workloads

> assume sustained tail pushing conditions, a committed intent doesn't
> trigger relog again until it falls within that threshold in the on-disk
> log. The current CIL (nonblocking) size threshold is half that at 12.5%.

Or smaller. For small logs it is 12.5% of the log size. For larger
logs, it caps at 32MB (8 * (256k << 4)).

> So relative to a given rolling transaction processing an intent chain,
> there's a decent number of full CIL checkpoints that can occur before
> any of those intents need to relog again (if at all), regardless of log
> size.

Your logic is inverted because reservation pressure does not reflect
CIL pressure.  Log space consumption and reservation pressure were
decoupled by the in-memory relogging that the CIL enables, hence
given a specific intent chain, the likely probability is that it
will not span more than a single CIL context. i.e. it will complete
rolling entirely within a single CIL commit.

As the log gets larger and the CIL increases in size, the
probability that an intent chain completes within a single CIL
commit goes up (e.g. 6MB reservation vs 32MB CIL push threshold).
The lighter the load, the more likely it is that a transaction chain
will complete within a single CIL checkpoint, even on small logs.

> Without that logic, we're changing behavior to relog the entire chain in
> every CIL checkpoint. That's a fairly significant change in behavior
> with less predictable breakdown conditions. Do we know how long a single
> chain is going to be?

Yes: the typical worst case chain length is defined by the
transaction reservation log count. That is supposed to cover > %99
of typical log space requirements for that operation.

For any chain that is longer than this, we end up in the slow
regrant path that reserves a unit of log space at a time, and these
are the cases where the transaction must be careful about not
pinning the tail of the log. i.e. long chains are exactly the case
where we want to relog the intents in every new CIL context. This is
no different to the way we relog the inode in -every transaction
roll- whether it is modified or not so that we can guarantee it
doesn't pin the tail of the log when we need to regrant space on
commit....

> Do we know how many CPUs are concurrently
> processing "long chain" operations?

Yes: as many as the grant head reservations will allow. That's
always been the bound maximum transaction concurrency we can
support.

> Do we know whether an external
> workload is causing even more frequent checkpoints than governed by the
> CIL size limit?

Irrelevant, because checkpoint frequency affects the relogging
efficiency of -everything- that running transactions. i.e. the
impact is not isolated to relogging a few small intents, it affects
relogging of all metadata, from AG headers to btree blocks,
directories and inodes. IOWs, the overhead of relogging intents
will be lost in the overhead of completely relogging entire dirty
metadata blocks that the transactions also touch, even though they
may have only newly dirtied a few bytes in each buffer.

> The examples in the commit logs in this series refer to
> chains of hundreds of intents with hundreds of transaction rolls.

Truncating a file with 10 million extents will roll the transaction
10 million times. Having a long intent chain is no different from a
"don't pin the tail of the log" perspective than truncating a
badly fragmented file. Both need to relog their outstanding items
that could pin the tail of the log as frequently as they commit...

This is a basic principle of permanent transactions: they must
guarantee forwards progress by ensuring they can't pin the tail of
the log at any time. That is, if you hold an item that *may* pin the
tail of the log when you need to regrant log space, you need to move
those items to the head of the log -before- you attempt to regrant
log space. We do not do that with intents, and conditional relogging
doesn't provide that guarantee, either.  Relogging the item once the
item is no longer at the head of the log provides that forwards
progress guarantee.

I don't want to slap a band-aid over the problem in the name of
"performance". Correctness comes first, then if we find a
performance problem we'll address that without breaking correctness.

> Those types of scenarios are hard enough to reason about,
> particularly when we consider boxes with hundreds of CPUs, so I'm
> somewhat skeptical of us accurately predicting
> performance/behavior over an implementation that bounds processing
> more explicitly.  ISTM that these are all essentially undefined
> contributing factors.

I don't find these things hard to reason about, nor do I consider
them undefined factors. This is largely because I've been dealing
with journalling and AIL issues at this scale for the best part of
15 years. Everything I think about in this area starts with the
requirement "this needs to scale to 10,000+ concurrent transactions
across thousands of CPUs". The reason for that can be found in
ancient history, such as:

commit 249a8c1124653fa90f3a3afff869095a31bc229f
Author: David Chinner <dgc@sgi.com>
Date:   Tue Feb 5 12:13:32 2008 +1100

    [XFS] Move AIL pushing into it's own thread
    
    When many hundreds to thousands of threads all try to do simultaneous
    transactions and the log is in a tail-pushing situation (i.e. full), we
    can get multiple threads walking the AIL list and contending on the AIL
    lock.
....

commit 28f1bc4aabea316d01ca7a59c38d619bc17e3550
Author: Dave Chinner <dgc@sgi.com>
Date:   Fri Feb 15 15:19:57 2008 +0000

    Prevent AIL lock contention during transaction completion
    
    When hundreds of processors attempt to commit transactions at the
    same time, they can contend on the AIL lock when updating the tail
    LSN held in the in-core log structure.
....

The workload that lead to the lockless grant head reservation code,
the single threaded, cursor based AIL traversals, the atomic tail
accounting, etc was a MPI workload on a 2048p machine doing an MPI
synchronised close on ~6 fds per CPU on all CPUs at once. The
lockless log code reduced this part of the workload from 4 hours to
4 seconds....

Servers these days are still small compared to the SGI machines that
XFS ran on in the mid-2000s....

> > However, when we are under heavy load the code will now be reading
> > the grant head and log position accounting variables during every
> > commit, hence greatly increasing the number and temporal
> > distribution of accesses to the hotest cachelines in the log. We
> > currently never access these cache lines during commit unless the
> > unit reservation has run out and we have to regrant physical log
> > space for the transaction to continue (i.e. we are into slow path
> > commit code). IOWs, this is like causing far more than double the
> > number of accesses to the grant head, the log tail, the
> > last_sync_lsn, etc, all of which is unnecessary exactly when we care
> > about minimising contention on the log space accounting variables...
> > 
> 
> If we're under sustained tail pushing pressure, blocking transactions
> have already hit this cacheline as well, FWIW.

No, tail pushing != blocking. If the AIL pushing is keeping up with
the targets that are being set (as frequently happens with large
logs and fast storage), then we rarely run out of log space and we
do not block new reservations waiting for reservation space.

> But if we're concerned about cacheline access in the commit path
> specifically, I'm sure we could come up with any number of optimizations
> to address that directly. E.g., we could sample the threshold
> occasionally instead of on every roll, wait until the current
> transaction has consumed all logres units (where we'll be hitting that
> line anyways), shift state tracking over to xfsaild via setting a flag
> on log items with an ->iop_relog() handler set that happen to pin the
> tail, etc. etc. That said, I do think any such added complexity should
> be justified with some accompanying profiling data (and I like the idea
> of new stats counters mentioned in the separate mail).

Yes, there's lots of ways the pushing threshold could be done
differently, but to focus on that misses the point that intents
violate forwards progress guarantees rolling transactions are
supposed to provide the log. I simply made the "access overhead"
argument as a supporting point that this change is also likely to
have unintended side effects...

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Brian Foster]

On Tue, Sep 29, 2020 at 09:09:10AM +1000, Dave Chinner wrote:
> On Mon, Sep 28, 2020 at 11:16:27AM -0400, Brian Foster wrote:
> > On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> > > On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > > > +xfs_defer_relog(
> > > > +	struct xfs_trans		**tpp,
> > > > +	struct list_head		*dfops)
> > > > +{
> > > > +	struct xfs_defer_pending	*dfp;
> > > > +	xfs_lsn_t			threshold_lsn;
> > > > +
> > > > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > > > +
> > > > +	/*
> > > > +	 * Figure out where we need the tail to be in order to maintain the
> > > > +	 * minimum required free space in the log.
> > > > +	 */
> > > > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > > > +	if (threshold_lsn == NULLCOMMITLSN)
> > > > +		return 0;
> > > 
> > > This smells of premature optimisation.
> > > 
> > > When we are in a tail-pushing scenario (i.e. any sort of
> > > sustained metadata workload) this will always return true, and so we
> > > will relog every intent that isn't in the current checkpoint every
> > > time this is called.  Under light load, we don't care if we add a
> > > little bit of relogging overhead as the CIL slowly flushes/pushes -
> > > it will have neglible impact on performance because there is little
> > > load on the journal.
> > > 
> > 
> > That seems like an overly broad and not necessarily correct assumption.
> > The threshold above is tail relative and hardcoded (with the zero param)
> > to the default AIL pushing threshold, which is 25% of the log. If we
> 
> The pushing threshold is 75% of the log space has been reserved by
> the grant head, not that there's only 25% of the log free. The
> reservation is typically much, much larger than the change that is
> actually written to the log, and so we can be tail pushing even when
> the log is largely empty and the CIL hasn't reached it's threshold
> for pushing.
> 
> Think about it - if we have a log with a 256kB log stripe unit,
> a itruncate reservation is somewhere around 1.5MB in size (700kB *
> 2), and if we have reflink/rmap enabled, it's closer to 6MB in size.
> Yet a typical modification will not use any of the 512kB*8 space
> reserved for the LSU (because CIL!) and might only use 10kB of new
> log space in the CIL because that's all that was newly dirtied.
> 
> That means we reserve 6MB of log space for each itruncate
> transaction in flight, (directory ops are almost as heavyweight) so
> it only takes 16 transactions in flight to consume 100MB of reserve
> grant head space. If we've got a log smaller than 130MB in this
> situation, we are into tail pushing -even if the physical log is
> empty-.
> 
> IOWs, tail pushing is not triggered by how much physical log space
> has been consumed - it is triggered by reservation pressure. And we
> can trivially drive the system into reservation pressure with
> concurrent workloads
> 

Yes, I understand. What I'm saying is that once we get past the
reservation head checks, there is a threshold lsn check that requires an
intent sit in that 25% range from the on-disk tail of the log for it to
be relogged. That _might_ unnecessarily relog in certain cases (i.e.
when the active range of the log is small), but it is not always the
case and I don't think it results in per CIL context relogging in
practice.

> > assume sustained tail pushing conditions, a committed intent doesn't
> > trigger relog again until it falls within that threshold in the on-disk
> > log. The current CIL (nonblocking) size threshold is half that at 12.5%.
> 
> Or smaller. For small logs it is 12.5% of the log size. For larger
> logs, it caps at 32MB (8 * (256k << 4)).
> 
> > So relative to a given rolling transaction processing an intent chain,
> > there's a decent number of full CIL checkpoints that can occur before
> > any of those intents need to relog again (if at all), regardless of log
> > size.
> 
> Your logic is inverted because reservation pressure does not reflect
> CIL pressure.  Log space consumption and reservation pressure were
> decoupled by the in-memory relogging that the CIL enables, hence
> given a specific intent chain, the likely probability is that it
> will not span more than a single CIL context. i.e. it will complete
> rolling entirely within a single CIL commit.
> 
> As the log gets larger and the CIL increases in size, the
> probability that an intent chain completes within a single CIL
> commit goes up (e.g. 6MB reservation vs 32MB CIL push threshold).
> The lighter the load, the more likely it is that a transaction chain
> will complete within a single CIL checkpoint, even on small logs.
> 

Sure, I agree with that. That's not a major factor for intent chains
that pin the log tail long enough to cause deadlocks.

> > Without that logic, we're changing behavior to relog the entire chain in
> > every CIL checkpoint. That's a fairly significant change in behavior
> > with less predictable breakdown conditions. Do we know how long a single
> > chain is going to be?
> 
> Yes: the typical worst case chain length is defined by the
> transaction reservation log count. That is supposed to cover > %99
> of typical log space requirements for that operation.
> 

I don't think reservation log counts define worst case conditions for
intent chains. Darrick has documented cases in the commit logs that far
exceed those values. I'm assuming those are legitimate/observed
scenarios, but could be mistaken.

> For any chain that is longer than this, we end up in the slow
> regrant path that reserves a unit of log space at a time, and these
> are the cases where the transaction must be careful about not
> pinning the tail of the log. i.e. long chains are exactly the case
> where we want to relog the intents in every new CIL context. This is
> no different to the way we relog the inode in -every transaction
> roll- whether it is modified or not so that we can guarantee it
> doesn't pin the tail of the log when we need to regrant space on
> commit....
> 

Yes, the relogging approach is the same. The difference is that in one
case we're logging a small, fixed size (inode) object repeatedly that is
already factored into the transaction reservation and in the other case,
we're logging a dynamic and non-deterministic number of (intent) objects
a non-deterministic number of times.

> > Do we know how many CPUs are concurrently
> > processing "long chain" operations?
> 
> Yes: as many as the grant head reservations will allow. That's
> always been the bound maximum transaction concurrency we can
> support.
> 
> > Do we know whether an external
> > workload is causing even more frequent checkpoints than governed by the
> > CIL size limit?
> 
> Irrelevant, because checkpoint frequency affects the relogging
> efficiency of -everything- that running transactions. i.e. the
> impact is not isolated to relogging a few small intents, it affects
> relogging of all metadata, from AG headers to btree blocks,
> directories and inodes. IOWs, the overhead of relogging intents
> will be lost in the overhead of completely relogging entire dirty
> metadata blocks that the transactions also touch, even though they
> may have only newly dirtied a few bytes in each buffer.
> 
> > The examples in the commit logs in this series refer to
> > chains of hundreds of intents with hundreds of transaction rolls.
> 
> Truncating a file with 10 million extents will roll the transaction
> 10 million times. Having a long intent chain is no different from a
> "don't pin the tail of the log" perspective than truncating a
> badly fragmented file. Both need to relog their outstanding items
> that could pin the tail of the log as frequently as they commit...
> 
> This is a basic principle of permanent transactions: they must
> guarantee forwards progress by ensuring they can't pin the tail of
> the log at any time. That is, if you hold an item that *may* pin the
> tail of the log when you need to regrant log space, you need to move
> those items to the head of the log -before- you attempt to regrant
> log space. We do not do that with intents, and conditional relogging
> doesn't provide that guarantee, either.  Relogging the item once the
> item is no longer at the head of the log provides that forwards
> progress guarantee.
> 

It sounds like there's a correctness argument buried in here. If you
think the tail lsn threshold approach is not fundamentally correct, can
you please elaborate on that? I think fundamental correctness is far
more important at this early stage than the prospective impact of
cacheline contention caused by an implementation detail.

> I don't want to slap a band-aid over the problem in the name of
> "performance". Correctness comes first, then if we find a
> performance problem we'll address that without breaking correctness.
> 
...
> > > However, when we are under heavy load the code will now be reading
> > > the grant head and log position accounting variables during every
> > > commit, hence greatly increasing the number and temporal
> > > distribution of accesses to the hotest cachelines in the log. We
> > > currently never access these cache lines during commit unless the
> > > unit reservation has run out and we have to regrant physical log
> > > space for the transaction to continue (i.e. we are into slow path
> > > commit code). IOWs, this is like causing far more than double the
> > > number of accesses to the grant head, the log tail, the
> > > last_sync_lsn, etc, all of which is unnecessary exactly when we care
> > > about minimising contention on the log space accounting variables...
> > > 
> > 
> > If we're under sustained tail pushing pressure, blocking transactions
> > have already hit this cacheline as well, FWIW.
> 
> No, tail pushing != blocking. If the AIL pushing is keeping up with
> the targets that are being set (as frequently happens with large
> logs and fast storage), then we rarely run out of log space and we
> do not block new reservations waiting for reservation space.
> 

Just pointing out that there's another prospective path for a
transaction to hit the cacheline. As you've already pointed out, it's
quite easy to reach reservation blocking conditions before the AIL is
even involved.

> > But if we're concerned about cacheline access in the commit path
> > specifically, I'm sure we could come up with any number of optimizations
> > to address that directly. E.g., we could sample the threshold
> > occasionally instead of on every roll, wait until the current
> > transaction has consumed all logres units (where we'll be hitting that
> > line anyways), shift state tracking over to xfsaild via setting a flag
> > on log items with an ->iop_relog() handler set that happen to pin the
> > tail, etc. etc. That said, I do think any such added complexity should
> > be justified with some accompanying profiling data (and I like the idea
> > of new stats counters mentioned in the separate mail).
> 
> Yes, there's lots of ways the pushing threshold could be done
> differently, but to focus on that misses the point that intents
> violate forwards progress guarantees rolling transactions are
> supposed to provide the log. I simply made the "access overhead"
> argument as a supporting point that this change is also likely to
> have unintended side effects...
> 

The argument stated was that the relog filtering was redundant logic. I
think that misinterprets the logic. If there's a correctness issue, then
I'd much prefer to focus on that..

Brian

> Cheers,
> 
> Dave.
> -- 
> Dave Chinner
> david@fromorbit.com
> 

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Darrick J. Wong]

On Tue, Sep 29, 2020 at 08:27:39AM -0400, Brian Foster wrote:
> On Tue, Sep 29, 2020 at 09:09:10AM +1000, Dave Chinner wrote:
> > On Mon, Sep 28, 2020 at 11:16:27AM -0400, Brian Foster wrote:
> > > On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> > > > On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > > > > +xfs_defer_relog(
> > > > > +	struct xfs_trans		**tpp,
> > > > > +	struct list_head		*dfops)
> > > > > +{
> > > > > +	struct xfs_defer_pending	*dfp;
> > > > > +	xfs_lsn_t			threshold_lsn;
> > > > > +
> > > > > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > > > > +
> > > > > +	/*
> > > > > +	 * Figure out where we need the tail to be in order to maintain the
> > > > > +	 * minimum required free space in the log.
> > > > > +	 */
> > > > > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > > > > +	if (threshold_lsn == NULLCOMMITLSN)
> > > > > +		return 0;
> > > > 
> > > > This smells of premature optimisation.
> > > > 
> > > > When we are in a tail-pushing scenario (i.e. any sort of
> > > > sustained metadata workload) this will always return true, and so we
> > > > will relog every intent that isn't in the current checkpoint every
> > > > time this is called.  Under light load, we don't care if we add a
> > > > little bit of relogging overhead as the CIL slowly flushes/pushes -
> > > > it will have neglible impact on performance because there is little
> > > > load on the journal.
> > > > 
> > > 
> > > That seems like an overly broad and not necessarily correct assumption.
> > > The threshold above is tail relative and hardcoded (with the zero param)
> > > to the default AIL pushing threshold, which is 25% of the log. If we
> > 
> > The pushing threshold is 75% of the log space has been reserved by
> > the grant head, not that there's only 25% of the log free. The
> > reservation is typically much, much larger than the change that is
> > actually written to the log, and so we can be tail pushing even when
> > the log is largely empty and the CIL hasn't reached it's threshold
> > for pushing.
> > 
> > Think about it - if we have a log with a 256kB log stripe unit,
> > a itruncate reservation is somewhere around 1.5MB in size (700kB *
> > 2), and if we have reflink/rmap enabled, it's closer to 6MB in size.
> > Yet a typical modification will not use any of the 512kB*8 space
> > reserved for the LSU (because CIL!) and might only use 10kB of new
> > log space in the CIL because that's all that was newly dirtied.
> > 
> > That means we reserve 6MB of log space for each itruncate
> > transaction in flight, (directory ops are almost as heavyweight) so
> > it only takes 16 transactions in flight to consume 100MB of reserve
> > grant head space. If we've got a log smaller than 130MB in this
> > situation, we are into tail pushing -even if the physical log is
> > empty-.
> > 
> > IOWs, tail pushing is not triggered by how much physical log space
> > has been consumed - it is triggered by reservation pressure. And we
> > can trivially drive the system into reservation pressure with
> > concurrent workloads
> > 
> 
> Yes, I understand. What I'm saying is that once we get past the
> reservation head checks, there is a threshold lsn check that requires an
> intent sit in that 25% range from the on-disk tail of the log for it to
> be relogged. That _might_ unnecessarily relog in certain cases (i.e.
> when the active range of the log is small), but it is not always the
> case and I don't think it results in per CIL context relogging in
> practice.

FWIW, I added a defer_relog stats counter and re-ran my nightly fstests
runs (which at this point consist of):

A) upstream V5 with all features enabled
B) same, but with 1k block size
C) V4 filesystem
D) V5 with DAX

With the first of the relogging patches enabled, we relog any time we
find that an intent item is not in the current checkpoint.

A) defer_relog 26237
B) defer_relog 81500
C) defer_relog 15
D) defer_relog 2660

With both enabled, we relog if the intent item is below the push
threshold and the intent item isn't in the current checkpoint.

A) defer_relog 11345
B) defer_relog 1
C) defer_relog 945
D) defer_relog 1805

The runtime was about the same, though oddly the runtime has gone from
3.5h (last week) to 6h (this week) though I did just rebase fstests
and... wow, there are some new tests that take forever to run.

From the ftrace data, the longest chains I see are from evil reflink
tests that create a large extent, share it, punch out every other block
of one of the copies, and then delete the other copy to stress CUI/EFI
creation.

Those chains can run into the hundreds (~400 on the (A) config) though
sadly they don't test the relogging mechanism since the removal is
single-threaded, and the log doesn't checkpoint or hit the push
thresholds.

> > > assume sustained tail pushing conditions, a committed intent doesn't
> > > trigger relog again until it falls within that threshold in the on-disk
> > > log. The current CIL (nonblocking) size threshold is half that at 12.5%.
> > 
> > Or smaller. For small logs it is 12.5% of the log size. For larger
> > logs, it caps at 32MB (8 * (256k << 4)).
> > 
> > > So relative to a given rolling transaction processing an intent chain,
> > > there's a decent number of full CIL checkpoints that can occur before
> > > any of those intents need to relog again (if at all), regardless of log
> > > size.
> > 
> > Your logic is inverted because reservation pressure does not reflect
> > CIL pressure.  Log space consumption and reservation pressure were
> > decoupled by the in-memory relogging that the CIL enables, hence
> > given a specific intent chain, the likely probability is that it
> > will not span more than a single CIL context. i.e. it will complete
> > rolling entirely within a single CIL commit.
> > 
> > As the log gets larger and the CIL increases in size, the
> > probability that an intent chain completes within a single CIL
> > commit goes up (e.g. 6MB reservation vs 32MB CIL push threshold).
> > The lighter the load, the more likely it is that a transaction chain
> > will complete within a single CIL checkpoint, even on small logs.
> > 
> 
> Sure, I agree with that. That's not a major factor for intent chains
> that pin the log tail long enough to cause deadlocks.
> 
> > > Without that logic, we're changing behavior to relog the entire chain in
> > > every CIL checkpoint. That's a fairly significant change in behavior
> > > with less predictable breakdown conditions. Do we know how long a single
> > > chain is going to be?
> > 
> > Yes: the typical worst case chain length is defined by the
> > transaction reservation log count. That is supposed to cover > %99
> > of typical log space requirements for that operation.
> > 
> 
> I don't think reservation log counts define worst case conditions for
> intent chains. Darrick has documented cases in the commit logs that far
> exceed those values. I'm assuming those are legitimate/observed
> scenarios, but could be mistaken.

They're rare, but definitely the kinds of things (see above) that
unprivileged userspace can create.

> > For any chain that is longer than this, we end up in the slow
> > regrant path that reserves a unit of log space at a time, and these
> > are the cases where the transaction must be careful about not
> > pinning the tail of the log. i.e. long chains are exactly the case
> > where we want to relog the intents in every new CIL context. This is
> > no different to the way we relog the inode in -every transaction
> > roll- whether it is modified or not so that we can guarantee it
> > doesn't pin the tail of the log when we need to regrant space on
> > commit....
> > 
> 
> Yes, the relogging approach is the same. The difference is that in one
> case we're logging a small, fixed size (inode) object repeatedly that is
> already factored into the transaction reservation and in the other case,
> we're logging a dynamic and non-deterministic number of (intent) objects
> a non-deterministic number of times.
> 
> > > Do we know how many CPUs are concurrently
> > > processing "long chain" operations?
> > 
> > Yes: as many as the grant head reservations will allow. That's
> > always been the bound maximum transaction concurrency we can
> > support.
> > 
> > > Do we know whether an external
> > > workload is causing even more frequent checkpoints than governed by the
> > > CIL size limit?
> > 
> > Irrelevant, because checkpoint frequency affects the relogging
> > efficiency of -everything- that running transactions. i.e. the
> > impact is not isolated to relogging a few small intents, it affects
> > relogging of all metadata, from AG headers to btree blocks,
> > directories and inodes. IOWs, the overhead of relogging intents
> > will be lost in the overhead of completely relogging entire dirty
> > metadata blocks that the transactions also touch, even though they
> > may have only newly dirtied a few bytes in each buffer.

/me is confused, does this refer to transactions relogging dirty
buffers because they dirtied something (aka xfs_trans_log_buf)?  Or does
the checkpointing itself force relogging into the new checkpoint?

> > 
> > > The examples in the commit logs in this series refer to
> > > chains of hundreds of intents with hundreds of transaction rolls.
> > 
> > Truncating a file with 10 million extents will roll the transaction
> > 10 million times. Having a long intent chain is no different from a
> > "don't pin the tail of the log" perspective than truncating a
> > badly fragmented file. Both need to relog their outstanding items
> > that could pin the tail of the log as frequently as they commit...
> > 
> > This is a basic principle of permanent transactions: they must
> > guarantee forwards progress by ensuring they can't pin the tail of
> > the log at any time. That is, if you hold an item that *may* pin the
> > tail of the log when you need to regrant log space, you need to move
> > those items to the head of the log -before- you attempt to regrant
> > log space. We do not do that with intents, and conditional relogging
> > doesn't provide that guarantee, either.  Relogging the item once the
> > item is no longer at the head of the log provides that forwards
> > progress guarantee.
> > 
> 
> It sounds like there's a correctness argument buried in here. If you
> think the tail lsn threshold approach is not fundamentally correct, can
> you please elaborate on that? I think fundamental correctness is far
> more important at this early stage than the prospective impact of
> cacheline contention caused by an implementation detail.

I've been wondering if this discussion could be summarized like this:

We don't want logged inode items to pin the tail on long running
operations, so we tell everyone that if they're going to keep the inode
locked across transaction rolls, they must relog the inode into the new
transaction to keep it moving forward.  This is easy to spot and easy to
think about, since we generally only operate on one inode at a time and
the core is a fixed size.

For log intent items, the same general principle applies (anything that
we want to hold onto across a roll must be relogged to avoid pinning the
tail), but a transaction can have an arbitrary number of arbitrarily
sized intent items, and the overhead of relogging (aka logging an intent
done item and a new intent item) is much higher than relogging an inode.

Therefore, we add a new rule (A) that intent items must be relogged
across checkpoints.  There's less overhead than doing it *every
transaction* but this keeps the intents moving along.  This is still a
bright line rule, albeit buried in the defer ops code, because we know
exactly when it will trigger relogging.

However, adding (B) the push threshold thing now makes it /harder/ to
think about the intent item relogging because now we sort of have to
merge two not-quite-the-same concepts (the push threshold of the actual
log space usage vs. space usage according to the reservation grants)
which just makes relogging less predictable.

From my POV, we don't currently do any relogging of deferred items, so
applying either (A) or (B) seems like a benefit because at least we
close off a theoretical deadlock vector.  (B) on its own makes me
somewhat nervous because it sounds like the sort of thing that ends in
"infrequently used code path explodes in subtle ways on $config that
nobody tests", whereas (A) at least does it regularly enough that
everyone will know its there.  OTOH, if checkpoints are small, that
could result in a lot of unnecessary relogging, hence the attraction of
(B) or (A+B).

(I don't know anything about cacheline contention: I don't have quite
enough fast hardware and perf-fu (or free time) to study that in depth.
Since we're kind of lazy about locking around the grant head, it's
probably fine to be even lazier and only read that stuff once per
go-around, and only if we find an item that wasn't logged in the current
checkpoint.  Anyone got numbers?)

> > I don't want to slap a band-aid over the problem in the name of
> > "performance". Correctness comes first, then if we find a
> > performance problem we'll address that without breaking correctness.
> > 
> ...
> > > > However, when we are under heavy load the code will now be reading
> > > > the grant head and log position accounting variables during every
> > > > commit, hence greatly increasing the number and temporal
> > > > distribution of accesses to the hotest cachelines in the log. We
> > > > currently never access these cache lines during commit unless the
> > > > unit reservation has run out and we have to regrant physical log
> > > > space for the transaction to continue (i.e. we are into slow path
> > > > commit code). IOWs, this is like causing far more than double the
> > > > number of accesses to the grant head, the log tail, the
> > > > last_sync_lsn, etc, all of which is unnecessary exactly when we care
> > > > about minimising contention on the log space accounting variables...
> > > > 
> > > 
> > > If we're under sustained tail pushing pressure, blocking transactions
> > > have already hit this cacheline as well, FWIW.
> > 
> > No, tail pushing != blocking. If the AIL pushing is keeping up with
> > the targets that are being set (as frequently happens with large
> > logs and fast storage), then we rarely run out of log space and we
> > do not block new reservations waiting for reservation space.
> > 
> 
> Just pointing out that there's another prospective path for a
> transaction to hit the cacheline. As you've already pointed out, it's
> quite easy to reach reservation blocking conditions before the AIL is
> even involved.
> 
> > > But if we're concerned about cacheline access in the commit path
> > > specifically, I'm sure we could come up with any number of optimizations
> > > to address that directly. E.g., we could sample the threshold
> > > occasionally instead of on every roll, wait until the current
> > > transaction has consumed all logres units (where we'll be hitting that
> > > line anyways), shift state tracking over to xfsaild via setting a flag
> > > on log items with an ->iop_relog() handler set that happen to pin the

I'm not sure what I think about the AIL reaching out to touch intent
items that higher level code could also be accessing at the same time.
Wouldn't that require more coordination?

> > > tail, etc. etc. That said, I do think any such added complexity should
> > > be justified with some accompanying profiling data (and I like the idea
> > > of new stats counters mentioned in the separate mail).
> > 
> > Yes, there's lots of ways the pushing threshold could be done
> > differently, but to focus on that misses the point that intents
> > violate forwards progress guarantees rolling transactions are
> > supposed to provide the log. I simply made the "access overhead"
> > argument as a supporting point that this change is also likely to
> > have unintended side effects...
> > 
> 
> The argument stated was that the relog filtering was redundant logic. I
> think that misinterprets the logic. If there's a correctness issue, then
> I'd much prefer to focus on that..

I hope I didn't just stumble in and muddy things further. :)

--D

> Brian
> 
> > Cheers,
> > 
> > Dave.
> > -- 
> > Dave Chinner
> > david@fromorbit.com
> > 
> 

Re: [PATCH 3/3] xfs: periodically relog deferred intent items

[Brian Foster]

On Tue, Sep 29, 2020 at 10:01:13AM -0700, Darrick J. Wong wrote:
> On Tue, Sep 29, 2020 at 08:27:39AM -0400, Brian Foster wrote:
> > On Tue, Sep 29, 2020 at 09:09:10AM +1000, Dave Chinner wrote:
> > > On Mon, Sep 28, 2020 at 11:16:27AM -0400, Brian Foster wrote:
> > > > On Mon, Sep 28, 2020 at 09:08:23AM +1000, Dave Chinner wrote:
> > > > > On Tue, Sep 22, 2020 at 10:33:19PM -0700, Darrick J. Wong wrote:
> > > > > > +xfs_defer_relog(
> > > > > > +	struct xfs_trans		**tpp,
> > > > > > +	struct list_head		*dfops)
> > > > > > +{
> > > > > > +	struct xfs_defer_pending	*dfp;
> > > > > > +	xfs_lsn_t			threshold_lsn;
> > > > > > +
> > > > > > +	ASSERT((*tpp)->t_flags & XFS_TRANS_PERM_LOG_RES);
> > > > > > +
> > > > > > +	/*
> > > > > > +	 * Figure out where we need the tail to be in order to maintain the
> > > > > > +	 * minimum required free space in the log.
> > > > > > +	 */
> > > > > > +	threshold_lsn = xlog_grant_push_threshold((*tpp)->t_mountp->m_log, 0);
> > > > > > +	if (threshold_lsn == NULLCOMMITLSN)
> > > > > > +		return 0;
> > > > > 
> > > > > This smells of premature optimisation.
> > > > > 
> > > > > When we are in a tail-pushing scenario (i.e. any sort of
> > > > > sustained metadata workload) this will always return true, and so we
> > > > > will relog every intent that isn't in the current checkpoint every
> > > > > time this is called.  Under light load, we don't care if we add a
> > > > > little bit of relogging overhead as the CIL slowly flushes/pushes -
> > > > > it will have neglible impact on performance because there is little
> > > > > load on the journal.
> > > > > 
> > > > 
> > > > That seems like an overly broad and not necessarily correct assumption.
> > > > The threshold above is tail relative and hardcoded (with the zero param)
> > > > to the default AIL pushing threshold, which is 25% of the log. If we
> > > 
> > > The pushing threshold is 75% of the log space has been reserved by
> > > the grant head, not that there's only 25% of the log free. The
> > > reservation is typically much, much larger than the change that is
> > > actually written to the log, and so we can be tail pushing even when
> > > the log is largely empty and the CIL hasn't reached it's threshold
> > > for pushing.
> > > 
> > > Think about it - if we have a log with a 256kB log stripe unit,
> > > a itruncate reservation is somewhere around 1.5MB in size (700kB *
> > > 2), and if we have reflink/rmap enabled, it's closer to 6MB in size.
> > > Yet a typical modification will not use any of the 512kB*8 space
> > > reserved for the LSU (because CIL!) and might only use 10kB of new
> > > log space in the CIL because that's all that was newly dirtied.
> > > 
> > > That means we reserve 6MB of log space for each itruncate
> > > transaction in flight, (directory ops are almost as heavyweight) so
> > > it only takes 16 transactions in flight to consume 100MB of reserve
> > > grant head space. If we've got a log smaller than 130MB in this
> > > situation, we are into tail pushing -even if the physical log is
> > > empty-.
> > > 
> > > IOWs, tail pushing is not triggered by how much physical log space
> > > has been consumed - it is triggered by reservation pressure. And we
> > > can trivially drive the system into reservation pressure with
> > > concurrent workloads
> > > 
> > 
> > Yes, I understand. What I'm saying is that once we get past the
> > reservation head checks, there is a threshold lsn check that requires an
> > intent sit in that 25% range from the on-disk tail of the log for it to
> > be relogged. That _might_ unnecessarily relog in certain cases (i.e.
> > when the active range of the log is small), but it is not always the
> > case and I don't think it results in per CIL context relogging in
> > practice.
> 
> FWIW, I added a defer_relog stats counter and re-ran my nightly fstests
> runs (which at this point consist of):
> 
> A) upstream V5 with all features enabled
> B) same, but with 1k block size
> C) V4 filesystem
> D) V5 with DAX
> 
> With the first of the relogging patches enabled, we relog any time we
> find that an intent item is not in the current checkpoint.
> 
> A) defer_relog 26237
> B) defer_relog 81500
> C) defer_relog 15
> D) defer_relog 2660
> 
> With both enabled, we relog if the intent item is below the push
> threshold and the intent item isn't in the current checkpoint.
> 
> A) defer_relog 11345
> B) defer_relog 1
> C) defer_relog 945
> D) defer_relog 1805
> 

Those B and C numbers are definitely interesting. It's hard to say what
might be going on there since fstests can do so many crazy things
(including explicitly formatting filesystems with a version other than
what is specified in the config, IIRC).

> The runtime was about the same, though oddly the runtime has gone from
> 3.5h (last week) to 6h (this week) though I did just rebase fstests
> and... wow, there are some new tests that take forever to run.
> 
> From the ftrace data, the longest chains I see are from evil reflink
> tests that create a large extent, share it, punch out every other block
> of one of the copies, and then delete the other copy to stress CUI/EFI
> creation.
> 
> Those chains can run into the hundreds (~400 on the (A) config) though
> sadly they don't test the relogging mechanism since the removal is
> single-threaded, and the log doesn't checkpoint or hit the push
> thresholds.
> 

Ok, good to know. Any idea how large of a file generates that length of
chain?

Just some quick thoughts on the rest, since Dave should probably chime
in on some of the other bits..

> > > > assume sustained tail pushing conditions, a committed intent doesn't
> > > > trigger relog again until it falls within that threshold in the on-disk
> > > > log. The current CIL (nonblocking) size threshold is half that at 12.5%.
> > > 
> > > Or smaller. For small logs it is 12.5% of the log size. For larger
> > > logs, it caps at 32MB (8 * (256k << 4)).
> > > 
> > > > So relative to a given rolling transaction processing an intent chain,
> > > > there's a decent number of full CIL checkpoints that can occur before
> > > > any of those intents need to relog again (if at all), regardless of log
> > > > size.
> > > 
> > > Your logic is inverted because reservation pressure does not reflect
> > > CIL pressure.  Log space consumption and reservation pressure were
> > > decoupled by the in-memory relogging that the CIL enables, hence
> > > given a specific intent chain, the likely probability is that it
> > > will not span more than a single CIL context. i.e. it will complete
> > > rolling entirely within a single CIL commit.
> > > 
> > > As the log gets larger and the CIL increases in size, the
> > > probability that an intent chain completes within a single CIL
> > > commit goes up (e.g. 6MB reservation vs 32MB CIL push threshold).
> > > The lighter the load, the more likely it is that a transaction chain
> > > will complete within a single CIL checkpoint, even on small logs.
> > > 
> > 
> > Sure, I agree with that. That's not a major factor for intent chains
> > that pin the log tail long enough to cause deadlocks.
> > 
> > > > Without that logic, we're changing behavior to relog the entire chain in
> > > > every CIL checkpoint. That's a fairly significant change in behavior
> > > > with less predictable breakdown conditions. Do we know how long a single
> > > > chain is going to be?
> > > 
> > > Yes: the typical worst case chain length is defined by the
> > > transaction reservation log count. That is supposed to cover > %99
> > > of typical log space requirements for that operation.
> > > 
> > 
> > I don't think reservation log counts define worst case conditions for
> > intent chains. Darrick has documented cases in the commit logs that far
> > exceed those values. I'm assuming those are legitimate/observed
> > scenarios, but could be mistaken.
> 
> They're rare, but definitely the kinds of things (see above) that
> unprivileged userspace can create.
> 
> > > For any chain that is longer than this, we end up in the slow
> > > regrant path that reserves a unit of log space at a time, and these
> > > are the cases where the transaction must be careful about not
> > > pinning the tail of the log. i.e. long chains are exactly the case
> > > where we want to relog the intents in every new CIL context. This is
> > > no different to the way we relog the inode in -every transaction
> > > roll- whether it is modified or not so that we can guarantee it
> > > doesn't pin the tail of the log when we need to regrant space on
> > > commit....
> > > 
> > 
> > Yes, the relogging approach is the same. The difference is that in one
> > case we're logging a small, fixed size (inode) object repeatedly that is
> > already factored into the transaction reservation and in the other case,
> > we're logging a dynamic and non-deterministic number of (intent) objects
> > a non-deterministic number of times.
> > 
> > > > Do we know how many CPUs are concurrently
> > > > processing "long chain" operations?
> > > 
> > > Yes: as many as the grant head reservations will allow. That's
> > > always been the bound maximum transaction concurrency we can
> > > support.
> > > 
> > > > Do we know whether an external
> > > > workload is causing even more frequent checkpoints than governed by the
> > > > CIL size limit?
> > > 
> > > Irrelevant, because checkpoint frequency affects the relogging
> > > efficiency of -everything- that running transactions. i.e. the
> > > impact is not isolated to relogging a few small intents, it affects
> > > relogging of all metadata, from AG headers to btree blocks,
> > > directories and inodes. IOWs, the overhead of relogging intents
> > > will be lost in the overhead of completely relogging entire dirty
> > > metadata blocks that the transactions also touch, even though they
> > > may have only newly dirtied a few bytes in each buffer.
> 
> /me is confused, does this refer to transactions relogging dirty
> buffers because they dirtied something (aka xfs_trans_log_buf)?  Or does
> the checkpointing itself force relogging into the new checkpoint?
> 
> > > 
> > > > The examples in the commit logs in this series refer to
> > > > chains of hundreds of intents with hundreds of transaction rolls.
> > > 
> > > Truncating a file with 10 million extents will roll the transaction
> > > 10 million times. Having a long intent chain is no different from a
> > > "don't pin the tail of the log" perspective than truncating a
> > > badly fragmented file. Both need to relog their outstanding items
> > > that could pin the tail of the log as frequently as they commit...
> > > 
> > > This is a basic principle of permanent transactions: they must
> > > guarantee forwards progress by ensuring they can't pin the tail of
> > > the log at any time. That is, if you hold an item that *may* pin the
> > > tail of the log when you need to regrant log space, you need to move
> > > those items to the head of the log -before- you attempt to regrant
> > > log space. We do not do that with intents, and conditional relogging
> > > doesn't provide that guarantee, either.  Relogging the item once the
> > > item is no longer at the head of the log provides that forwards
> > > progress guarantee.
> > > 
> > 
> > It sounds like there's a correctness argument buried in here. If you
> > think the tail lsn threshold approach is not fundamentally correct, can
> > you please elaborate on that? I think fundamental correctness is far
> > more important at this early stage than the prospective impact of
> > cacheline contention caused by an implementation detail.
> 
> I've been wondering if this discussion could be summarized like this:
> 
> We don't want logged inode items to pin the tail on long running
> operations, so we tell everyone that if they're going to keep the inode
> locked across transaction rolls, they must relog the inode into the new
> transaction to keep it moving forward.  This is easy to spot and easy to
> think about, since we generally only operate on one inode at a time and
> the core is a fixed size.
> 
> For log intent items, the same general principle applies (anything that
> we want to hold onto across a roll must be relogged to avoid pinning the
> tail), but a transaction can have an arbitrary number of arbitrarily
> sized intent items, and the overhead of relogging (aka logging an intent
> done item and a new intent item) is much higher than relogging an inode.
> 
> Therefore, we add a new rule (A) that intent items must be relogged
> across checkpoints.  There's less overhead than doing it *every
> transaction* but this keeps the intents moving along.  This is still a
> bright line rule, albeit buried in the defer ops code, because we know
> exactly when it will trigger relogging.
> 

That all sounds about right to me.

> However, adding (B) the push threshold thing now makes it /harder/ to
> think about the intent item relogging because now we sort of have to
> merge two not-quite-the-same concepts (the push threshold of the actual
> log space usage vs. space usage according to the reservation grants)
> which just makes relogging less predictable.
> 

I'm not sure relogging is more or less predictable either way due to
external factors that can change behavior. The same intent chain might
relog many times if contending with 100 CPUs committing unrelated
transactions, doing fsyncs, etc. and not at all on an otherwise idle fs.
I'm also not sure how much that really matters since it's just a
characteristic of how the underlying log subsystem (delayed logging)
already works.

> From my POV, we don't currently do any relogging of deferred items, so
> applying either (A) or (B) seems like a benefit because at least we
> close off a theoretical deadlock vector.  (B) on its own makes me
> somewhat nervous because it sounds like the sort of thing that ends in
> "infrequently used code path explodes in subtle ways on $config that
> nobody tests", whereas (A) at least does it regularly enough that
> everyone will know its there.  OTOH, if checkpoints are small, that
> could result in a lot of unnecessary relogging, hence the attraction of
> (B) or (A+B).
> 

I think that last bit applies to both cases, TBH. As Dave mentioned
earlier, the common case is probably going to be that a chain is logged
entirely in a single checkpoint. I think the more important question is
whether we have sufficient tests to stress the underlying scheme.

E.g., if you guys prefer to just relog the entire chain (per
checkpoint), then I think we should at least make sure we have test
coverage for scenarios like long intent chains that result in excessive
relogging. Perhaps we could accomplish that with some creative
combination of error injection tags and variants of the existing tests
(i.e., set a tag to control relog frequency and run one or more of those
evil reflink workloads, or just combine the latter with an fsstress
workload, etc.). That would at least provide some tangible data on
questions like whether we're going to start blowing transaction
reservations or burning up CPUs processing huge intent chains.

> (I don't know anything about cacheline contention: I don't have quite
> enough fast hardware and perf-fu (or free time) to study that in depth.
> Since we're kind of lazy about locking around the grant head, it's
> probably fine to be even lazier and only read that stuff once per
> go-around, and only if we find an item that wasn't logged in the current
> checkpoint.  Anyone got numbers?)
> 
> > > I don't want to slap a band-aid over the problem in the name of
> > > "performance". Correctness comes first, then if we find a
> > > performance problem we'll address that without breaking correctness.
> > > 
> > ...
> > > > > However, when we are under heavy load the code will now be reading
> > > > > the grant head and log position accounting variables during every
> > > > > commit, hence greatly increasing the number and temporal
> > > > > distribution of accesses to the hotest cachelines in the log. We
> > > > > currently never access these cache lines during commit unless the
> > > > > unit reservation has run out and we have to regrant physical log
> > > > > space for the transaction to continue (i.e. we are into slow path
> > > > > commit code). IOWs, this is like causing far more than double the
> > > > > number of accesses to the grant head, the log tail, the
> > > > > last_sync_lsn, etc, all of which is unnecessary exactly when we care
> > > > > about minimising contention on the log space accounting variables...
> > > > > 
> > > > 
> > > > If we're under sustained tail pushing pressure, blocking transactions
> > > > have already hit this cacheline as well, FWIW.
> > > 
> > > No, tail pushing != blocking. If the AIL pushing is keeping up with
> > > the targets that are being set (as frequently happens with large
> > > logs and fast storage), then we rarely run out of log space and we
> > > do not block new reservations waiting for reservation space.
> > > 
> > 
> > Just pointing out that there's another prospective path for a
> > transaction to hit the cacheline. As you've already pointed out, it's
> > quite easy to reach reservation blocking conditions before the AIL is
> > even involved.
> > 
> > > > But if we're concerned about cacheline access in the commit path
> > > > specifically, I'm sure we could come up with any number of optimizations
> > > > to address that directly. E.g., we could sample the threshold
> > > > occasionally instead of on every roll, wait until the current
> > > > transaction has consumed all logres units (where we'll be hitting that
> > > > line anyways), shift state tracking over to xfsaild via setting a flag
> > > > on log items with an ->iop_relog() handler set that happen to pin the
> 
> I'm not sure what I think about the AIL reaching out to touch intent
> items that higher level code could also be accessing at the same time.
> Wouldn't that require more coordination?
> 

This already happens today. More traditional items (inodes, bufs, etc.)
mediate access through item specific locks, but the AIL does list
processing, flag updates, etc. outside of that. I don't think anything
prevents the AIL from setting an XFS_LI_AIL_PUSHED flag or some such
that the intent owner could use to identify an intent to relog. That
said, that was just a quick/handwavy thought wrt to avoiding l_tail_lsn
access and may or may not be a viable option.

Brian

> > > > tail, etc. etc. That said, I do think any such added complexity should
> > > > be justified with some accompanying profiling data (and I like the idea
> > > > of new stats counters mentioned in the separate mail).
> > > 
> > > Yes, there's lots of ways the pushing threshold could be done
> > > differently, but to focus on that misses the point that intents
> > > violate forwards progress guarantees rolling transactions are
> > > supposed to provide the log. I simply made the "access overhead"
> > > argument as a supporting point that this change is also likely to
> > > have unintended side effects...
> > > 
> > 
> > The argument stated was that the relog filtering was redundant logic. I
> > think that misinterprets the logic. If there's a correctness issue, then
> > I'd much prefer to focus on that..
> 
> I hope I didn't just stumble in and muddy things further. :)
> 
> --D
> 
> > Brian
> > 
> > > Cheers,
> > > 
> > > Dave.
> > > -- 
> > > Dave Chinner
> > > david@fromorbit.com
> > > 
> > 
>