These are rare, but can be helpful at tracking down DMAR and other
problems.
Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
---
include/trace/events/rpcrdma.h | 136 ++++++++++++++++++++++++++++++++++++++++
net/sunrpc/xprtrdma/frwr_ops.c | 12 +---
net/sunrpc/xprtrdma/rpc_rdma.c | 2 -
net/sunrpc/xprtrdma/verbs.c | 4 +
4 files changed, 144 insertions(+), 10 deletions(-)
diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h
index 727786f..f4537a6 100644
--- 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_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 addr=%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 addr=%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 6d6cc80..529865a 100644
--- a/net/sunrpc/xprtrdma/frwr_ops.c
+++ b/net/sunrpc/xprtrdma/frwr_ops.c
@@ -104,8 +104,7 @@
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);
}
@@ -158,8 +157,7 @@
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:
@@ -421,15 +419,13 @@
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 b89342d..422d793 100644
--- a/net/sunrpc/xprtrdma/rpc_rdma.c
+++ b/net/sunrpc/xprtrdma/rpc_rdma.c
@@ -668,7 +668,7 @@ static bool rpcrdma_results_inline(struct rpcrdma_xprt *r_xprt,
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 4afed9f..1ee55d1 100644
--- a/net/sunrpc/xprtrdma/verbs.c
+++ b/net/sunrpc/xprtrdma/verbs.c
@@ -1419,8 +1419,10 @@ struct rpcrdma_regbuf *
(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;
