xprtrdma: Add xprtrdma_post_recvs_err() tracepoint
authorChuck Lever <chuck.lever@oracle.com>
Mon, 2 Aug 2021 18:44:30 +0000 (14:44 -0400)
committerAnna Schumaker <Anna.Schumaker@Netapp.com>
Mon, 9 Aug 2021 20:42:10 +0000 (16:42 -0400)
In the vast majority of cases, rc=0. Don't record that in the
post_recvs tracepoint. Instead, add a separate tracepoint that can
be left enabled all the time to capture the very rare immediate
errors returned by ib_post_recv().

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Anna Schumaker <Anna.Schumaker@Netapp.com>
include/trace/events/rpcrdma.h
net/sunrpc/xprtrdma/verbs.c

index bd55908c1bef9557c0c6915765bafc1da6e93be8..d65a84bd040ce03f82c91a005a3aef68ffc44669 100644 (file)
@@ -818,16 +818,14 @@ TRACE_EVENT(xprtrdma_post_recv,
 TRACE_EVENT(xprtrdma_post_recvs,
        TP_PROTO(
                const struct rpcrdma_xprt *r_xprt,
-               unsigned int count,
-               int status
+               unsigned int count
        ),
 
-       TP_ARGS(r_xprt, count, status),
+       TP_ARGS(r_xprt, count),
 
        TP_STRUCT__entry(
                __field(u32, cq_id)
                __field(unsigned int, count)
-               __field(int, status)
                __field(int, posted)
                __string(addr, rpcrdma_addrstr(r_xprt))
                __string(port, rpcrdma_portstr(r_xprt))
@@ -838,15 +836,44 @@ TRACE_EVENT(xprtrdma_post_recvs,
 
                __entry->cq_id = ep->re_attr.recv_cq->res.id;
                __entry->count = count;
-               __entry->status = status;
                __entry->posted = ep->re_receive_count;
                __assign_str(addr, rpcrdma_addrstr(r_xprt));
                __assign_str(port, rpcrdma_portstr(r_xprt));
        ),
 
-       TP_printk("peer=[%s]:%s cq.id=%d %u new recvs, %d active (rc %d)",
+       TP_printk("peer=[%s]:%s cq.id=%d %u new recvs, %d active",
+               __get_str(addr), __get_str(port), __entry->cq_id,
+               __entry->count, __entry->posted
+       )
+);
+
+TRACE_EVENT(xprtrdma_post_recvs_err,
+       TP_PROTO(
+               const struct rpcrdma_xprt *r_xprt,
+               int status
+       ),
+
+       TP_ARGS(r_xprt, status),
+
+       TP_STRUCT__entry(
+               __field(u32, cq_id)
+               __field(int, status)
+               __string(addr, rpcrdma_addrstr(r_xprt))
+               __string(port, rpcrdma_portstr(r_xprt))
+       ),
+
+       TP_fast_assign(
+               const struct rpcrdma_ep *ep = r_xprt->rx_ep;
+
+               __entry->cq_id = ep->re_attr.recv_cq->res.id;
+               __entry->status = status;
+               __assign_str(addr, rpcrdma_addrstr(r_xprt));
+               __assign_str(port, rpcrdma_portstr(r_xprt));
+       ),
+
+       TP_printk("peer=[%s]:%s cq.id=%d rc=%d",
                __get_str(addr), __get_str(port), __entry->cq_id,
-               __entry->count, __entry->posted, __entry->status
+               __entry->status
        )
 );
 
index 016f10a781b4f7b90cb35505cfe80bb31df96659..1e9041c022b6c2f6c5fbafe43af50df658b8fc53 100644 (file)
@@ -1417,6 +1417,7 @@ void rpcrdma_post_recvs(struct rpcrdma_xprt *r_xprt, int needed, bool temp)
        rc = ib_post_recv(ep->re_id->qp, wr,
                          (const struct ib_recv_wr **)&bad_wr);
        if (rc) {
+               trace_xprtrdma_post_recvs_err(r_xprt, rc);
                for (wr = bad_wr; wr;) {
                        struct rpcrdma_rep *rep;
 
@@ -1430,7 +1431,7 @@ void rpcrdma_post_recvs(struct rpcrdma_xprt *r_xprt, int needed, bool temp)
                complete(&ep->re_done);
 
 out:
-       trace_xprtrdma_post_recvs(r_xprt, count, rc);
+       trace_xprtrdma_post_recvs(r_xprt, count);
        ep->re_receive_count += count;
        return;
 }