Re: [PATCH 01/10] NFSv4: Add tracepoints for debugging state management problems

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Wed, 2013-08-14 at 11:31 -0400, J. Bruce Fields wrote:
> On Tue, Aug 13, 2013 at 02:35:43PM -0400, Trond Myklebust wrote:
> > Set up basic tracepoints for debugging client id creation/destruction
> > and session creation/destruction.
> 
> Looks good to me. Dumb questions, just out of curiosity:
> 
> 	- Some of these are followed by dprintk's with similar
> 	  information.  Is it worth keeping those, or could they be
> 	  phased out at some point?

I'd like to phase out the dprintks over time.

> 	- Some of them are paired with an rpc_call_sync.  What do these
> 	  get you that wouldn't get out of wireshark with a suitable
> 	  filter?

The tracepoints give you the ability to do more sophisticated dynamic
tracing using systemtap or lttng.

The ringbuffer used by ftrace means that the overhead is relatively
small: you're not spamming the syslog all the time. Furthermore, ftrace
does support some simple filters. I'm therefore thinking that some
sysadmins might want to consider enabling some of these tracepoints
permanently on their systems in order to be able to post-mortem state
recovery issues following networking outages and/or server reboots.

Cheers
  Trond

> --b.
> 
> > 
> > Signed-off-by: Trond Myklebust <Trond.Myklebust@xxxxxxxxxx>
> > ---
> >  fs/nfs/Makefile    |   3 +-
> >  fs/nfs/nfs4proc.c  |   9 +++
> >  fs/nfs/nfs4trace.c |  10 +++
> >  fs/nfs/nfs4trace.h | 205 +++++++++++++++++++++++++++++++++++++++++++++++++++++
> >  4 files changed, 226 insertions(+), 1 deletion(-)
> >  create mode 100644 fs/nfs/nfs4trace.c
> >  create mode 100644 fs/nfs/nfs4trace.h
> > 
> > diff --git a/fs/nfs/Makefile b/fs/nfs/Makefile
> > index e0bb048..71ba4c2 100644
> > --- a/fs/nfs/Makefile
> > +++ b/fs/nfs/Makefile
> > @@ -21,7 +21,8 @@ nfsv3-$(CONFIG_NFS_V3_ACL) += nfs3acl.o
> >  obj-$(CONFIG_NFS_V4) += nfsv4.o
> >  nfsv4-y := nfs4proc.o nfs4xdr.o nfs4state.o nfs4renewd.o nfs4super.o nfs4file.o \
> >  	  delegation.o idmap.o callback.o callback_xdr.o callback_proc.o \
> > -	  nfs4namespace.o nfs4getroot.o nfs4client.o dns_resolve.o
> > +	  nfs4namespace.o nfs4getroot.o nfs4client.o dns_resolve.o \
> > +	  nfs4trace.c
> >  nfsv4-$(CONFIG_NFS_USE_LEGACY_DNS) += cache_lib.o
> >  nfsv4-$(CONFIG_SYSCTL)	+= nfs4sysctl.o
> >  nfsv4-$(CONFIG_NFS_V4_1)	+= nfs4session.o pnfs.o pnfs_dev.o
> > diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c
> > index a187f4d..3a55f24 100644
> > --- a/fs/nfs/nfs4proc.c
> > +++ b/fs/nfs/nfs4proc.c
> > @@ -66,6 +66,8 @@
> >  #include "nfs4session.h"
> >  #include "fscache.h"
> >  
> > +#include "nfs4trace.h"
> > +
> >  #define NFSDBG_FACILITY		NFSDBG_PROC
> >  
> >  #define NFS4_POLL_RETRY_MIN	(HZ/10)
> > @@ -4730,6 +4732,7 @@ int nfs4_proc_setclientid(struct nfs_client *clp, u32 program,
> >  		clp->cl_rpcclient->cl_auth->au_ops->au_name,
> >  		setclientid.sc_name_len, setclientid.sc_name);
> >  	status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_setclientid(clp, status);
> >  	dprintk("NFS reply setclientid: %d\n", status);
> >  	return status;
> >  }
> > @@ -4757,6 +4760,7 @@ int nfs4_proc_setclientid_confirm(struct nfs_client *clp,
> >  		clp->cl_rpcclient->cl_auth->au_ops->au_name,
> >  		clp->cl_clientid);
> >  	status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_setclientid_confirm(clp, status);
> >  	dprintk("NFS reply setclientid_confirm: %d\n", status);
> >  	return status;
> >  }
> > @@ -5887,6 +5891,7 @@ int nfs4_proc_bind_conn_to_session(struct nfs_client *clp, struct rpc_cred *cred
> >  	}
> >  
> >  	status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_bind_conn_to_session(clp, status);
> >  	if (status == 0) {
> >  		if (memcmp(res.session->sess_id.data,
> >  		    clp->cl_session->sess_id.data, NFS4_MAX_SESSIONID_LEN)) {
> > @@ -5972,6 +5977,7 @@ int nfs4_proc_exchange_id(struct nfs_client *clp, struct rpc_cred *cred)
> >  	}
> >  
> >  	status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_exchange_id(clp, status);
> >  	if (status == 0)
> >  		status = nfs4_check_cl_exchange_flags(res.flags);
> >  
> > @@ -6032,6 +6038,7 @@ static int _nfs4_proc_destroy_clientid(struct nfs_client *clp,
> >  	int status;
> >  
> >  	status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_destroy_clientid(clp, status);
> >  	if (status)
> >  		dprintk("NFS: Got error %d from the server %s on "
> >  			"DESTROY_CLIENTID.", status, clp->cl_hostname);
> > @@ -6295,6 +6302,7 @@ static int _nfs4_proc_create_session(struct nfs_client *clp,
> >  	args.flags = (SESSION4_PERSIST | SESSION4_BACK_CHAN);
> >  
> >  	status = rpc_call_sync(session->clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_create_session(clp, status);
> >  
> >  	if (!status) {
> >  		/* Verify the session's negotiated channel_attrs values */
> > @@ -6358,6 +6366,7 @@ int nfs4_proc_destroy_session(struct nfs4_session *session,
> >  		return status;
> >  
> >  	status = rpc_call_sync(session->clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT);
> > +	trace_nfs4_destroy_session(session->clp, status);
> >  
> >  	if (status)
> >  		dprintk("NFS: Got error %d from the server on DESTROY_SESSION. "
> > diff --git a/fs/nfs/nfs4trace.c b/fs/nfs/nfs4trace.c
> > new file mode 100644
> > index 0000000..3f02183
> > --- /dev/null
> > +++ b/fs/nfs/nfs4trace.c
> > @@ -0,0 +1,10 @@
> > +/*
> > + * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@xxxxxxxxxx>
> > + */
> > +#include <linux/nfs_fs.h>
> > +#include "nfs4_fs.h"
> > +#include "internal.h"
> > +
> > +#define CREATE_TRACE_POINTS
> > +#include "nfs4trace.h"
> > +
> > diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h
> > new file mode 100644
> > index 0000000..451954f
> > --- /dev/null
> > +++ b/fs/nfs/nfs4trace.h
> > @@ -0,0 +1,205 @@
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM nfs4
> > +
> > +#if !defined(_TRACE_NFS4_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_NFS4_H
> > +
> > +#include <linux/tracepoint.h>
> > +
> > +#define show_nfsv4_errors(error) __print_symbolic(error,		\
> > +		{ NFS4_OK,			"OK" },			\
> > +		/* Mapped by nfs4_stat_to_errno() */			\
> > +		{ -EPERM,			"EPERM" },		\
> > +		{ -ENOENT,			"ENOENT" },		\
> > +		{ -EIO,				"EIO" },		\
> > +		{ -ENXIO,			"ENXIO" },		\
> > +		{ -EACCES,			"EACCES" },		\
> > +		{ -EEXIST,			"EEXIST" },		\
> > +		{ -EXDEV,			"EXDEV" },		\
> > +		{ -ENOTDIR,			"ENOTDIR" },		\
> > +		{ -EISDIR,			"EISDIR" },		\
> > +		{ -EFBIG,			"EFBIG" },		\
> > +		{ -ENOSPC,			"ENOSPC" },		\
> > +		{ -EROFS,			"EROFS" },		\
> > +		{ -EMLINK,			"EMLINK" },		\
> > +		{ -ENAMETOOLONG,		"ENAMETOOLONG" },	\
> > +		{ -ENOTEMPTY,			"ENOTEMPTY" },		\
> > +		{ -EDQUOT,			"EDQUOT" },		\
> > +		{ -ESTALE,			"ESTALE" },		\
> > +		{ -EBADHANDLE,			"EBADHANDLE" },		\
> > +		{ -EBADCOOKIE,			"EBADCOOKIE" },		\
> > +		{ -ENOTSUPP,			"ENOTSUPP" },		\
> > +		{ -ETOOSMALL,			"ETOOSMALL" },		\
> > +		{ -EREMOTEIO,			"EREMOTEIO" },		\
> > +		{ -EBADTYPE,			"EBADTYPE" },		\
> > +		{ -EAGAIN,			"EAGAIN" },		\
> > +		{ -ELOOP,			"ELOOP" },		\
> > +		{ -EOPNOTSUPP,			"EOPNOTSUPP" },		\
> > +		{ -EDEADLK,			"EDEADLK" },		\
> > +		/* RPC errors */					\
> > +		{ -ENOMEM,			"ENOMEM" },		\
> > +		{ -EKEYEXPIRED,			"EKEYEXPIRED" },	\
> > +		{ -ETIMEDOUT,			"ETIMEDOUT" },		\
> > +		{ -ERESTARTSYS,			"ERESTARTSYS" },	\
> > +		{ -ECONNREFUSED,		"ECONNREFUSED" },	\
> > +		{ -ECONNRESET,			"ECONNRESET" },		\
> > +		{ -ENETUNREACH,			"ENETUNREACH" },	\
> > +		{ -EHOSTUNREACH,		"EHOSTUNREACH" },	\
> > +		{ -EHOSTDOWN,			"EHOSTDOWN" },		\
> > +		{ -EPIPE,			"EPIPE" },		\
> > +		{ -EPFNOSUPPORT,		"EPFNOSUPPORT" },	\
> > +		{ -EPROTONOSUPPORT,		"EPROTONOSUPPORT" },	\
> > +		/* NFSv4 native errors */				\
> > +		{ -NFS4ERR_ACCESS,		"ACCESS" },		\
> > +		{ -NFS4ERR_ATTRNOTSUPP,		"ATTRNOTSUPP" },	\
> > +		{ -NFS4ERR_ADMIN_REVOKED,	"ADMIN_REVOKED" },	\
> > +		{ -NFS4ERR_BACK_CHAN_BUSY,	"BACK_CHAN_BUSY" },	\
> > +		{ -NFS4ERR_BADCHAR,		"BADCHAR" },		\
> > +		{ -NFS4ERR_BADHANDLE,		"BADHANDLE" },		\
> > +		{ -NFS4ERR_BADIOMODE,		"BADIOMODE" },		\
> > +		{ -NFS4ERR_BADLAYOUT,		"BADLAYOUT" },		\
> > +		{ -NFS4ERR_BADNAME,		"BADNAME" },		\
> > +		{ -NFS4ERR_BADOWNER,		"BADOWNER" },		\
> > +		{ -NFS4ERR_BADSESSION,		"BADSESSION" },		\
> > +		{ -NFS4ERR_BADSLOT,		"BADSLOT" },		\
> > +		{ -NFS4ERR_BADTYPE,		"BADTYPE" },		\
> > +		{ -NFS4ERR_BADXDR,		"BADXDR" },		\
> > +		{ -NFS4ERR_BAD_COOKIE,		"BAD_COOKIE" },		\
> > +		{ -NFS4ERR_BAD_HIGH_SLOT,	"BAD_HIGH_SLOT" },	\
> > +		{ -NFS4ERR_BAD_RANGE,		"BAD_RANGE" },		\
> > +		{ -NFS4ERR_BAD_SEQID,		"BAD_SEQID" },		\
> > +		{ -NFS4ERR_BAD_SESSION_DIGEST,	"BAD_SESSION_DIGEST" },	\
> > +		{ -NFS4ERR_BAD_STATEID,		"BAD_STATEID" },	\
> > +		{ -NFS4ERR_CB_PATH_DOWN,	"CB_PATH_DOWN" },	\
> > +		{ -NFS4ERR_CLID_INUSE,		"CLID_INUSE" },		\
> > +		{ -NFS4ERR_CLIENTID_BUSY,	"CLIENTID_BUSY" },	\
> > +		{ -NFS4ERR_COMPLETE_ALREADY,	"COMPLETE_ALREADY" },	\
> > +		{ -NFS4ERR_CONN_NOT_BOUND_TO_SESSION,			\
> > +						"CONN_NOT_BOUND_TO_SESSION" }, \
> > +		{ -NFS4ERR_DEADLOCK,		"DEADLOCK" },		\
> > +		{ -NFS4ERR_DEADSESSION,		"DEAD_SESSION" },	\
> > +		{ -NFS4ERR_DELAY,		"DELAY" },		\
> > +		{ -NFS4ERR_DELEG_ALREADY_WANTED,			\
> > +						"DELEG_ALREADY_WANTED" }, \
> > +		{ -NFS4ERR_DELEG_REVOKED,	"DELEG_REVOKED" },	\
> > +		{ -NFS4ERR_DENIED,		"DENIED" },		\
> > +		{ -NFS4ERR_DIRDELEG_UNAVAIL,	"DIRDELEG_UNAVAIL" },	\
> > +		{ -NFS4ERR_DQUOT,		"DQUOT" },		\
> > +		{ -NFS4ERR_ENCR_ALG_UNSUPP,	"ENCR_ALG_UNSUPP" },	\
> > +		{ -NFS4ERR_EXIST,		"EXIST" },		\
> > +		{ -NFS4ERR_EXPIRED,		"EXPIRED" },		\
> > +		{ -NFS4ERR_FBIG,		"FBIG" },		\
> > +		{ -NFS4ERR_FHEXPIRED,		"FHEXPIRED" },		\
> > +		{ -NFS4ERR_FILE_OPEN,		"FILE_OPEN" },		\
> > +		{ -NFS4ERR_GRACE,		"GRACE" },		\
> > +		{ -NFS4ERR_HASH_ALG_UNSUPP,	"HASH_ALG_UNSUPP" },	\
> > +		{ -NFS4ERR_INVAL,		"INVAL" },		\
> > +		{ -NFS4ERR_IO,			"IO" },			\
> > +		{ -NFS4ERR_ISDIR,		"ISDIR" },		\
> > +		{ -NFS4ERR_LAYOUTTRYLATER,	"LAYOUTTRYLATER" },	\
> > +		{ -NFS4ERR_LAYOUTUNAVAILABLE,	"LAYOUTUNAVAILABLE" },	\
> > +		{ -NFS4ERR_LEASE_MOVED,		"LEASE_MOVED" },	\
> > +		{ -NFS4ERR_LOCKED,		"LOCKED" },		\
> > +		{ -NFS4ERR_LOCKS_HELD,		"LOCKS_HELD" },		\
> > +		{ -NFS4ERR_LOCK_RANGE,		"LOCK_RANGE" },		\
> > +		{ -NFS4ERR_MINOR_VERS_MISMATCH,	"MINOR_VERS_MISMATCH" }, \
> > +		{ -NFS4ERR_MLINK,		"MLINK" },		\
> > +		{ -NFS4ERR_MOVED,		"MOVED" },		\
> > +		{ -NFS4ERR_NAMETOOLONG,		"NAMETOOLONG" },	\
> > +		{ -NFS4ERR_NOENT,		"NOENT" },		\
> > +		{ -NFS4ERR_NOFILEHANDLE,	"NOFILEHANDLE" },	\
> > +		{ -NFS4ERR_NOMATCHING_LAYOUT,	"NOMATCHING_LAYOUT" },	\
> > +		{ -NFS4ERR_NOSPC,		"NOSPC" },		\
> > +		{ -NFS4ERR_NOTDIR,		"NOTDIR" },		\
> > +		{ -NFS4ERR_NOTEMPTY,		"NOTEMPTY" },		\
> > +		{ -NFS4ERR_NOTSUPP,		"NOTSUPP" },		\
> > +		{ -NFS4ERR_NOT_ONLY_OP,		"NOT_ONLY_OP" },	\
> > +		{ -NFS4ERR_NOT_SAME,		"NOT_SAME" },		\
> > +		{ -NFS4ERR_NO_GRACE,		"NO_GRACE" },		\
> > +		{ -NFS4ERR_NXIO,		"NXIO" },		\
> > +		{ -NFS4ERR_OLD_STATEID,		"OLD_STATEID" },	\
> > +		{ -NFS4ERR_OPENMODE,		"OPENMODE" },		\
> > +		{ -NFS4ERR_OP_ILLEGAL,		"OP_ILLEGAL" },		\
> > +		{ -NFS4ERR_OP_NOT_IN_SESSION,	"OP_NOT_IN_SESSION" },	\
> > +		{ -NFS4ERR_PERM,		"PERM" },		\
> > +		{ -NFS4ERR_PNFS_IO_HOLE,	"PNFS_IO_HOLE" },	\
> > +		{ -NFS4ERR_PNFS_NO_LAYOUT,	"PNFS_NO_LAYOUT" },	\
> > +		{ -NFS4ERR_RECALLCONFLICT,	"RECALLCONFLICT" },	\
> > +		{ -NFS4ERR_RECLAIM_BAD,		"RECLAIM_BAD" },	\
> > +		{ -NFS4ERR_RECLAIM_CONFLICT,	"RECLAIM_CONFLICT" },	\
> > +		{ -NFS4ERR_REJECT_DELEG,	"REJECT_DELEG" },	\
> > +		{ -NFS4ERR_REP_TOO_BIG,		"REP_TOO_BIG" },	\
> > +		{ -NFS4ERR_REP_TOO_BIG_TO_CACHE,			\
> > +						"REP_TOO_BIG_TO_CACHE" }, \
> > +		{ -NFS4ERR_REQ_TOO_BIG,		"REQ_TOO_BIG" },	\
> > +		{ -NFS4ERR_RESTOREFH,		"RESTOREFH" },		\
> > +		{ -NFS4ERR_RETRY_UNCACHED_REP,	"RETRY_UNCACHED_REP" },	\
> > +		{ -NFS4ERR_RETURNCONFLICT,	"RETURNCONFLICT" },	\
> > +		{ -NFS4ERR_ROFS,		"ROFS" },		\
> > +		{ -NFS4ERR_SAME,		"SAME" },		\
> > +		{ -NFS4ERR_SHARE_DENIED,	"SHARE_DENIED" },	\
> > +		{ -NFS4ERR_SEQUENCE_POS,	"SEQUENCE_POS" },	\
> > +		{ -NFS4ERR_SEQ_FALSE_RETRY,	"SEQ_FALSE_RETRY" },	\
> > +		{ -NFS4ERR_SEQ_MISORDERED,	"SEQ_MISORDERED" },	\
> > +		{ -NFS4ERR_SERVERFAULT,		"SERVERFAULT" },	\
> > +		{ -NFS4ERR_STALE,		"STALE" },		\
> > +		{ -NFS4ERR_STALE_CLIENTID,	"STALE_CLIENTID" },	\
> > +		{ -NFS4ERR_STALE_STATEID,	"STALE_STATEID" },	\
> > +		{ -NFS4ERR_SYMLINK,		"SYMLINK" },		\
> > +		{ -NFS4ERR_TOOSMALL,		"TOOSMALL" },		\
> > +		{ -NFS4ERR_TOO_MANY_OPS,	"TOO_MANY_OPS" },	\
> > +		{ -NFS4ERR_UNKNOWN_LAYOUTTYPE,	"UNKNOWN_LAYOUTTYPE" },	\
> > +		{ -NFS4ERR_UNSAFE_COMPOUND,	"UNSAFE_COMPOUND" },	\
> > +		{ -NFS4ERR_WRONGSEC,		"WRONGSEC" },		\
> > +		{ -NFS4ERR_WRONG_CRED,		"WRONG_CRED" },		\
> > +		{ -NFS4ERR_WRONG_TYPE,		"WRONG_TYPE" },		\
> > +		{ -NFS4ERR_XDEV,		"XDEV" })
> > +
> > +DECLARE_EVENT_CLASS(nfs4_clientid_event,
> > +		TP_PROTO(const struct nfs_client *clp,
> > +			int error),
> > +
> > +		TP_ARGS(clp, error),
> > +
> > +		TP_STRUCT__entry(
> > +			__string(dstaddr,
> > +				rpc_peeraddr2str(clp->cl_rpcclient,
> > +					RPC_DISPLAY_ADDR))
> > +			__field(int, error)
> > +		),
> > +
> > +		TP_fast_assign(
> > +			__entry->error = error;
> > +			__assign_str(dstaddr,
> > +				rpc_peeraddr2str(clp->cl_rpcclient,
> > +						RPC_DISPLAY_ADDR));
> > +		),
> > +
> > +		TP_printk("error=%d (%s), dstaddr=%s",
> > +			__entry->error,
> > +			show_nfsv4_errors(__entry->error),
> > +			__get_str(dstaddr)
> > +		)
> > +);
> > +#define DEFINE_NFS4_CLIENTID_EVENT(name)		\
> > +DEFINE_EVENT(nfs4_clientid_event, name,			\
> > +		TP_PROTO(const struct nfs_client *clp,	\
> > +			int error),			\
> > +		TP_ARGS(clp, error))
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_setclientid);
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_setclientid_confirm);
> > +#ifdef CONFIG_NFS_V4_1
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_exchange_id);
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_create_session);
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_destroy_session);
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_destroy_clientid);
> > +DEFINE_NFS4_CLIENTID_EVENT(nfs4_bind_conn_to_session);
> > +#endif /* CONFIG_NFS_V4_1 */
> > +
> > +#endif /* _TRACE_NFS4_H */
> > +
> > +#undef TRACE_INCLUDE_PATH
> > +#define TRACE_INCLUDE_PATH .
> > +#define TRACE_INCLUDE_FILE nfs4trace
> > +/* This part must be outside protection */
> > +#include <trace/define_trace.h>
> > -- 
> > 1.8.3.1
> > 
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> > the body of a message to majordomo@xxxxxxxxxxxxxxx
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to majordomo@xxxxxxxxxxxxxxx
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

-- 
Trond Myklebust
Linux NFS client maintainer

NetApp
Trond.Myklebust@xxxxxxxxxx
www.netapp.com
��.n��������+%������w��{.n�����{��w���jg��������ݢj����G�������j:+v���w�m������w�������h�����٥




[Index of Archives]     [Linux Filesystem Development]     [Linux USB Development]     [Linux Media Development]     [Video for Linux]     [Linux NILFS]     [Linux Audio Users]     [Yosemite Info]     [Linux SCSI]

  Powered by Linux