diff mbox series

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

Message ID 20201218072917.16805-7-allison.henderson@oracle.com (mailing list archive)
State Superseded
Headers show
Series xfs: Delayed Attributes | expand

Commit Message

Allison Henderson Dec. 18, 2020, 7:29 a.m. UTC
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@oracle.com>
---
 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(-)

Comments

Chandan Babu R Jan. 5, 2021, 4:50 a.m. UTC | #1
On Fri, 18 Dec 2020 00:29:08 -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
>

Looks good to me.

Reviewed-by: Chandan Babu R <chandanrlinux@gmail.com>

> Signed-off-by: Allison Henderson <allison.henderson@oracle.com>
> ---
>  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);
>  	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);
>  		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
>
Darrick J. Wong Jan. 5, 2021, 5:28 a.m. UTC | #2
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@oracle.com>
> ---
>  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.

>  	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...

--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
>
Allison Henderson Jan. 5, 2021, 9:06 p.m. UTC | #3
On 1/4/21 9:50 PM, Chandan Babu R wrote:
> On Fri, 18 Dec 2020 00:29:08 -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
>>
> 
> Looks good to me.
> 
> Reviewed-by: Chandan Babu R <chandanrlinux@gmail.com>
Ok, thank you!

Allison
> 
>> Signed-off-by: Allison Henderson <allison.henderson@oracle.com>
>> ---
>>   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);
>>   	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);
>>   		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
>>
> 
>
Allison Henderson Jan. 5, 2021, 9:07 p.m. UTC | #4
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@oracle.com>
>> ---
>>   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
>>
diff mbox series

Patch

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);
 	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);
 		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