@@ -6702,9 +6702,7 @@ nfsd4_lock(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
struct net *net = SVC_NET(rqstp);
struct nfsd_net *nn = net_generic(net, nfsd_net_id);
- dprintk("NFSD: nfsd4_lock: start=%Ld length=%Ld\n",
- (long long) lock->lk_offset,
- (long long) lock->lk_length);
+ trace_nfsd4_lock(rqstp, lock);
if (check_lock_length(lock->lk_offset, lock->lk_length))
return nfserr_inval;
@@ -7002,9 +7000,7 @@ nfsd4_locku(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
int err;
struct nfsd_net *nn = net_generic(SVC_NET(rqstp), nfsd_net_id);
- dprintk("NFSD: nfsd4_locku: start=%Ld length=%Ld\n",
- (long long) locku->lu_offset,
- (long long) locku->lu_length);
+ trace_nfsd4_locku(rqstp, locku);
if (check_lock_length(locku->lu_offset, locku->lu_length))
return nfserr_inval;
@@ -736,6 +736,54 @@ TRACE_EVENT(nfsd4_stateid_prep,
)
);
+TRACE_EVENT(nfsd4_lock,
+ TP_PROTO(
+ const struct svc_rqst *rqstp,
+ const struct nfsd4_lock *lock
+ ),
+ TP_ARGS(rqstp, lock),
+ TP_STRUCT__entry(
+ __field(u32, xid)
+ __field(unsigned long, type)
+ __field(bool, new)
+ __field(long long, start)
+ __field(long long, length)
+ ),
+ TP_fast_assign(
+ __entry->xid = be32_to_cpu(rqstp->rq_xid);
+ __entry->type = lock->lk_type;
+ __entry->new = lock->lk_is_new;
+ __entry->start = lock->lk_offset;
+ __entry->length = lock->lk_length;
+ ),
+ TP_printk("xid=0x%08x type=%s start=%Ld length=%Ld (%s)",
+ __entry->xid, show_nfs4_lock_type(__entry->type),
+ __entry->start, __entry->length,
+ __entry->new ? "new" : "not new"
+ )
+);
+
+TRACE_EVENT(nfsd4_locku,
+ TP_PROTO(
+ const struct svc_rqst *rqstp,
+ const struct nfsd4_locku *locku
+ ),
+ TP_ARGS(rqstp, locku),
+ TP_STRUCT__entry(
+ __field(u32, xid)
+ __field(long long, start)
+ __field(long long, length)
+ ),
+ TP_fast_assign(
+ __entry->xid = be32_to_cpu(rqstp->rq_xid);
+ __entry->start = locku->lu_offset;
+ __entry->length = locku->lu_length;
+ ),
+ TP_printk("xid=0x%08x start=%Ld length=%Ld",
+ __entry->xid, __entry->start, __entry->length
+ )
+);
+
TRACE_EVENT(nfsd4_delegreturn,
TP_PROTO(
const struct svc_rqst *rqstp,
@@ -495,3 +495,17 @@ TRACE_DEFINE_ENUM(NFS4_OPEN_CLAIM_DELEG_PREV_FH);
{ NFS4_SHARE_ACCESS_READ, "READ" }, \
{ NFS4_SHARE_ACCESS_WRITE, "WRITE" }, \
{ NFS4_SHARE_ACCESS_BOTH, "BOTH" })
+
+TRACE_DEFINE_ENUM(NFS4_UNLOCK_LT);
+TRACE_DEFINE_ENUM(NFS4_READ_LT);
+TRACE_DEFINE_ENUM(NFS4_WRITE_LT);
+TRACE_DEFINE_ENUM(NFS4_READW_LT);
+TRACE_DEFINE_ENUM(NFS4_WRITEW_LT);
+
+#define show_nfs4_lock_type(x) \
+ __print_symbolic(x, \
+ { NFS4_UNLOCK_LT, "UNLOCK" }, \
+ { NFS4_READ_LT, "READ" }, \
+ { NFS4_WRITE_LT, "WRITE" }, \
+ { NFS4_READW_LT, "READW" }, \
+ { NFS4_WRITEW_LT, "WRITEW" })
Record lock metadata. nfsd-1035 [003] 842.934033: nfsd4_lock: xid=0xf9651b20 type=WRITE start=2 length=1 (not new) nfsd-1035 [003] 842.934055: nfsd4_seqid_prep: seqid=0 client 5f68de0f:f04d8b18 stateid 00000014:00000001 nfsd-1035 [003] 842.934089: nfsd_file_put: hash=0x6ca inode=0xffff88873c0953f0 ref=4 flags=HASHED|REFERENCED may=WRITE|READ file=0xffff888708173400 nfsd-1035 [003] 842.934095: nfsd4_compoundstatus: xid=0xf9651b20 op=3/3 OP_LOCK status=OK nfsd-1035 [003] 842.937579: nfsd4_locku: xid=0xff651b20 start=0 length=1 nfsd-1035 [003] 842.937580: nfsd4_seqid_prep: seqid=0 client 5f68de0f:f04d8b18 stateid 00000014:00000002 nfsd-1035 [003] 842.937611: nfsd_file_put: hash=0x6ca inode=0xffff88873c0953f0 ref=3 flags=HASHED|REFERENCED may=WRITE|READ file=0xffff888708173400 nfsd-1035 [003] 842.937616: nfsd4_compoundstatus: xid=0xff651b20 op=3/3 OP_LOCKU status=OK Signed-off-by: Chuck Lever <chuck.lever@oracle.com> --- fs/nfsd/nfs4state.c | 8 ++----- fs/nfsd/trace.h | 48 ++++++++++++++++++++++++++++++++++++++++++++ include/trace/events/nfs.h | 14 +++++++++++++ 3 files changed, 64 insertions(+), 6 deletions(-)