[PATCH v2 17/27] NFSD: Add a tracepoint to report the current filehandle

[Chuck Lever <chuck.lever@xxxxxxxxxx>]

Expose the "current_fh", which is an implicit argument in many NFSv4
operations. I've tried to insert this tracepoint at each place that
can change the current filehandle. Typically:

nfsd-1034  [000]   165.214516: nfsd_compound:        xid=0x012e9610 opcnt=3
nfsd-1034  [000]   165.214518: nfsd_fh_current:      xid=0x012e9610 fh_hash=0x90351828 name=Makefile
nfsd-1034  [000]   165.214581: nfsd_compound_status: xid=0x012e9610 op=1/3 OP_PUTFH status=OK

Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
---
 fs/nfsd/nfs4proc.c |   22 ++++++++++++++++++----
 fs/nfsd/trace.h    |   31 +++++++++++++++++++++++++++++++
 2 files changed, 49 insertions(+), 4 deletions(-)

diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
index 17a627f97766..e378aa91ba46 100644
--- a/fs/nfsd/nfs4proc.c
+++ b/fs/nfsd/nfs4proc.c
@@ -467,6 +467,7 @@ nfsd4_open(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	}
 	nfsd4_cleanup_open_state(cstate, open);
 	nfsd4_bump_seqid(cstate, status);
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 	return status;
 }
 
@@ -517,6 +518,7 @@ nfsd4_putfh(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 		ret = 0;
 	}
 #endif
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 	return ret;
 }
 
@@ -528,6 +530,7 @@ nfsd4_putrootfh(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 
 	fh_put(&cstate->current_fh);
 	status = exp_pseudoroot(rqstp, &cstate->current_fh);
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 	return status;
 }
 
@@ -543,6 +546,7 @@ nfsd4_restorefh(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 		memcpy(&cstate->current_stateid, &cstate->save_stateid, sizeof(stateid_t));
 		SET_CSTATE_FLAG(cstate, CURRENT_STATE_ID_FLAG);
 	}
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 	return nfs_ok;
 }
 
@@ -687,6 +691,7 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	fh_unlock(&cstate->current_fh);
 	set_change_info(&create->cr_cinfo, &cstate->current_fh);
 	fh_dup2(&cstate->current_fh, &resfh);
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 out:
 	fh_put(&resfh);
 out_umask:
@@ -751,16 +756,24 @@ static __be32
 nfsd4_lookupp(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	      union nfsd4_op_u *u)
 {
-	return nfsd4_do_lookupp(rqstp, &cstate->current_fh);
+	__be32 status;
+
+	status = nfsd4_do_lookupp(rqstp, &cstate->current_fh);
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
+	return status;
 }
 
 static __be32
 nfsd4_lookup(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	     union nfsd4_op_u *u)
 {
-	return nfsd_lookup(rqstp, &cstate->current_fh,
-			   u->lookup.lo_name, u->lookup.lo_len,
-			   &cstate->current_fh);
+	__be32 status;
+
+	status = nfsd_lookup(rqstp, &cstate->current_fh,
+			     u->lookup.lo_name, u->lookup.lo_len,
+			     &cstate->current_fh);
+	trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
+	return status;
 }
 
 static __be32
@@ -928,6 +941,7 @@ nfsd4_secinfo_no_name(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstat
 		err = nfsd4_do_lookupp(rqstp, &cstate->current_fh);
 		if (err)
 			return err;
+		trace_nfsd4_fh_current(rqstp, &cstate->current_fh);
 		break;
 	default:
 		return nfserr_inval;
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 6f707e9f3786..c2e72b880e6a 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -533,6 +533,37 @@ TRACE_EVENT(nfsd4_compoundstatus,
 	)
 )
 
+TRACE_EVENT(nfsd4_fh_current,
+	TP_PROTO(
+		const struct svc_rqst *rqstp,
+		const struct svc_fh *fhp
+	),
+	TP_ARGS(rqstp, fhp),
+	TP_STRUCT__entry(
+		__field(u32, xid)
+		__field(u32, fh_hash)
+		__dynamic_array(unsigned char, name,
+				fhp->fh_dentry ?
+				fhp->fh_dentry->d_name.len + 1 : 0)
+	),
+	TP_fast_assign(
+		const struct dentry *dentry = fhp->fh_dentry;
+
+		__entry->xid = be32_to_cpu(rqstp->rq_xid);
+		__entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle);
+		if (dentry) {
+			memcpy(__get_str(name), dentry->d_name.name,
+			       dentry->d_name.len);
+			__get_str(name)[dentry->d_name.len] = '\0';
+		} else {
+			__get_str(name)[0] = '\0';
+		}
+	),
+	TP_printk("xid=0x%08x fh_hash=0x%08x name=%s",
+		__entry->xid, __entry->fh_hash, __get_str(name)
+	)
+);
+
 #include "state.h"
 #include "filecache.h"
 #include "vfs.h"