diff mbox series

[RFC,11/21] NFSD: Add tracepoints to report NFSv4 session state

Message ID 160029259113.29208.736901808320139614.stgit@klimt.1015granger.net
State New
Headers show
Series NFSD operation monitoring tracepoints | expand

Commit Message

Chuck Lever Sept. 16, 2020, 9:43 p.m. UTC
These record the SEQ4 status flags and session slot and sequence
information for debugging purposes. Examples:

nfsd-1034  [001]   217.828352: nfsd4_create_session: xid=0x0059d52e client 5f611a66:37899067 sessionid=661a615f679089370300000000000000
nfsd-1034  [001]   217.830900: nfsd4_sequence:       xid=0x0159d52e sessionid=661a615f679089370300000000000000 seqid=1 slot=0/30 status=

 ...

nfsd-1034  [002]   627.709041: nfsd4_destroy_session: xid=0x54bed52e sessionid=661a615f679089370300000000000000

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    6 ++
 fs/nfsd/trace.h     |  163 +++++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 169 insertions(+)
diff mbox series

Patch

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 974b3303d2fc..f101202ed536 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3446,6 +3446,7 @@  nfsd4_create_session(struct svc_rqst *rqstp,
 	nfsd4_put_session(new);
 	if (old)
 		expire_client(old);
+	trace_nfsd4_create_session(rqstp, cr_ses);
 	return status;
 out_free_conn:
 	spin_unlock(&nn->client_lock);
@@ -3545,6 +3546,8 @@  __be32 nfsd4_bind_conn_to_session(struct svc_rqst *rqstp,
 	struct net *net = SVC_NET(rqstp);
 	struct nfsd_net *nn = net_generic(net, nfsd_net_id);
 
+	trace_nfsd4_bind_conn_to_session(rqstp, bcts);
+
 	if (!nfsd4_last_compound_op(rqstp))
 		return nfserr_not_only_op;
 	spin_lock(&nn->client_lock);
@@ -3591,6 +3594,8 @@  nfsd4_destroy_session(struct svc_rqst *r, struct nfsd4_compound_state *cstate,
 	struct net *net = SVC_NET(r);
 	struct nfsd_net *nn = net_generic(net, nfsd_net_id);
 
+	trace_nfsd4_destroy_session(r, sessionid);
+
 	status = nfserr_not_only_op;
 	if (nfsd4_compound_in_session(cstate, sessionid)) {
 		if (!nfsd4_last_compound_op(r))
@@ -3812,6 +3817,7 @@  nfsd4_sequence(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	}
 	if (!list_empty(&clp->cl_revoked))
 		seq->status_flags |= SEQ4_STATUS_RECALLABLE_STATE_REVOKED;
+	trace_nfsd4_sequence(rqstp, seq);
 out_no_session:
 	if (conn)
 		free_conn(conn);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index cbecefc3e112..dbbc45f22a80 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -911,6 +911,169 @@  TRACE_EVENT(nfsd_setattr_args,
 	)
 );
 
+TRACE_EVENT(nfsd4_create_session,
+	TP_PROTO(
+		const struct svc_rqst *rqstp,
+		const struct nfsd4_create_session *cr_ses
+	),
+	TP_ARGS(rqstp, cr_ses),
+	TP_STRUCT__entry(
+		__field(u32, xid)
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__array(unsigned char, sessionid, NFS4_MAX_SESSIONID_LEN)
+
+		__field(u32, fore_maxreqsz)
+		__field(u32, fore_maxrespsz)
+		__field(u32, fore_maxops)
+		__field(u32, fore_maxreps)
+
+		__field(u32, back_maxreqsz)
+		__field(u32, back_maxrespsz)
+		__field(u32, back_maxops)
+		__field(u32, back_maxreps)
+	),
+	TP_fast_assign(
+		__entry->xid = be32_to_cpu(rqstp->rq_xid);
+		__entry->cl_boot = cr_ses->clientid.cl_boot;
+		__entry->cl_id = cr_ses->clientid.cl_id;
+		memcpy(__entry->sessionid, &cr_ses->sessionid,
+		       NFS4_MAX_SESSIONID_LEN);
+		__entry->fore_maxreqsz = cr_ses->fore_channel.maxreq_sz;
+		__entry->fore_maxrespsz = cr_ses->fore_channel.maxresp_sz;
+		__entry->fore_maxops = cr_ses->fore_channel.maxops;
+		__entry->fore_maxreps = cr_ses->fore_channel.maxreqs;
+		__entry->back_maxreqsz = cr_ses->back_channel.maxreq_sz;
+		__entry->back_maxrespsz = cr_ses->back_channel.maxresp_sz;
+		__entry->back_maxops = cr_ses->back_channel.maxops;
+		__entry->back_maxreps = cr_ses->back_channel.maxreqs;
+	),
+	TP_printk("xid=0x%08x client=%08x:%08x sessionid=%s",
+		__entry->xid, __entry->cl_boot, __entry->cl_id,
+		__print_hex_str(__entry->sessionid, NFS4_MAX_SESSIONID_LEN)
+	)
+);
+
+/*
+ * from include/uapi/linux/nfs4.h
+ */
+TRACE_DEFINE_ENUM(NFS4_CDFC4_FORE);
+TRACE_DEFINE_ENUM(NFS4_CDFC4_BACK);
+TRACE_DEFINE_ENUM(NFS4_CDFC4_BOTH);
+TRACE_DEFINE_ENUM(NFS4_CDFC4_BACK_OR_BOTH);
+
+#define show_nfsd_bcts_dir(x) \
+	__print_symbolic(x, \
+		{ NFS4_CDFC4_FORE,		"FORE" }, \
+		{ NFS4_CDFC4_BACK,		"BACK" }, \
+		{ NFS4_CDFC4_BOTH,		"BOTH" }, \
+		{ NFS4_CDFC4_BACK_OR_BOTH,	"BACK_OR_BOTH" })
+
+TRACE_EVENT(nfsd4_bind_conn_to_session,
+	TP_PROTO(
+		const struct svc_rqst *rqstp,
+		const struct nfsd4_bind_conn_to_session *bcts
+	),
+	TP_ARGS(rqstp, bcts),
+	TP_STRUCT__entry(
+		__field(u32, xid)
+		__field(unsigned long, dir)
+		__array(unsigned char, sessionid, NFS4_MAX_SESSIONID_LEN)
+	),
+	TP_fast_assign(
+		__entry->xid = be32_to_cpu(rqstp->rq_xid);
+		__entry->dir = bcts->dir;
+		memcpy(__entry->sessionid, &bcts->sessionid,
+		       NFS4_MAX_SESSIONID_LEN);
+	),
+	TP_printk("xid=0x%08x sessionid=%s, dir=%s",
+		__entry->xid,
+		__print_hex_str(__entry->sessionid, NFS4_MAX_SESSIONID_LEN),
+		show_nfsd_bcts_dir(__entry->dir)
+	)
+);
+
+TRACE_EVENT(nfsd4_destroy_session,
+	TP_PROTO(
+		const struct svc_rqst *rqstp,
+		const struct nfs4_sessionid *sessionid
+	),
+	TP_ARGS(rqstp, sessionid),
+	TP_STRUCT__entry(
+		__field(u32, xid)
+		__array(unsigned char, sessionid, NFS4_MAX_SESSIONID_LEN)
+	),
+	TP_fast_assign(
+		__entry->xid = be32_to_cpu(rqstp->rq_xid);
+		memcpy(__entry->sessionid, sessionid, NFS4_MAX_SESSIONID_LEN);
+	),
+	TP_printk("xid=0x%08x sessionid=%s",
+		__entry->xid,
+		__print_hex_str(__entry->sessionid, NFS4_MAX_SESSIONID_LEN)
+	)
+);
+
+/*
+ * from include/uapi/linux/nfs4.h
+ */
+#define NFSD_SEQ4_FLAG_LIST \
+	nfsd_seq4_flag(CB_PATH_DOWN) \
+	nfsd_seq4_flag(CB_GSS_CONTEXTS_EXPIRING) \
+	nfsd_seq4_flag(CB_GSS_CONTEXTS_EXPIRED) \
+	nfsd_seq4_flag(EXPIRED_ALL_STATE_REVOKED) \
+	nfsd_seq4_flag(EXPIRED_SOME_STATE_REVOKED) \
+	nfsd_seq4_flag(ADMIN_STATE_REVOKED) \
+	nfsd_seq4_flag(RECALLABLE_STATE_REVOKED) \
+	nfsd_seq4_flag(LEASE_MOVED) \
+	nfsd_seq4_flag(RESTART_RECLAIM_NEEDED) \
+	nfsd_seq4_flag(CB_PATH_DOWN_SESSION) \
+	nfsd_seq4_flag_end(BACKCHANNEL_FAULT)
+
+#undef nfsd_seq4_flag
+#undef nfsd_seq4_flag_end
+#define nfsd_seq4_flag(x)	TRACE_DEFINE_ENUM(SEQ4_STATUS_##x);
+#define nfsd_seq4_flag_end(x)	TRACE_DEFINE_ENUM(SEQ4_STATUS_##x);
+
+NFSD_SEQ4_FLAG_LIST
+
+#undef nfsd_seq4_flag
+#undef nfsd_seq4_flag_end
+#define nfsd_seq4_flag(x)	{ SEQ4_STATUS_##x, #x },
+#define nfsd_seq4_flag_end(x)	{ SEQ4_STATUS_##x, #x }
+
+#define show_nfsd_seq4_status(x) __print_flags(x, "|", NFSD_SEQ4_FLAG_LIST)
+
+TRACE_EVENT(nfsd4_sequence,
+	TP_PROTO(
+		const struct svc_rqst *rqstp,
+		const struct nfsd4_sequence *seq
+	),
+	TP_ARGS(rqstp, seq),
+	TP_STRUCT__entry(
+		__field(u32, xid)
+		__field(u32, seqid)
+		__field(u32, slotid)
+		__field(u32, maxslots)
+		__field(unsigned long, flags)
+		__array(unsigned char, sessionid, NFS4_MAX_SESSIONID_LEN)
+	),
+	TP_fast_assign(
+		__entry->xid = be32_to_cpu(rqstp->rq_xid);
+		__entry->seqid = seq->seqid;
+		__entry->slotid = seq->slotid;
+		__entry->maxslots = seq->maxslots;
+		__entry->flags = seq->status_flags;
+		memcpy(__entry->sessionid, &seq->sessionid,
+		       NFS4_MAX_SESSIONID_LEN);
+	),
+	TP_printk("xid=0x%08x sessionid=%s slot=%u/%u seqid=%u flags=%s",
+		__entry->xid,
+		__print_hex_str(__entry->sessionid, NFS4_MAX_SESSIONID_LEN),
+		__entry->slotid, __entry->maxslots, __entry->seqid,
+		show_nfsd_seq4_status(__entry->flags)
+	)
+);
+
 TRACE_EVENT(nfsd4_setclientid,
 	TP_PROTO(
 		const struct svc_rqst *rqstp,