Re: [PATCH v14 06/15] xfs: Add state machine tracepoints

Allison Henderson <allison.henderson@xxxxxxxxxx> · Tue, 5 Jan 2021 14:07:04 -0700

On 1/4/21 10:28 PM, Darrick J. Wong wrote:
On Fri, Dec 18, 2020 at 12:29:08AM -0700, Allison Henderson wrote:
This is a quick patch to add a new tracepoint: xfs_das_state_return.  We
use this to track when ever a new state is set or -EAGAIN is returned

Signed-off-by: Allison Henderson <allison.henderson@xxxxxxxxxx>
---
  fs/xfs/libxfs/xfs_attr.c        | 22 +++++++++++++++++++++-
  fs/xfs/libxfs/xfs_attr_remote.c |  1 +
  fs/xfs/xfs_trace.h              | 20 ++++++++++++++++++++
  3 files changed, 42 insertions(+), 1 deletion(-)

diff --git a/fs/xfs/libxfs/xfs_attr.c b/fs/xfs/libxfs/xfs_attr.c
index cd72512..8ed00bc 100644
--- a/fs/xfs/libxfs/xfs_attr.c
+++ b/fs/xfs/libxfs/xfs_attr.c
@@ -263,6 +263,7 @@ xfs_attr_set_shortform(
  	 * We're still in XFS_DAS_UNINIT state here.  We've converted the attr
  	 * fork to leaf format and will restart with the leaf add.
  	 */
+	trace_xfs_das_state_return(XFS_DAS_UNINIT);

It would help to record the inode number in the trace data.  When
someone encounters an xattr problem involving things like fsstress,
it'll be /much/ easier to disentangle who's doing what.
Sure, I can add that in


  	return -EAGAIN;
  }
  
@@ -409,9 +410,11 @@ xfs_attr_set_iter(
  		 * down into the node handling code below
  		 */
  		dac->flags |= XFS_DAC_DEFER_FINISH;
+		trace_xfs_das_state_return(dac->dela_state);
  		return -EAGAIN;
  	case 0:
  		dac->dela_state = XFS_DAS_FOUND_LBLK;
+		trace_xfs_das_state_return(dac->dela_state);
  		return -EAGAIN;
  	}
  	return error;
@@ -841,6 +844,7 @@ xfs_attr_leaf_addname(
  			return error;
  
  		dac->flags |= XFS_DAC_DEFER_FINISH;
+		trace_xfs_das_state_return(dac->dela_state);

Also, please consider capturing more info about /which/ of these
xfs_das_state_return tracepoints fired, either by introducing more
variants (e.g. xfs_attr_leaf_addname_das_return) or by feeding
__this_address into the trace "call" and printing it in the TP_printk
output (formatting string '%pS').

Each declared tracepoint /does/ have a permanent memory cost, so I would
think hard about trying #2...
Ok, how about a variant for each function then?  I think that would work 
out to 7 variants.

Allison

--D

  		return -EAGAIN;
  	}
  
@@ -874,6 +878,7 @@ xfs_attr_leaf_addname(
  	 * Commit the flag value change and start the next trans in series.
  	 */
  	dac->dela_state = XFS_DAS_FLIP_LFLAG;
+	trace_xfs_das_state_return(dac->dela_state);
  	return -EAGAIN;
  das_flip_flag:
  	/*
@@ -891,6 +896,8 @@ xfs_attr_leaf_addname(
  das_rm_lblk:
  	if (args->rmtblkno) {
  		error = __xfs_attr_rmtval_remove(dac);
+		if (error == -EAGAIN)
+			trace_xfs_das_state_return(dac->dela_state);
  		if (error)
  			return error;
  	}
@@ -1142,6 +1149,7 @@ xfs_attr_node_addname(
  			 * this point.
  			 */
  			dac->flags |= XFS_DAC_DEFER_FINISH;
+			trace_xfs_das_state_return(dac->dela_state);
  			return -EAGAIN;
  		}
  
@@ -1175,6 +1183,7 @@ xfs_attr_node_addname(
  	state = NULL;
  
  	dac->dela_state = XFS_DAS_FOUND_NBLK;
+	trace_xfs_das_state_return(dac->dela_state);
  	return -EAGAIN;
  das_found_nblk:
  
@@ -1202,6 +1211,7 @@ xfs_attr_node_addname(
  				return error;
  
  			dac->flags |= XFS_DAC_DEFER_FINISH;
+			trace_xfs_das_state_return(dac->dela_state);
  			return -EAGAIN;
  		}
  
@@ -1236,6 +1246,7 @@ xfs_attr_node_addname(
  	 * Commit the flag value change and start the next trans in series
  	 */
  	dac->dela_state = XFS_DAS_FLIP_NFLAG;
+	trace_xfs_das_state_return(dac->dela_state);
  	return -EAGAIN;
  das_flip_flag:
  	/*
@@ -1253,6 +1264,10 @@ xfs_attr_node_addname(
  das_rm_nblk:
  	if (args->rmtblkno) {
  		error = __xfs_attr_rmtval_remove(dac);
+
+		if (error == -EAGAIN)
+			trace_xfs_das_state_return(dac->dela_state);
+
  		if (error)
  			return error;
  	}
@@ -1396,6 +1411,8 @@ xfs_attr_node_remove_rmt (
  	 * May return -EAGAIN to request that the caller recall this function
  	 */
  	error = __xfs_attr_rmtval_remove(dac);
+	if (error == -EAGAIN)
+		trace_xfs_das_state_return(dac->dela_state);
  	if (error)
  		return error;
  
@@ -1514,6 +1531,7 @@ xfs_attr_node_removename_iter(
  
  			dac->flags |= XFS_DAC_DEFER_FINISH;
  			dac->dela_state = XFS_DAS_RM_SHRINK;
+			trace_xfs_das_state_return(dac->dela_state);
  			return -EAGAIN;
  		}
  
@@ -1532,8 +1550,10 @@ xfs_attr_node_removename_iter(
  		goto out;
  	}
  
-	if (error == -EAGAIN)
+	if (error == -EAGAIN) {
+		trace_xfs_das_state_return(dac->dela_state);
  		return error;
+	}
  out:
  	if (state)
  		xfs_da_state_free(state);
diff --git a/fs/xfs/libxfs/xfs_attr_remote.c b/fs/xfs/libxfs/xfs_attr_remote.c
index 6af86bf..4840de9 100644
--- a/fs/xfs/libxfs/xfs_attr_remote.c
+++ b/fs/xfs/libxfs/xfs_attr_remote.c
@@ -763,6 +763,7 @@ __xfs_attr_rmtval_remove(
  	 */
  	if (!done) {
  		dac->flags |= XFS_DAC_DEFER_FINISH;
+		trace_xfs_das_state_return(dac->dela_state);
  		return -EAGAIN;
  	}
  
diff --git a/fs/xfs/xfs_trace.h b/fs/xfs/xfs_trace.h
index 9074b8b..4f6939b4 100644
--- a/fs/xfs/xfs_trace.h
+++ b/fs/xfs/xfs_trace.h
@@ -3887,6 +3887,26 @@ DEFINE_EVENT(xfs_timestamp_range_class, name, \
  DEFINE_TIMESTAMP_RANGE_EVENT(xfs_inode_timestamp_range);
  DEFINE_TIMESTAMP_RANGE_EVENT(xfs_quota_expiry_range);
  
+
+DECLARE_EVENT_CLASS(xfs_das_state_class,
+	TP_PROTO(int das),
+	TP_ARGS(das),
+	TP_STRUCT__entry(
+		__field(int, das)
+	),
+	TP_fast_assign(
+		__entry->das = das;
+	),
+	TP_printk("state change %d",
+		  __entry->das)
+)
+
+#define DEFINE_DAS_STATE_EVENT(name) \
+DEFINE_EVENT(xfs_das_state_class, name, \
+	TP_PROTO(int das), \
+	TP_ARGS(das))
+DEFINE_DAS_STATE_EVENT(xfs_das_state_return);
+
  #endif /* _TRACE_XFS_H */
  
  #undef TRACE_INCLUDE_PATH
--
2.7.4







