[PATCH 3/5] xfs: report the error that made deferred work shut down the fs

[Javier Tia <javier@peridio.com>]

When xfs_defer_finish_one() fails with anything other than -EAGAIN,
xfs_defer_finish_noroll() shuts the filesystem down from a generic
out_shutdown: label.  SHUTDOWN_CORRUPT_INCORE makes that surface as
"Corruption of in-memory data (0x8) detected at
xfs_defer_finish_noroll+0x29a/0x4b0 (fs/xfs/libxfs/xfs_defer.c:721)",
naming neither the errno nor the deferred op that produced it.  Any
error from any deferred work item lands on that one line, so the report
is equally consistent with a transient -ENOSPC, an -EIO on a metadata
buffer, or genuine in-core corruption, and there is no way to tell
which from the log.

trace_xfs_defer_finish_error() records the errno, but it is called
after xfs_force_shutdown().  With fs.xfs.panic_mask carrying
XFS_PTAG_SHUTDOWN_CORRUPT (16), the first shutdown reaches
_xfs_alert_tag(), which BUGs, so the tracepoint does not fire for it.
Later racers do reach it, because xfs_do_force_shutdown() returns early
once xfs_set_shutdown() has fired, but by then the errno belongs to a
secondary failure.  The informative one is lost, and that is the
configuration used to capture a crash dump: recovering the errno from a
vmcore means an ORC unwind of the xfs_defer_finish_noroll frame to read
the callee-saved %rbp that happens to still hold the value.

Move the tracepoint ahead of xfs_force_shutdown() so it is reachable
for the first failure, and report the same information through the log,
because the systems that hit this do not have tracing armed in advance.
Report t_blk_res as well as the errno: how much of the reservation is
left separates a transaction that ran out of blocks from one that never
came close, which is the difference between suspecting whichever
xfs_*_space_res() fed it and moving the search to the allocator or to
the buffer that returned the error.  It cannot say more than that,
since xfs_trans_dup() hands each rolled transaction the unused
remainder, so a small value is also what a correctly sized reservation
looks like several rolls in.  t_blk_res_used is not worth printing
beside it: the new transaction starts at zero because xfs_trans_dup()
allocates it with kmem_cache_zalloc(), so it reads zero on the roll
paths and counts only the current segment on the others.

Take the op name in a local read before the call rather than from dfp
afterwards.  dfp is freed once its work list drains, so the name has to
be captured while the item is known live, and it has to outlive the
item to be available at out_shutdown for the paths that do not come
from xfs_defer_finish_one() at all.  dfp_ops points into a static const
table, so the string itself outlives everything.

Clear the attribution once an item finishes.  Three of the four paths to
out_shutdown - the create_intents failure and both trans_roll failures -
are reached at the top of a later loop iteration, before any item has
been picked, so a name left over from an item that already succeeded
would blame it for a log commit that failed afterwards.  That is worse
than the generic message this replaces, because it invents a lead where
there was none.  An -EAGAIN item keeps its name, since the roll that
follows is part of completing it.

Skip the alert once the filesystem is already down.  Only the first
failure is informative; everything after it is a consequence, and
xfs_do_force_shutdown() suppresses its own message for exactly that
reason.  Testing xfs_is_shutdown() rather than rate-limiting keeps the
first report unconditionally and drops the ones that follow, instead of
a token bucket that could spend itself on another mount's failures and
discard the one that mattered.

Signed-off-by: Javier Tia <floss@jetm.me>
---
 fs/xfs/libxfs/xfs_defer.c | 15 ++++++++++++++-
 1 file changed, 14 insertions(+), 1 deletion(-)

diff --git a/fs/xfs/libxfs/xfs_defer.c b/fs/xfs/libxfs/xfs_defer.c
index 75f0d37914d5..bbf2f4ca3c2e 100644
--- a/fs/xfs/libxfs/xfs_defer.c
+++ b/fs/xfs/libxfs/xfs_defer.c
@@ -656,6 +656,7 @@ xfs_defer_finish_noroll(
 	struct xfs_trans		**tp)
 {
 	struct xfs_defer_pending	*dfp = NULL;
+	const char			*what = "deferred";
 	int				error = 0;
 	LIST_HEAD(dop_pending);
 	LIST_HEAD(dop_paused);
@@ -705,9 +706,17 @@ xfs_defer_finish_noroll(
 				struct xfs_defer_pending, dfp_list);
 		if (!dfp)
 			break;
+		what = dfp->dfp_ops->name;
 		error = xfs_defer_finish_one(*tp, dfp);
 		if (error && error != -EAGAIN)
 			goto out_shutdown;
+		/*
+		 * A finished item is no longer a candidate for a later
+		 * failure.  An -EAGAIN one is not finished, so it keeps the
+		 * attribution across the roll that completes it.
+		 */
+		if (!error)
+			what = "deferred";
 	}
 
 	/* Requeue the paused items in the outgoing transaction. */
@@ -719,8 +728,12 @@ xfs_defer_finish_noroll(
 out_shutdown:
 	list_splice_tail_init(&dop_paused, &dop_pending);
 	xfs_defer_trans_abort(*tp, &dop_pending);
-	xfs_force_shutdown((*tp)->t_mountp, SHUTDOWN_CORRUPT_INCORE);
 	trace_xfs_defer_finish_error(*tp, error);
+	if (!xfs_is_shutdown((*tp)->t_mountp))
+		xfs_alert((*tp)->t_mountp,
+			  "%s work failed, error %d, %u blocks reserved",
+			  what, error, (*tp)->t_blk_res);
+	xfs_force_shutdown((*tp)->t_mountp, SHUTDOWN_CORRUPT_INCORE);
 	xfs_defer_cancel_list((*tp)->t_mountp, &dop_pending);
 	xfs_defer_cancel(*tp);
 	return error;
-- 
Javier Tia