NFSv4.1: Add tracepoints for debugging slot table operations

Add tracepoints to nfs41_setup_sequence and nfs41_sequence_done to track session and slot table state changes. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>

NFSv4.1: Add tracepoints for debugging slot table operations
Add tracepoints to nfs41_setup_sequence and nfs41_sequence_done to track session and slot table state changes. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
Trond Myklebust
1 parent 1037e6eaa3
Showing 5 changed files with 154 additions and 0 deletions Side-by-side Diff
fs/nfs/callback_proc.c
fs/nfs/nfs4proc.c
fs/nfs/nfs4session.h
fs/nfs/nfs4trace.c
fs/nfs/nfs4trace.h
@@ -464,6 +464,7 @@
 	} else
 		res->csr_status = status;
  
+	trace_nfs4_cb_sequence(args, res, status);
 	dprintk("%s: exit with status = %d res->csr_status %d\n", __func__,
 		ntohl(status), ntohl(res->csr_status));
 	return status;
@@ -508,6 +508,7 @@
 		interrupted = true;
 	}
  
+	trace_nfs4_sequence_done(session, res);
 	/* Check the SEQUENCE operation status */
 	switch (res->sr_status) {
 	case 0:
@@ -660,6 +661,7 @@
 	 * set to 1 if an rpc level failure occurs.
 	 */
 	res->sr_status = 1;
+	trace_nfs4_setup_sequence(session, args);
 out_success:
 	rpc_call_start(task);
 	return 0;
@@ -117,6 +117,16 @@
 	return 0;
 }
  
+#ifdef CONFIG_CRC32
+/*
+ * nfs_session_id_hash - calculate the crc32 hash for the session id
+ * @session - pointer to session
+ */
+#define nfs_session_id_hash(sess_id) \
+	(~crc32_le(0xFFFFFFFF, &(sess_id)->data[0], sizeof((sess_id)->data)))
+#else
+#define nfs_session_id_hash(session) (0)
+#endif
 #else /* defined(CONFIG_NFS_V4_1) */
  
 static inline int nfs4_init_session(struct nfs_client *clp)
@@ -4,6 +4,8 @@
 #include <linux/nfs_fs.h>
 #include "nfs4_fs.h"
 #include "internal.h"
+#include "nfs4session.h"
+#include "callback.h"
  
 #define CREATE_TRACE_POINTS
 #include "nfs4trace.h"
@@ -240,6 +240,145 @@
 DEFINE_NFS4_CLIENTID_EVENT(nfs4_bind_conn_to_session);
 DEFINE_NFS4_CLIENTID_EVENT(nfs4_sequence);
 DEFINE_NFS4_CLIENTID_EVENT(nfs4_reclaim_complete);
+
+TRACE_EVENT(nfs4_setup_sequence,
+		TP_PROTO(
+			const struct nfs4_session *session,
+			const struct nfs4_sequence_args *args
+		),
+		TP_ARGS(session, args),
+
+		TP_STRUCT__entry(
+			__field(unsigned int, session)
+			__field(unsigned int, slot_nr)
+			__field(unsigned int, seq_nr)
+			__field(unsigned int, highest_used_slotid)
+		),
+
+		TP_fast_assign(
+			const struct nfs4_slot *sa_slot = args->sa_slot;
+			__entry->session = nfs_session_id_hash(&session->sess_id);
+			__entry->slot_nr = sa_slot->slot_nr;
+			__entry->seq_nr = sa_slot->seq_nr;
+			__entry->highest_used_slotid =
+					sa_slot->table->highest_used_slotid;
+		),
+		TP_printk(
+			"session=0x%08x slot_nr=%u seq_nr=%u "
+			"highest_used_slotid=%u",
+			__entry->session,
+			__entry->slot_nr,
+			__entry->seq_nr,
+			__entry->highest_used_slotid
+		)
+);
+
+#define show_nfs4_sequence_status_flags(status) \
+	__print_flags((unsigned long)status, "|", \
+		{ SEQ4_STATUS_CB_PATH_DOWN, "CB_PATH_DOWN" }, \
+		{ SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRING, \
+			"CB_GSS_CONTEXTS_EXPIRING" }, \
+		{ SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRED, \
+			"CB_GSS_CONTEXTS_EXPIRED" }, \
+		{ SEQ4_STATUS_EXPIRED_ALL_STATE_REVOKED, \
+			"EXPIRED_ALL_STATE_REVOKED" }, \
+		{ SEQ4_STATUS_EXPIRED_SOME_STATE_REVOKED, \
+			"EXPIRED_SOME_STATE_REVOKED" }, \
+		{ SEQ4_STATUS_ADMIN_STATE_REVOKED, \
+			"ADMIN_STATE_REVOKED" }, \
+		{ SEQ4_STATUS_RECALLABLE_STATE_REVOKED,	 \
+			"RECALLABLE_STATE_REVOKED" }, \
+		{ SEQ4_STATUS_LEASE_MOVED, "LEASE_MOVED" }, \
+		{ SEQ4_STATUS_RESTART_RECLAIM_NEEDED, \
+			"RESTART_RECLAIM_NEEDED" }, \
+		{ SEQ4_STATUS_CB_PATH_DOWN_SESSION, \
+			"CB_PATH_DOWN_SESSION" }, \
+		{ SEQ4_STATUS_BACKCHANNEL_FAULT, \
+			"BACKCHANNEL_FAULT" })
+
+TRACE_EVENT(nfs4_sequence_done,
+		TP_PROTO(
+			const struct nfs4_session *session,
+			const struct nfs4_sequence_res *res
+		),
+		TP_ARGS(session, res),
+
+		TP_STRUCT__entry(
+			__field(unsigned int, session)
+			__field(unsigned int, slot_nr)
+			__field(unsigned int, seq_nr)
+			__field(unsigned int, highest_slotid)
+			__field(unsigned int, target_highest_slotid)
+			__field(unsigned int, status_flags)
+			__field(int, error)
+		),
+
+		TP_fast_assign(
+			const struct nfs4_slot *sr_slot = res->sr_slot;
+			__entry->session = nfs_session_id_hash(&session->sess_id);
+			__entry->slot_nr = sr_slot->slot_nr;
+			__entry->seq_nr = sr_slot->seq_nr;
+			__entry->highest_slotid = res->sr_highest_slotid;
+			__entry->target_highest_slotid =
+					res->sr_target_highest_slotid;
+			__entry->error = res->sr_status;
+		),
+		TP_printk(
+			"error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
+			"highest_slotid=%u target_highest_slotid=%u "
+			"status_flags=%u (%s)",
+			__entry->error,
+			show_nfsv4_errors(__entry->error),
+			__entry->session,
+			__entry->slot_nr,
+			__entry->seq_nr,
+			__entry->highest_slotid,
+			__entry->target_highest_slotid,
+			__entry->status_flags,
+			show_nfs4_sequence_status_flags(__entry->status_flags)
+		)
+);
+
+struct cb_sequenceargs;
+struct cb_sequenceres;
+
+TRACE_EVENT(nfs4_cb_sequence,
+		TP_PROTO(
+			const struct cb_sequenceargs *args,
+			const struct cb_sequenceres *res,
+			__be32 status
+		),
+		TP_ARGS(args, res, status),
+
+		TP_STRUCT__entry(
+			__field(unsigned int, session)
+			__field(unsigned int, slot_nr)
+			__field(unsigned int, seq_nr)
+			__field(unsigned int, highest_slotid)
+			__field(unsigned int, cachethis)
+			__field(int, error)
+		),
+
+		TP_fast_assign(
+			__entry->session = nfs_session_id_hash(&args->csa_sessionid);
+			__entry->slot_nr = args->csa_slotid;
+			__entry->seq_nr = args->csa_sequenceid;
+			__entry->highest_slotid = args->csa_highestslotid;
+			__entry->cachethis = args->csa_cachethis;
+			__entry->error = -be32_to_cpu(status);
+		),
+
+		TP_printk(
+			"error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
+			"highest_slotid=%u",
+			__entry->error,
+			show_nfsv4_errors(__entry->error),
+			__entry->session,
+			__entry->slot_nr,
+			__entry->seq_nr,
+			__entry->highest_slotid
+		)
+);
 #endif /* CONFIG_NFS_V4_1 */
  
 DECLARE_EVENT_CLASS(nfs4_open_event,
...	...	@@ -464,6 +464,7 @@
464	464	} else
465	465	res->csr_status = status;
466	466
	467	+ trace_nfs4_cb_sequence(args, res, status);
467	468	dprintk("%s: exit with status = %d res->csr_status %d\n", __func__,
468	469	ntohl(status), ntohl(res->csr_status));
469	470	return status;
...	...	@@ -508,6 +508,7 @@
508	508	interrupted = true;
509	509	}
510	510
	511	+ trace_nfs4_sequence_done(session, res);
511	512	/* Check the SEQUENCE operation status */
512	513	switch (res->sr_status) {
513	514	case 0:
...	...	@@ -660,6 +661,7 @@
660	661	* set to 1 if an rpc level failure occurs.
661	662	*/
662	663	res->sr_status = 1;
	664	+ trace_nfs4_setup_sequence(session, args);
663	665	out_success:
664	666	rpc_call_start(task);
665	667	return 0;
...	...	@@ -117,6 +117,16 @@
117	117	return 0;
118	118	}
119	119
	120	+#ifdef CONFIG_CRC32
	121	+/*
	122	+ * nfs_session_id_hash - calculate the crc32 hash for the session id
	123	+ * @session - pointer to session
	124	+ */
	125	+#define nfs_session_id_hash(sess_id) \
	126	+ (~crc32_le(0xFFFFFFFF, &(sess_id)->data[0], sizeof((sess_id)->data)))
	127	+#else
	128	+#define nfs_session_id_hash(session) (0)
	129	+#endif
120	130	#else /* defined(CONFIG_NFS_V4_1) */
121	131
122	132	static inline int nfs4_init_session(struct nfs_client *clp)
...	...	@@ -4,6 +4,8 @@
4	4	#include <linux/nfs_fs.h>
5	5	#include "nfs4_fs.h"
6	6	#include "internal.h"
	7	+#include "nfs4session.h"
	8	+#include "callback.h"
7	9
8	10	#define CREATE_TRACE_POINTS
9	11	#include "nfs4trace.h"
...	...	@@ -240,6 +240,145 @@
240	240	DEFINE_NFS4_CLIENTID_EVENT(nfs4_bind_conn_to_session);
241	241	DEFINE_NFS4_CLIENTID_EVENT(nfs4_sequence);
242	242	DEFINE_NFS4_CLIENTID_EVENT(nfs4_reclaim_complete);
	243	+
	244	+TRACE_EVENT(nfs4_setup_sequence,
	245	+ TP_PROTO(
	246	+ const struct nfs4_session *session,
	247	+ const struct nfs4_sequence_args *args
	248	+ ),
	249	+ TP_ARGS(session, args),
	250	+
	251	+ TP_STRUCT__entry(
	252	+ __field(unsigned int, session)
	253	+ __field(unsigned int, slot_nr)
	254	+ __field(unsigned int, seq_nr)
	255	+ __field(unsigned int, highest_used_slotid)
	256	+ ),
	257	+
	258	+ TP_fast_assign(
	259	+ const struct nfs4_slot *sa_slot = args->sa_slot;
	260	+ __entry->session = nfs_session_id_hash(&session->sess_id);
	261	+ __entry->slot_nr = sa_slot->slot_nr;
	262	+ __entry->seq_nr = sa_slot->seq_nr;
	263	+ __entry->highest_used_slotid =
	264	+ sa_slot->table->highest_used_slotid;
	265	+ ),
	266	+ TP_printk(
	267	+ "session=0x%08x slot_nr=%u seq_nr=%u "
	268	+ "highest_used_slotid=%u",
	269	+ __entry->session,
	270	+ __entry->slot_nr,
	271	+ __entry->seq_nr,
	272	+ __entry->highest_used_slotid
	273	+ )
	274	+);
	275	+
	276	+#define show_nfs4_sequence_status_flags(status) \
	277	+ __print_flags((unsigned long)status, "\|", \
	278	+ { SEQ4_STATUS_CB_PATH_DOWN, "CB_PATH_DOWN" }, \
	279	+ { SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRING, \
	280	+ "CB_GSS_CONTEXTS_EXPIRING" }, \
	281	+ { SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRED, \
	282	+ "CB_GSS_CONTEXTS_EXPIRED" }, \
	283	+ { SEQ4_STATUS_EXPIRED_ALL_STATE_REVOKED, \
	284	+ "EXPIRED_ALL_STATE_REVOKED" }, \
	285	+ { SEQ4_STATUS_EXPIRED_SOME_STATE_REVOKED, \
	286	+ "EXPIRED_SOME_STATE_REVOKED" }, \
	287	+ { SEQ4_STATUS_ADMIN_STATE_REVOKED, \
	288	+ "ADMIN_STATE_REVOKED" }, \
	289	+ { SEQ4_STATUS_RECALLABLE_STATE_REVOKED, \
	290	+ "RECALLABLE_STATE_REVOKED" }, \
	291	+ { SEQ4_STATUS_LEASE_MOVED, "LEASE_MOVED" }, \
	292	+ { SEQ4_STATUS_RESTART_RECLAIM_NEEDED, \
	293	+ "RESTART_RECLAIM_NEEDED" }, \
	294	+ { SEQ4_STATUS_CB_PATH_DOWN_SESSION, \
	295	+ "CB_PATH_DOWN_SESSION" }, \
	296	+ { SEQ4_STATUS_BACKCHANNEL_FAULT, \
	297	+ "BACKCHANNEL_FAULT" })
	298	+
	299	+TRACE_EVENT(nfs4_sequence_done,
	300	+ TP_PROTO(
	301	+ const struct nfs4_session *session,
	302	+ const struct nfs4_sequence_res *res
	303	+ ),
	304	+ TP_ARGS(session, res),
	305	+
	306	+ TP_STRUCT__entry(
	307	+ __field(unsigned int, session)
	308	+ __field(unsigned int, slot_nr)
	309	+ __field(unsigned int, seq_nr)
	310	+ __field(unsigned int, highest_slotid)
	311	+ __field(unsigned int, target_highest_slotid)
	312	+ __field(unsigned int, status_flags)
	313	+ __field(int, error)
	314	+ ),
	315	+
	316	+ TP_fast_assign(
	317	+ const struct nfs4_slot *sr_slot = res->sr_slot;
	318	+ __entry->session = nfs_session_id_hash(&session->sess_id);
	319	+ __entry->slot_nr = sr_slot->slot_nr;
	320	+ __entry->seq_nr = sr_slot->seq_nr;
	321	+ __entry->highest_slotid = res->sr_highest_slotid;
	322	+ __entry->target_highest_slotid =
	323	+ res->sr_target_highest_slotid;
	324	+ __entry->error = res->sr_status;
	325	+ ),
	326	+ TP_printk(
	327	+ "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
	328	+ "highest_slotid=%u target_highest_slotid=%u "
	329	+ "status_flags=%u (%s)",
	330	+ __entry->error,
	331	+ show_nfsv4_errors(__entry->error),
	332	+ __entry->session,
	333	+ __entry->slot_nr,
	334	+ __entry->seq_nr,
	335	+ __entry->highest_slotid,
	336	+ __entry->target_highest_slotid,
	337	+ __entry->status_flags,
	338	+ show_nfs4_sequence_status_flags(__entry->status_flags)
	339	+ )
	340	+);
	341	+
	342	+struct cb_sequenceargs;
	343	+struct cb_sequenceres;
	344	+
	345	+TRACE_EVENT(nfs4_cb_sequence,
	346	+ TP_PROTO(
	347	+ const struct cb_sequenceargs *args,
	348	+ const struct cb_sequenceres *res,
	349	+ __be32 status
	350	+ ),
	351	+ TP_ARGS(args, res, status),
	352	+
	353	+ TP_STRUCT__entry(
	354	+ __field(unsigned int, session)
	355	+ __field(unsigned int, slot_nr)
	356	+ __field(unsigned int, seq_nr)
	357	+ __field(unsigned int, highest_slotid)
	358	+ __field(unsigned int, cachethis)
	359	+ __field(int, error)
	360	+ ),
	361	+
	362	+ TP_fast_assign(
	363	+ __entry->session = nfs_session_id_hash(&args->csa_sessionid);
	364	+ __entry->slot_nr = args->csa_slotid;
	365	+ __entry->seq_nr = args->csa_sequenceid;
	366	+ __entry->highest_slotid = args->csa_highestslotid;
	367	+ __entry->cachethis = args->csa_cachethis;
	368	+ __entry->error = -be32_to_cpu(status);
	369	+ ),
	370	+
	371	+ TP_printk(
	372	+ "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u "
	373	+ "highest_slotid=%u",
	374	+ __entry->error,
	375	+ show_nfsv4_errors(__entry->error),
	376	+ __entry->session,
	377	+ __entry->slot_nr,
	378	+ __entry->seq_nr,
	379	+ __entry->highest_slotid
	380	+ )
	381	+);
243	382	#endif /* CONFIG_NFS_V4_1 */
244	383
245	384	DECLARE_EVENT_CLASS(nfs4_open_event,