SUNRPC: Trace struct svc_sock lifetime events
authorChuck Lever <chuck.lever@oracle.com>
Mon, 15 May 2023 13:33:00 +0000 (09:33 -0400)
committerChuck Lever <chuck.lever@oracle.com>
Mon, 5 Jun 2023 13:01:42 +0000 (09:01 -0400)
Capture a timestamp and pointer address during the creation and
destruction of struct svc_sock to record its lifetime. This helps
to diagnose transport reference counting issues.

Reviewed-by: Jeff Layton <jlayton@kernel.org>
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
include/trace/events/sunrpc.h
net/sunrpc/svcsock.c

index 31bc702..69e42ef 100644 (file)
@@ -2104,31 +2104,46 @@ DEFINE_SVC_DEFERRED_EVENT(drop);
 DEFINE_SVC_DEFERRED_EVENT(queue);
 DEFINE_SVC_DEFERRED_EVENT(recv);
 
-TRACE_EVENT(svcsock_new_socket,
+DECLARE_EVENT_CLASS(svcsock_lifetime_class,
        TP_PROTO(
+               const void *svsk,
                const struct socket *socket
        ),
-
-       TP_ARGS(socket),
-
+       TP_ARGS(svsk, socket),
        TP_STRUCT__entry(
+               __field(unsigned int, netns_ino)
+               __field(const void *, svsk)
+               __field(const void *, sk)
                __field(unsigned long, type)
                __field(unsigned long, family)
-               __field(bool, listener)
+               __field(unsigned long, state)
        ),
-
        TP_fast_assign(
+               struct sock *sk = socket->sk;
+
+               __entry->netns_ino = sock_net(sk)->ns.inum;
+               __entry->svsk = svsk;
+               __entry->sk = sk;
                __entry->type = socket->type;
-               __entry->family = socket->sk->sk_family;
-               __entry->listener = (socket->sk->sk_state == TCP_LISTEN);
+               __entry->family = sk->sk_family;
+               __entry->state = sk->sk_state;
        ),
-
-       TP_printk("type=%s family=%s%s",
-               show_socket_type(__entry->type),
+       TP_printk("svsk=%p type=%s family=%s%s",
+               __entry->svsk, show_socket_type(__entry->type),
                rpc_show_address_family(__entry->family),
-               __entry->listener ? " (listener)" : ""
+               __entry->state == TCP_LISTEN ? " (listener)" : ""
        )
 );
+#define DEFINE_SVCSOCK_LIFETIME_EVENT(name) \
+       DEFINE_EVENT(svcsock_lifetime_class, name, \
+               TP_PROTO( \
+                       const void *svsk, \
+                       const struct socket *socket \
+               ), \
+               TP_ARGS(svsk, socket))
+
+DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_new);
+DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_free);
 
 TRACE_EVENT(svcsock_marker,
        TP_PROTO(
index fbe33c9..5f519fc 100644 (file)
@@ -1470,7 +1470,7 @@ static struct svc_sock *svc_setup_socket(struct svc_serv *serv,
        else
                svc_tcp_init(svsk, serv);
 
-       trace_svcsock_new_socket(sock);
+       trace_svcsock_new(svsk, sock);
        return svsk;
 }
 
@@ -1651,6 +1651,8 @@ static void svc_sock_free(struct svc_xprt *xprt)
        struct svc_sock *svsk = container_of(xprt, struct svc_sock, sk_xprt);
        struct socket *sock = svsk->sk_sock;
 
+       trace_svcsock_free(svsk, sock);
+
        tls_handshake_cancel(sock->sk);
        if (sock->file)
                sockfd_put(sock);