SUNRPC: Trace transport lifetime events

Refactor: Hoist create/destroy/disconnect tracepoints out of
xprtrdma and into the generic RPC client. Some benefits include:

- Enable tracing of xprt lifetime events for the socket transport
  types

- Expose the different types of disconnect to help run down
  issues with lingering connections

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 132c3c7..edb55ea 100644 (file)
--- a/include/trace/events/rpcrdma.h
+++ b/include/trace/events/rpcrdma.h
@@ -380,12 +380,8 @@ TRACE_EVENT(xprtrdma_inline_thresh,
 
 DEFINE_CONN_EVENT(connect);
 DEFINE_CONN_EVENT(disconnect);
-DEFINE_CONN_EVENT(flush_dct);
 
-DEFINE_RXPRT_EVENT(xprtrdma_create);
-DEFINE_RXPRT_EVENT(xprtrdma_op_destroy);
 DEFINE_RXPRT_EVENT(xprtrdma_op_inject_dsc);
-DEFINE_RXPRT_EVENT(xprtrdma_op_close);
 DEFINE_RXPRT_EVENT(xprtrdma_op_setport);
 
 TRACE_EVENT(xprtrdma_op_connect,

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 4747803..fc8a969 100644 (file)
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -724,6 +724,41 @@ DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
 
+DECLARE_EVENT_CLASS(rpc_xprt_lifetime_class,
+       TP_PROTO(
+               const struct rpc_xprt *xprt
+       ),
+
+       TP_ARGS(xprt),
+
+       TP_STRUCT__entry(
+               __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
+               __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
+       ),
+
+       TP_fast_assign(
+               __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
+               __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
+       ),
+
+       TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port))
+);
+
+#define DEFINE_RPC_XPRT_LIFETIME_EVENT(name) \
+       DEFINE_EVENT(rpc_xprt_lifetime_class, \
+                       xprt_##name, \
+                       TP_PROTO( \
+                               const struct rpc_xprt *xprt \
+                       ), \
+                       TP_ARGS(xprt))
+
+DEFINE_RPC_XPRT_LIFETIME_EVENT(create);
+DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_auto);
+DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_done);
+DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_force);
+DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_cleanup);
+DEFINE_RPC_XPRT_LIFETIME_EVENT(destroy);
+
 DECLARE_EVENT_CLASS(rpc_xprt_event,
        TP_PROTO(
                const struct rpc_xprt *xprt,

diff --git a/net/sunrpc/xprt.c b/net/sunrpc/xprt.c
index 053de05..d5cc5db 100644 (file)
--- a/net/sunrpc/xprt.c
+++ b/net/sunrpc/xprt.c
@@ -663,6 +663,7 @@ static void xprt_autoclose(struct work_struct *work)
                container_of(work, struct rpc_xprt, task_cleanup);
        unsigned int pflags = memalloc_nofs_save();
 
+       trace_xprt_disconnect_auto(xprt);
        clear_bit(XPRT_CLOSE_WAIT, &xprt->state);
        xprt->ops->close(xprt);
        xprt_release_write(xprt, NULL);
@@ -677,7 +678,7 @@ static void xprt_autoclose(struct work_struct *work)
  */
 void xprt_disconnect_done(struct rpc_xprt *xprt)
 {
-       dprintk("RPC:       disconnected transport %p\n", xprt);
+       trace_xprt_disconnect_done(xprt);
        spin_lock(&xprt->transport_lock);
        xprt_clear_connected(xprt);
        xprt_clear_write_space_locked(xprt);
@@ -694,6 +695,8 @@ EXPORT_SYMBOL_GPL(xprt_disconnect_done);
  */
 void xprt_force_disconnect(struct rpc_xprt *xprt)
 {
+       trace_xprt_disconnect_force(xprt);
+
        /* Don't race with the test_bit() in xprt_clear_locked() */
        spin_lock(&xprt->transport_lock);
        set_bit(XPRT_CLOSE_WAIT, &xprt->state);
@@ -832,8 +835,10 @@ void xprt_connect(struct rpc_task *task)
        if (!xprt_lock_write(xprt, task))
                return;
 
-       if (test_and_clear_bit(XPRT_CLOSE_WAIT, &xprt->state))
+       if (test_and_clear_bit(XPRT_CLOSE_WAIT, &xprt->state)) {
+               trace_xprt_disconnect_cleanup(xprt);
                xprt->ops->close(xprt);
+       }
 
        if (!xprt_connected(xprt)) {
                task->tk_rqstp->rq_connect_cookie = xprt->connect_cookie;
@@ -1903,11 +1908,8 @@ struct rpc_xprt *xprt_create_transport(struct xprt_create *args)
 
 found:
        xprt = t->setup(args);
-       if (IS_ERR(xprt)) {
-               dprintk("RPC:       xprt_create_transport: failed, %ld\n",
-                               -PTR_ERR(xprt));
+       if (IS_ERR(xprt))
                goto out;
-       }
        if (args->flags & XPRT_CREATE_NO_IDLE_TIMEOUT)
                xprt->idle_timeout = 0;
        INIT_WORK(&xprt->task_cleanup, xprt_autoclose);
@@ -1928,8 +1930,7 @@ found:
 
        rpc_xprt_debugfs_register(xprt);
 
-       dprintk("RPC:       created transport %p with %u slots\n", xprt,
-                       xprt->max_reqs);
+       trace_xprt_create(xprt);
 out:
        return xprt;
 }
@@ -1939,6 +1940,8 @@ static void xprt_destroy_cb(struct work_struct *work)
        struct rpc_xprt *xprt =
                container_of(work, struct rpc_xprt, task_cleanup);
 
+       trace_xprt_destroy(xprt);
+
        rpc_xprt_debugfs_unregister(xprt);
        rpc_destroy_wait_queue(&xprt->binding);
        rpc_destroy_wait_queue(&xprt->pending);
@@ -1963,8 +1966,6 @@ static void xprt_destroy_cb(struct work_struct *work)
  */
 static void xprt_destroy(struct rpc_xprt *xprt)
 {
-       dprintk("RPC:       destroying transport %p\n", xprt);
-
        /*
         * Exclude transport connect/disconnect handlers and autoclose
         */

diff --git a/net/sunrpc/xprtrdma/transport.c b/net/sunrpc/xprtrdma/transport.c
index 659da37..048c2fd 100644 (file)
--- a/net/sunrpc/xprtrdma/transport.c
+++ b/net/sunrpc/xprtrdma/transport.c
@@ -281,8 +281,6 @@ xprt_rdma_destroy(struct rpc_xprt *xprt)
 {
        struct rpcrdma_xprt *r_xprt = rpcx_to_rdmax(xprt);
 
-       trace_xprtrdma_op_destroy(r_xprt);
-
        cancel_delayed_work_sync(&r_xprt->rx_connect_worker);
 
        rpcrdma_xprt_disconnect(r_xprt);
@@ -365,10 +363,6 @@ xprt_setup_rdma(struct xprt_create *args)
 
        xprt->max_payload = RPCRDMA_MAX_DATA_SEGS << PAGE_SHIFT;
 
-       dprintk("RPC:       %s: %s:%s\n", __func__,
-               xprt->address_strings[RPC_DISPLAY_ADDR],
-               xprt->address_strings[RPC_DISPLAY_PORT]);
-       trace_xprtrdma_create(new_xprt);
        return xprt;
 }
 
@@ -385,8 +379,6 @@ void xprt_rdma_close(struct rpc_xprt *xprt)
 {
        struct rpcrdma_xprt *r_xprt = rpcx_to_rdmax(xprt);
 
-       trace_xprtrdma_op_close(r_xprt);
-
        rpcrdma_xprt_disconnect(r_xprt);
 
        xprt->reestablish_timeout = 0;

diff --git a/net/sunrpc/xprtrdma/verbs.c b/net/sunrpc/xprtrdma/verbs.c
index 05c4d3a..2ae3483 100644 (file)
--- a/net/sunrpc/xprtrdma/verbs.c
+++ b/net/sunrpc/xprtrdma/verbs.c
@@ -141,7 +141,6 @@ void rpcrdma_flush_disconnect(struct ib_cq *cq, struct ib_wc *wc)
        if (wc->status != IB_WC_SUCCESS &&
            r_xprt->rx_ep->re_connect_status == 1) {
                r_xprt->rx_ep->re_connect_status = -ECONNABORTED;
-               trace_xprtrdma_flush_dct(r_xprt, wc->status);
                xprt_force_disconnect(xprt);
        }
 }