[PATCH v1 08/15] SUNRPC: Trace transport lifetime events

Chuck Lever
2020-05-12T21:13:38Z

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>
---
include/trace/events/rpcrdma.h | 4 ----
include/trace/events/sunrpc.h | 35 +++++++++++++++++++++++++++++++++++
net/sunrpc/xprt.c | 21 +++++++++++----------
net/sunrpc/xprtrdma/transport.c | 8 --------
net/sunrpc/xprtrdma/verbs.c | 1 -
5 files changed, 46 insertions(+), 23 deletions(-)

diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h
index 132c3c778a43..edb55eab4762 100644
--- a/include/trace/events/rpcrdma.h
+++ b/include/trace/events/rpcrdma.h
@@ -380,12 +380,8 @@

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 4747803b370e..fc8a969ba306 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -724,6 +724,41 @@
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 053de053a024..d5cc5db9dbf3 100644
--- 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 @@ void xprt_disconnect_done(struct rpc_xprt *xprt)
*/
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 @@ struct rpc_xprt *xprt_create_transport(struct xprt_create *args)

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 659da37020a4..048c2fd85728 100644
--- a/net/sunrpc/xprtrdma/transport.c
+++ b/net/sunrpc/xprtrdma/transport.c
@@ -281,8 +281,6 @@
{
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->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 05c4d3a9cda2..2ae348377806 100644
--- 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);
}
}