nfsd: Add I/O trace points in the NFSv4 write path

NFSv4 write compound processing invokes nfsd_vfs_write directly. The
trace points currently in nfsd_write are not effective for NFSv4
writes.

Move the trace points into the shared nfsd_vfs_write() helper.

After the I/O, we also want to record any local I/O error that
might have occurred, and the total count of bytes that were actually
moved (rather than the requested number).

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>

3 files changed, 50 insertions, 13 deletions

diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
index 792fbb851046..b773b314f599 100644
--- a/fs/nfsd/nfs4proc.c
+++ b/fs/nfsd/nfs4proc.c
@@ -1001,6 +1001,9 @@ nfsd4_write(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
         if (write->wr_offset >= OFFSET_MAX)
                 return nfserr_inval;
 
+        cnt = write->wr_buflen;
+        trace_nfsd_write_start(rqstp, &cstate->current_fh,
+                               write->wr_offset, cnt);
         status = nfs4_preprocess_stateid_op(rqstp, cstate, &cstate->current_fh,
                                                 stateid, WR_STATE, &filp, NULL);
         if (status) {
@@ -1008,7 +1011,6 @@ nfsd4_write(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
                 return status;
         }
 
-        cnt = write->wr_buflen;
         write->wr_how_written = write->wr_stable_how;
         gen_boot_verifier(&write->wr_verifier, SVC_NET(rqstp));
 
@@ -1021,7 +1023,8 @@ nfsd4_write(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
         fput(filp);
 
         write->wr_bytes_written = cnt;
-
+        trace_nfsd_write_done(rqstp, &cstate->current_fh,
+                              write->wr_offset, cnt);
         return status;
 }
 
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 30e04852a4e0..653e9ee754d2 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -51,6 +51,39 @@ DEFINE_NFSD_IO_EVENT(write_opened);
 DEFINE_NFSD_IO_EVENT(write_io_done);
 DEFINE_NFSD_IO_EVENT(write_done);
 
+DECLARE_EVENT_CLASS(nfsd_err_class,
+        TP_PROTO(struct svc_rqst *rqstp,
+                 struct svc_fh  *fhp,
+                 loff_t         offset,
+                 int            status),
+        TP_ARGS(rqstp, fhp, offset, status),
+        TP_STRUCT__entry(
+                __field(u32, xid)
+                __field(u32, fh_hash)
+                __field(loff_t, offset)
+                __field(int, status)
+        ),
+        TP_fast_assign(
+                __entry->xid = be32_to_cpu(rqstp->rq_xid);
+                __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle);
+                __entry->offset = offset;
+                __entry->status = status;
+        ),
+        TP_printk("xid=0x%08x fh_hash=0x%08x offset=%lld status=%d",
+                  __entry->xid, __entry->fh_hash,
+                  __entry->offset, __entry->status)
+)
+
+#define DEFINE_NFSD_ERR_EVENT(name)             \
+DEFINE_EVENT(nfsd_err_class, nfsd_##name,       \
+        TP_PROTO(struct svc_rqst *rqstp,        \
+                 struct svc_fh  *fhp,           \
+                 loff_t         offset,         \
+                 int            len),           \
+        TP_ARGS(rqstp, fhp, offset, len))
+
+DEFINE_NFSD_ERR_EVENT(write_err);
+
 #include "state.h"
 
 DECLARE_EVENT_CLASS(nfsd_stateid_class,
diff --git a/fs/nfsd/vfs.c b/fs/nfsd/vfs.c
index 857031952970..ee59a0b24fab 100644
--- a/fs/nfsd/vfs.c
+++ b/fs/nfsd/vfs.c
@@ -965,13 +965,15 @@ nfsd_vfs_write(struct svc_rqst *rqstp, struct svc_fh *fhp, struct file *file,
 {
         struct svc_export       *exp;
         struct iov_iter         iter;
-        __be32                  err = 0;
+        __be32                  nfserr;
         int                     host_err;
         int                     use_wgather;
         loff_t                  pos = offset;
         unsigned int            pflags = current->flags;
         rwf_t                   flags = 0;
 
+        trace_nfsd_write_opened(rqstp, fhp, offset, *cnt);
+
         if (test_bit(RQ_LOCAL, &rqstp->rq_flags))
                 /*
                  * We want less throttling in balance_dirty_pages()
@@ -994,22 +996,23 @@ nfsd_vfs_write(struct svc_rqst *rqstp, struct svc_fh *fhp, struct file *file,
         host_err = vfs_iter_write(file, &iter, &pos, flags);
         if (host_err < 0)
                 goto out_nfserr;
-        *cnt = host_err;
-        nfsdstats.io_write += host_err;
+        nfsdstats.io_write += *cnt;
         fsnotify_modify(file);
 
         if (stable && use_wgather)
                 host_err = wait_for_concurrent_writes(file);
 
 out_nfserr:
-        dprintk("nfsd: write complete host_err=%d\n", host_err);
-        if (host_err >= 0)
-                err = 0;
-        else
-                err = nfserrno(host_err);
+        if (host_err >= 0) {
+                trace_nfsd_write_io_done(rqstp, fhp, offset, *cnt);
+                nfserr = nfs_ok;
+        } else {
+                trace_nfsd_write_err(rqstp, fhp, offset, host_err);
+                nfserr = nfserrno(host_err);
+        }
         if (test_bit(RQ_LOCAL, &rqstp->rq_flags))
                 current_restore_flags(pflags, PF_LESS_THROTTLE);
-        return err;
+        return nfserr;
 }
 
 /*
@@ -1067,9 +1070,7 @@ nfsd_write(struct svc_rqst *rqstp, struct svc_fh *fhp, loff_t offset,
         if (err)
                 goto out;
 
-        trace_nfsd_write_opened(rqstp, fhp, offset, *cnt);
         err = nfsd_vfs_write(rqstp, fhp, file, offset, vec, vlen, cnt, stable);
-        trace_nfsd_write_io_done(rqstp, fhp, offset, *cnt);
         fput(file);
 out:
         trace_nfsd_write_done(rqstp, fhp, offset, *cnt);