NFSD: Add tracepoints in nfsd4_decode/encode_compound()
authorChuck Lever <chuck.lever@oracle.com>
Sat, 21 Nov 2020 16:36:42 +0000 (11:36 -0500)
committerChuck Lever <chuck.lever@oracle.com>
Mon, 30 Nov 2020 19:46:35 +0000 (14:46 -0500)
For troubleshooting purposes, record failures to decode NFSv4
operation arguments and encode operation results.

trace_nfsd_compound_decode_err() replaces the dprintk() call sites
that are embedded in READ_* macros that are about to be removed.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
fs/nfsd/nfs4xdr.c
fs/nfsd/trace.h

index 86a149c..66edac7 100644 (file)
@@ -54,6 +54,8 @@
 #include "pnfs.h"
 #include "filecache.h"
 
+#include "trace.h"
+
 #ifdef CONFIG_NFSD_V4_SECURITY_LABEL
 #include <linux/security.h>
 #endif
@@ -2248,9 +2250,14 @@ nfsd4_decode_compound(struct nfsd4_compoundargs *argp)
                READ_BUF(4);
                op->opnum = be32_to_cpup(p++);
 
-               if (nfsd4_opnum_in_range(argp, op))
+               if (nfsd4_opnum_in_range(argp, op)) {
                        op->status = nfsd4_dec_ops[op->opnum](argp, &op->u);
-               else {
+                       if (op->status != nfs_ok)
+                               trace_nfsd_compound_decode_err(argp->rqstp,
+                                                              argp->opcnt, i,
+                                                              op->opnum,
+                                                              op->status);
+               } else {
                        op->opnum = OP_ILLEGAL;
                        op->status = nfserr_op_illegal;
                }
@@ -5203,6 +5210,8 @@ nfsd4_encode_operation(struct nfsd4_compoundres *resp, struct nfsd4_op *op)
               !nfsd4_enc_ops[op->opnum]);
        encoder = nfsd4_enc_ops[op->opnum];
        op->status = encoder(resp, op->status, &op->u);
+       if (op->status)
+               trace_nfsd_compound_encode_err(rqstp, op->opnum, op->status);
        if (opdesc && opdesc->op_release)
                opdesc->op_release(&op->u);
        xdr_commit_encode(xdr);
index 0bf1707..92a0973 100644 (file)
                               rqstp->rq_xprt->xpt_remotelen); \
                } while (0);
 
+#define NFSD_TRACE_PROC_RES_FIELDS \
+               __field(unsigned int, netns_ino) \
+               __field(u32, xid) \
+               __field(unsigned long, status) \
+               __array(unsigned char, server, sizeof(struct sockaddr_in6)) \
+               __array(unsigned char, client, sizeof(struct sockaddr_in6))
+
+#define NFSD_TRACE_PROC_RES_ASSIGNMENTS(error) \
+               do { \
+                       __entry->netns_ino = SVC_NET(rqstp)->ns.inum; \
+                       __entry->xid = be32_to_cpu(rqstp->rq_xid); \
+                       __entry->status = be32_to_cpu(error); \
+                       memcpy(__entry->server, &rqstp->rq_xprt->xpt_local, \
+                              rqstp->rq_xprt->xpt_locallen); \
+                       memcpy(__entry->client, &rqstp->rq_xprt->xpt_remote, \
+                              rqstp->rq_xprt->xpt_remotelen); \
+               } while (0);
+
 TRACE_EVENT(nfsd_garbage_args_err,
        TP_PROTO(
                const struct svc_rqst *rqstp
@@ -127,6 +145,56 @@ TRACE_EVENT(nfsd_compound_status,
                __get_str(name), __entry->status)
 )
 
+TRACE_EVENT(nfsd_compound_decode_err,
+       TP_PROTO(
+               const struct svc_rqst *rqstp,
+               u32 args_opcnt,
+               u32 resp_opcnt,
+               u32 opnum,
+               __be32 status
+       ),
+       TP_ARGS(rqstp, args_opcnt, resp_opcnt, opnum, status),
+       TP_STRUCT__entry(
+               NFSD_TRACE_PROC_RES_FIELDS
+
+               __field(u32, args_opcnt)
+               __field(u32, resp_opcnt)
+               __field(u32, opnum)
+       ),
+       TP_fast_assign(
+               NFSD_TRACE_PROC_RES_ASSIGNMENTS(status)
+
+               __entry->args_opcnt = args_opcnt;
+               __entry->resp_opcnt = resp_opcnt;
+               __entry->opnum = opnum;
+       ),
+       TP_printk("op=%u/%u opnum=%u status=%lu",
+               __entry->resp_opcnt, __entry->args_opcnt,
+               __entry->opnum, __entry->status)
+);
+
+TRACE_EVENT(nfsd_compound_encode_err,
+       TP_PROTO(
+               const struct svc_rqst *rqstp,
+               u32 opnum,
+               __be32 status
+       ),
+       TP_ARGS(rqstp, opnum, status),
+       TP_STRUCT__entry(
+               NFSD_TRACE_PROC_RES_FIELDS
+
+               __field(u32, opnum)
+       ),
+       TP_fast_assign(
+               NFSD_TRACE_PROC_RES_ASSIGNMENTS(status)
+
+               __entry->opnum = opnum;
+       ),
+       TP_printk("opnum=%u status=%lu",
+               __entry->opnum, __entry->status)
+);
+
+
 DECLARE_EVENT_CLASS(nfsd_fh_err_class,
        TP_PROTO(struct svc_rqst *rqstp,
                 struct svc_fh  *fhp,