xprtrdma: Trace mapping, alloc, and dereg failures

These are rare, but can be helpful at tracking down DMAR and other
problems.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>

diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h
index 3d068bba4532eabb079038294c2b123713fc70d6..ce528d5942c5c6db3b37d684c531d606f555d099 100644 (file)
--- a/include/trace/events/rpcrdma.h
+++ b/include/trace/events/rpcrdma.h
@@ -10,6 +10,7 @@
 #if !defined(_TRACE_RPCRDMA_H) || defined(TRACE_HEADER_MULTI_READ)
 #define _TRACE_RPCRDMA_H
 
+#include <linux/scatterlist.h>
 #include <linux/tracepoint.h>
 #include <trace/events/rdma.h>
 
@@ -663,12 +664,147 @@ DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_fastreg);
 DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li);
 DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li_wake);
 
+TRACE_EVENT(xprtrdma_frwr_alloc,
+       TP_PROTO(
+               const struct rpcrdma_mr *mr,
+               int rc
+       ),
+
+       TP_ARGS(mr, rc),
+
+       TP_STRUCT__entry(
+               __field(const void *, mr)
+               __field(int, rc)
+       ),
+
+       TP_fast_assign(
+               __entry->mr = mr;
+               __entry->rc     = rc;
+       ),
+
+       TP_printk("mr=%p: rc=%d",
+               __entry->mr, __entry->rc
+       )
+);
+
+TRACE_EVENT(xprtrdma_frwr_dereg,
+       TP_PROTO(
+               const struct rpcrdma_mr *mr,
+               int rc
+       ),
+
+       TP_ARGS(mr, rc),
+
+       TP_STRUCT__entry(
+               __field(const void *, mr)
+               __field(u32, handle)
+               __field(u32, length)
+               __field(u64, offset)
+               __field(u32, dir)
+               __field(int, rc)
+       ),
+
+       TP_fast_assign(
+               __entry->mr = mr;
+               __entry->handle = mr->mr_handle;
+               __entry->length = mr->mr_length;
+               __entry->offset = mr->mr_offset;
+               __entry->dir    = mr->mr_dir;
+               __entry->rc     = rc;
+       ),
+
+       TP_printk("mr=%p %u@0x%016llx:0x%08x (%s): rc=%d",
+               __entry->mr, __entry->length,
+               (unsigned long long)__entry->offset, __entry->handle,
+               xprtrdma_show_direction(__entry->dir),
+               __entry->rc
+       )
+);
+
+TRACE_EVENT(xprtrdma_frwr_sgerr,
+       TP_PROTO(
+               const struct rpcrdma_mr *mr,
+               int sg_nents
+       ),
+
+       TP_ARGS(mr, sg_nents),
+
+       TP_STRUCT__entry(
+               __field(const void *, mr)
+               __field(u64, addr)
+               __field(u32, dir)
+               __field(int, nents)
+       ),
+
+       TP_fast_assign(
+               __entry->mr = mr;
+               __entry->addr = mr->mr_sg->dma_address;
+               __entry->dir = mr->mr_dir;
+               __entry->nents = sg_nents;
+       ),
+
+       TP_printk("mr=%p dma addr=0x%llx (%s) sg_nents=%d",
+               __entry->mr, __entry->addr,
+               xprtrdma_show_direction(__entry->dir),
+               __entry->nents
+       )
+);
+
+TRACE_EVENT(xprtrdma_frwr_maperr,
+       TP_PROTO(
+               const struct rpcrdma_mr *mr,
+               int num_mapped
+       ),
+
+       TP_ARGS(mr, num_mapped),
+
+       TP_STRUCT__entry(
+               __field(const void *, mr)
+               __field(u64, addr)
+               __field(u32, dir)
+               __field(int, num_mapped)
+               __field(int, nents)
+       ),
+
+       TP_fast_assign(
+               __entry->mr = mr;
+               __entry->addr = mr->mr_sg->dma_address;
+               __entry->dir = mr->mr_dir;
+               __entry->num_mapped = num_mapped;
+               __entry->nents = mr->mr_nents;
+       ),
+
+       TP_printk("mr=%p dma addr=0x%llx (%s) nents=%d of %d",
+               __entry->mr, __entry->addr,
+               xprtrdma_show_direction(__entry->dir),
+               __entry->num_mapped, __entry->nents
+       )
+);
+
 DEFINE_MR_EVENT(localinv);
 DEFINE_MR_EVENT(map);
 DEFINE_MR_EVENT(unmap);
 DEFINE_MR_EVENT(remoteinv);
 DEFINE_MR_EVENT(recycle);
 
+TRACE_EVENT(xprtrdma_dma_maperr,
+       TP_PROTO(
+               u64 addr
+       ),
+
+       TP_ARGS(addr),
+
+       TP_STRUCT__entry(
+               __field(u64, addr)
+       ),
+
+       TP_fast_assign(
+               __entry->addr = addr;
+       ),
+
+       TP_printk("dma addr=0x%llx\n", __entry->addr)
+);
+
 /**
  ** Reply events
  **/

diff --git a/net/sunrpc/xprtrdma/frwr_ops.c b/net/sunrpc/xprtrdma/frwr_ops.c
index 1f508f4742f9b4f8ceedcd763e8d1b7865008ab0..8a0f1a6e6927ed06b38475926a52fe76a837557f 100644 (file)
--- a/net/sunrpc/xprtrdma/frwr_ops.c
+++ b/net/sunrpc/xprtrdma/frwr_ops.c
@@ -113,8 +113,7 @@ void frwr_release_mr(struct rpcrdma_mr *mr)
 
        rc = ib_dereg_mr(mr->frwr.fr_mr);
        if (rc)
-               pr_err("rpcrdma: final ib_dereg_mr for %p returned %i\n",
-                      mr, rc);
+               trace_xprtrdma_frwr_dereg(mr, rc);
        kfree(mr->mr_sg);
        kfree(mr);
 }
@@ -177,8 +176,7 @@ int frwr_init_mr(struct rpcrdma_ia *ia, struct rpcrdma_mr *mr)
 
 out_mr_err:
        rc = PTR_ERR(frwr->fr_mr);
-       dprintk("RPC:       %s: ib_alloc_mr status %i\n",
-               __func__, rc);
+       trace_xprtrdma_frwr_alloc(mr, rc);
        return rc;
 
 out_list_err:
@@ -465,15 +463,13 @@ struct rpcrdma_mr_seg *frwr_map(struct rpcrdma_xprt *r_xprt,
        return seg;
 
 out_dmamap_err:
-       pr_err("rpcrdma: failed to DMA map sg %p sg_nents %d\n",
-              mr->mr_sg, i);
        frwr->fr_state = FRWR_IS_INVALID;
+       trace_xprtrdma_frwr_sgerr(mr, i);
        rpcrdma_mr_put(mr);
        return ERR_PTR(-EIO);
 
 out_mapmr_err:
-       pr_err("rpcrdma: failed to map mr %p (%d/%d)\n",
-              frwr->fr_mr, n, mr->mr_nents);
+       trace_xprtrdma_frwr_maperr(mr, n);
        rpcrdma_mr_recycle(mr);
        return ERR_PTR(-EIO);
 }

diff --git a/net/sunrpc/xprtrdma/rpc_rdma.c b/net/sunrpc/xprtrdma/rpc_rdma.c
index 54fbd70c661c3fdd0c0d29c1b4e7f51865b1ae5c..062aee97b070607038b381db9d5d79f9a329a327 100644 (file)
--- a/net/sunrpc/xprtrdma/rpc_rdma.c
+++ b/net/sunrpc/xprtrdma/rpc_rdma.c
@@ -665,7 +665,7 @@ out_mapping_overflow:
 
 out_mapping_err:
        rpcrdma_unmap_sendctx(sc);
-       pr_err("rpcrdma: Send mapping error\n");
+       trace_xprtrdma_dma_maperr(sge[sge_no].addr);
        return false;
 }
 

diff --git a/net/sunrpc/xprtrdma/verbs.c b/net/sunrpc/xprtrdma/verbs.c
index 85c51b8c438d7f495229bbfab6d0aa96610bced6..719b69c8bb815225b72acb1dbf1889ddab016131 100644 (file)
--- a/net/sunrpc/xprtrdma/verbs.c
+++ b/net/sunrpc/xprtrdma/verbs.c
@@ -1392,8 +1392,10 @@ __rpcrdma_dma_map_regbuf(struct rpcrdma_ia *ia, struct rpcrdma_regbuf *rb)
                                            (void *)rb->rg_base,
                                            rdmab_length(rb),
                                            rb->rg_direction);
-       if (ib_dma_mapping_error(device, rdmab_addr(rb)))
+       if (ib_dma_mapping_error(device, rdmab_addr(rb))) {
+               trace_xprtrdma_dma_maperr(rdmab_addr(rb));
                return false;
+       }
 
        rb->rg_device = device;
        rb->rg_iov.lkey = ia->ri_pd->local_dma_lkey;