svcrdma: Split the svcrdma_wc_receive() tracepoint
authorChuck Lever <chuck.lever@oracle.com>
Mon, 4 Oct 2021 14:16:08 +0000 (10:16 -0400)
committerJ. Bruce Fields <bfields@redhat.com>
Mon, 4 Oct 2021 19:40:15 +0000 (15:40 -0400)
There are currently three separate purposes being served by a single
tracepoint here. They need to be split up.

svcrdma_wc_recv:
 - status is always zero, so there's no value in recording it.
 - vendor_err is meaningless unless status is not zero, so
   there's no value in recording it.
 - This tracepoint is needed only when developing modifications,
   so it should be left disabled most of the time.

svcrdma_wc_recv_flush:
 - As above, needed only rarely, and not an error.

svcrdma_wc_recv_err:
 - received is always zero, so there's no value in recording it.
 - This tracepoint can be left enabled because completion
   errors are run-time problems (except for FLUSHED_ERR).
 - Tracepoint name now ends in _err to reflect its purpose.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
include/trace/events/rpcrdma.h
net/sunrpc/xprtrdma/svc_rdma_recvfrom.c

index de41954995926de1ff021f7d16ffecd174779ddf..342d6d7b5cd9e698f97393f407cab54e2d3fa8d4 100644 (file)
@@ -145,6 +145,77 @@ DECLARE_EVENT_CLASS(rpcrdma_receive_completion_class,
                                ),                                      \
                                TP_ARGS(wc, cid))
 
+DECLARE_EVENT_CLASS(rpcrdma_receive_success_class,
+       TP_PROTO(
+               const struct ib_wc *wc,
+               const struct rpc_rdma_cid *cid
+       ),
+
+       TP_ARGS(wc, cid),
+
+       TP_STRUCT__entry(
+               __field(u32, cq_id)
+               __field(int, completion_id)
+               __field(u32, received)
+       ),
+
+       TP_fast_assign(
+               __entry->cq_id = cid->ci_queue_id;
+               __entry->completion_id = cid->ci_completion_id;
+               __entry->received = wc->byte_len;
+       ),
+
+       TP_printk("cq.id=%u cid=%d received=%u",
+               __entry->cq_id, __entry->completion_id,
+               __entry->received
+       )
+);
+
+#define DEFINE_RECEIVE_SUCCESS_EVENT(name)                             \
+               DEFINE_EVENT(rpcrdma_receive_success_class, name,       \
+                               TP_PROTO(                               \
+                                       const struct ib_wc *wc,         \
+                                       const struct rpc_rdma_cid *cid  \
+                               ),                                      \
+                               TP_ARGS(wc, cid))
+
+DECLARE_EVENT_CLASS(rpcrdma_receive_flush_class,
+       TP_PROTO(
+               const struct ib_wc *wc,
+               const struct rpc_rdma_cid *cid
+       ),
+
+       TP_ARGS(wc, cid),
+
+       TP_STRUCT__entry(
+               __field(u32, cq_id)
+               __field(int, completion_id)
+               __field(unsigned long, status)
+               __field(unsigned int, vendor_err)
+       ),
+
+       TP_fast_assign(
+               __entry->cq_id = cid->ci_queue_id;
+               __entry->completion_id = cid->ci_completion_id;
+               __entry->status = wc->status;
+               __entry->vendor_err = wc->vendor_err;
+       ),
+
+       TP_printk("cq.id=%u cid=%d status=%s (%lu/0x%x)",
+               __entry->cq_id, __entry->completion_id,
+               rdma_show_wc_status(__entry->status),
+               __entry->status, __entry->vendor_err
+       )
+);
+
+#define DEFINE_RECEIVE_FLUSH_EVENT(name)                               \
+               DEFINE_EVENT(rpcrdma_receive_flush_class, name,         \
+                               TP_PROTO(                               \
+                                       const struct ib_wc *wc,         \
+                                       const struct rpc_rdma_cid *cid  \
+                               ),                                      \
+                               TP_ARGS(wc, cid))
+
 DECLARE_EVENT_CLASS(xprtrdma_reply_class,
        TP_PROTO(
                const struct rpcrdma_rep *rep
@@ -1892,7 +1963,9 @@ TRACE_EVENT(svcrdma_post_recv,
        )
 );
 
-DEFINE_RECEIVE_COMPLETION_EVENT(svcrdma_wc_receive);
+DEFINE_RECEIVE_SUCCESS_EVENT(svcrdma_wc_recv);
+DEFINE_RECEIVE_FLUSH_EVENT(svcrdma_wc_recv_flush);
+DEFINE_RECEIVE_FLUSH_EVENT(svcrdma_wc_recv_err);
 
 TRACE_EVENT(svcrdma_rq_post_err,
        TP_PROTO(
index 6be23ce7a93d216d83cf92d91324a033215b2f32..cf76a6ad127b26603d0c07ea1a8845dd80527577 100644 (file)
@@ -330,9 +330,9 @@ static void svc_rdma_wc_receive(struct ib_cq *cq, struct ib_wc *wc)
        /* WARNING: Only wc->wr_cqe and wc->status are reliable */
        ctxt = container_of(cqe, struct svc_rdma_recv_ctxt, rc_cqe);
 
-       trace_svcrdma_wc_receive(wc, &ctxt->rc_cid);
        if (wc->status != IB_WC_SUCCESS)
                goto flushed;
+       trace_svcrdma_wc_recv(wc, &ctxt->rc_cid);
 
        /* If receive posting fails, the connection is about to be
         * lost anyway. The server will not be able to send a reply
@@ -345,7 +345,7 @@ static void svc_rdma_wc_receive(struct ib_cq *cq, struct ib_wc *wc)
         */
        if (rdma->sc_pending_recvs < rdma->sc_max_requests)
                if (!svc_rdma_refresh_recvs(rdma, rdma->sc_recv_batch, false))
-                       goto flushed;
+                       goto dropped;
 
        /* All wc fields are now known to be valid */
        ctxt->rc_byte_len = wc->byte_len;
@@ -360,6 +360,11 @@ static void svc_rdma_wc_receive(struct ib_cq *cq, struct ib_wc *wc)
        return;
 
 flushed:
+       if (wc->status == IB_WC_WR_FLUSH_ERR)
+               trace_svcrdma_wc_recv_flush(wc, &ctxt->rc_cid);
+       else
+               trace_svcrdma_wc_recv_err(wc, &ctxt->rc_cid);
+dropped:
        svc_rdma_recv_ctxt_put(rdma, ctxt);
        svc_xprt_deferred_close(&rdma->sc_xprt);
 }