From patchwork Mon May 15 13:32:41 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Chuck Lever X-Patchwork-Id: 13241468 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 370D6C77B7D for ; Mon, 15 May 2023 13:32:47 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S241313AbjEONcq (ORCPT ); Mon, 15 May 2023 09:32:46 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:48230 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S240863AbjEONcp (ORCPT ); Mon, 15 May 2023 09:32:45 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 76F681700 for ; Mon, 15 May 2023 06:32:43 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id 1091762471 for ; Mon, 15 May 2023 13:32:43 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 4EA12C433EF; Mon, 15 May 2023 13:32:42 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1684157562; bh=yCDjkNv+oqwBKcrh0OpYTEwzg7kxtSFsXePgNXq/u0k=; h=Subject:From:To:Cc:Date:In-Reply-To:References:From; b=N7KmZOSRCe7fyuZOy8hGwjEnLvC/rAO9DrGb6yVbblHnwBe3fO4k25rbE1SOdM0jF AjWv90vQ7kfg+1TweZYqU7UuERkBpmcq0pYLjKUQb70G99McuDeKeHbHuDHQUEzAmP 3vJObVjXxfZK04fSGIUga3GYXIylrvb4EFpcFkklgkL/us8SiJaBk94h9QRFl+LeQj h7ZWciEguAficMs6aCzHHDQa2K0R6FqFAg9QRGpfnXiVimV8X6qW5nqm0dWAZyuaMI qFBCmF6ybVx6yU6OagS88jRaA3gD8Iv5jbhEbePX2P3YhgpstAha+X9DSPcw1OKPUS nq7DmKSor1Qww== Subject: [PATCH 1/4] SUNRPC: Fix an incorrect comment From: Chuck Lever To: linux-nfs@vger.kernel.org Cc: Chuck Lever Date: Mon, 15 May 2023 09:32:41 -0400 Message-ID: <168415756128.9504.10972346476896238136.stgit@manet.1015granger.net> In-Reply-To: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> References: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> User-Agent: StGit/1.5 MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-nfs@vger.kernel.org From: Chuck Lever The correct function name is svc_tcp_listen_data_ready(). Signed-off-by: Chuck Lever --- net/sunrpc/svcsock.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c index 9aca6e1e78e4..e0fb65e90af2 100644 --- a/net/sunrpc/svcsock.c +++ b/net/sunrpc/svcsock.c @@ -1469,7 +1469,7 @@ static struct svc_sock *svc_setup_socket(struct svc_serv *serv, svsk->sk_owspace = inet->sk_write_space; /* * This barrier is necessary in order to prevent race condition - * with svc_data_ready(), svc_listen_data_ready() and others + * with svc_data_ready(), svc_tcp_listen_data_ready(), and others * when calling callbacks above. */ wmb(); From patchwork Mon May 15 13:32:47 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Chuck Lever X-Patchwork-Id: 13241469 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id C4665C77B7D for ; Mon, 15 May 2023 13:32:53 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S241579AbjEONcw (ORCPT ); Mon, 15 May 2023 09:32:52 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:48262 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S240863AbjEONcw (ORCPT ); Mon, 15 May 2023 09:32:52 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id B44CCE69 for ; Mon, 15 May 2023 06:32:49 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id 4E66F6249A for ; Mon, 15 May 2023 13:32:49 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 8CB1FC433EF; Mon, 15 May 2023 13:32:48 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1684157568; bh=OS26ygfCmeKYk5UMOdH88S37nToFGs1y0OBxzzMrPUU=; h=Subject:From:To:Cc:Date:In-Reply-To:References:From; b=tVzf0y2HXpbm46gIpliFC6CX5nA+QXHMZVa+WraWQkq2Fx6tn/O+yZqqG+nN1rPPt gVL769dE8KC8pUyeFVvH0btOgOtAGOJNaGjoWZK1qUU+SbAqc0cdE52WxvPJLPOiAV oSDmPy2RtfHQamDmOAXy716CrLWCuvMTIj6d2/ZNE5rvmosH+CThEuS5SavsNmbM3N ra4k8pkb2Xgq97JE7s4zPQVen3HYRhWxIxTSN0LMc2INSD9uYyMdC9Ys9AZ2AULbHR sk+JhuyEy31f1Fiq42N5pGRTMNm8X6aH1KyRl9Kk9zGKFvdxiMsZsqAHrLoiS16Hg0 M8bxwrLjxbbSQ== Subject: [PATCH 2/4] SUNRPC: Remove dprintk() in svc_handle_xprt() From: Chuck Lever To: linux-nfs@vger.kernel.org Cc: Chuck Lever Date: Mon, 15 May 2023 09:32:47 -0400 Message-ID: <168415756766.9504.10410580688428555837.stgit@manet.1015granger.net> In-Reply-To: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> References: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> User-Agent: StGit/1.5 MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-nfs@vger.kernel.org From: Chuck Lever When enabled, this dprintk() fires for every incoming RPC, which is an enormous amount of log traffic. These days, after the first few hundred log messages, the system journald is just going to mute it, along with all other NFSD debug output. Let's rely on trace points for this high-traffic information instead. Signed-off-by: Chuck Lever --- net/sunrpc/svc_xprt.c | 3 --- 1 file changed, 3 deletions(-) diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c index 84e5d7d31481..b3564afc53b7 100644 --- a/net/sunrpc/svc_xprt.c +++ b/net/sunrpc/svc_xprt.c @@ -833,9 +833,6 @@ static int svc_handle_xprt(struct svc_rqst *rqstp, struct svc_xprt *xprt) svc_xprt_received(xprt); } else if (svc_xprt_reserve_slot(rqstp, xprt)) { /* XPT_DATA|XPT_DEFERRED case: */ - dprintk("svc: server %p, pool %u, transport %p, inuse=%d\n", - rqstp, rqstp->rq_pool->sp_id, xprt, - kref_read(&xprt->xpt_ref)); rqstp->rq_deferred = svc_deferred_dequeue(xprt); if (rqstp->rq_deferred) len = svc_deferred_recv(rqstp); From patchwork Mon May 15 13:32:53 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Chuck Lever X-Patchwork-Id: 13241470 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 777DBC77B7D for ; Mon, 15 May 2023 13:33:02 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S240863AbjEONdB (ORCPT ); Mon, 15 May 2023 09:33:01 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:48294 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S241913AbjEONc6 (ORCPT ); Mon, 15 May 2023 09:32:58 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 1065119AE for ; Mon, 15 May 2023 06:32:56 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id 9FFB4617FB for ; Mon, 15 May 2023 13:32:55 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id DCA35C433EF; Mon, 15 May 2023 13:32:54 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1684157575; bh=Z15hsD/8FFDGUqV7uZIf9TkSoakYKb4C/ksvcrcRi7c=; h=Subject:From:To:Cc:Date:In-Reply-To:References:From; b=GOkOo8hL87xQ+A0NH/WZLTj0ZEpJ81K3UHlzrY4T0FCrBrK8bn0Mlw/u9S7WY/VE+ QJMF7RhsQxzRT7ftNYOy8/mCYGf8Q3q+jGaTD91V9xoLzjof+EuHH5GtidOpHP5QXV zhYHJVrkbHwWOQblhxd1P9Xph6bS/pYZxfZpyi+ZRyWckrskkLCLQXv2sv7YCO7NTc RnqmyaUjczXDg8fJ/Hfn5nlvMGFsrwAYJVmqwsDnpM8pobvCFQ63MMYhqq3Gh0pq3m 9EPQCzsun0NM8SuKnyCp/AbOahEb+RjIW3pVH2MmS56Yr19NN5ZGNVVJg8fWRIonpn Y4Xo6QtV8CTzQ== Subject: [PATCH 3/4] SUNRPC: Improve observability in svc_tcp_accept() From: Chuck Lever To: linux-nfs@vger.kernel.org Cc: Chuck Lever Date: Mon, 15 May 2023 09:32:53 -0400 Message-ID: <168415757392.9504.14836685251349712202.stgit@manet.1015granger.net> In-Reply-To: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> References: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> User-Agent: StGit/1.5 MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-nfs@vger.kernel.org From: Chuck Lever The -ENOMEM arm could fire repeatedly if the system runs low on memory, so remove it. Don't bother to trace -EAGAIN error events, since those fire after a listener is created (with no work done) and once again after an accept has been handled successfully (again, with no work done). Signed-off-by: Chuck Lever --- net/sunrpc/svcsock.c | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c index e0fb65e90af2..2058641ab9f6 100644 --- a/net/sunrpc/svcsock.c +++ b/net/sunrpc/svcsock.c @@ -885,13 +885,8 @@ static struct svc_xprt *svc_tcp_accept(struct svc_xprt *xprt) clear_bit(XPT_CONN, &svsk->sk_xprt.xpt_flags); err = kernel_accept(sock, &newsock, O_NONBLOCK); if (err < 0) { - if (err == -ENOMEM) - printk(KERN_WARNING "%s: no more sockets!\n", - serv->sv_name); - else if (err != -EAGAIN) - net_warn_ratelimited("%s: accept failed (err %d)!\n", - serv->sv_name, -err); - trace_svcsock_accept_err(xprt, serv->sv_name, err); + if (err != -EAGAIN) + trace_svcsock_accept_err(xprt, serv->sv_name, err); return NULL; } set_bit(XPT_CONN, &svsk->sk_xprt.xpt_flags); From patchwork Mon May 15 13:33:00 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Chuck Lever X-Patchwork-Id: 13241471 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 9AD9BC77B7D for ; Mon, 15 May 2023 13:33:07 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S241883AbjEONdG (ORCPT ); Mon, 15 May 2023 09:33:06 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:48328 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S241879AbjEONdG (ORCPT ); Mon, 15 May 2023 09:33:06 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 54516E69 for ; Mon, 15 May 2023 06:33:02 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id E5408617FB for ; Mon, 15 May 2023 13:33:01 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 33754C433EF; Mon, 15 May 2023 13:33:01 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1684157581; bh=UX5dBEOvzI+VJ3/nDoYVwDa423Kh9seDFIkHWcTue6U=; h=Subject:From:To:Cc:Date:In-Reply-To:References:From; b=AHFOaLrJfsOVzi+tsd1sqSf65oxMoZMV2J7+SEEpwVNvLFzWNDK89OwyJ4Ov7dj7U tSjdTG4PxzqMd6cWNOhRqZS/tAeEumDb9Wet0CQAIxuOQIah0m9UPcT9zg0AWjSTEA fOLPFYRtsLvoZoRo3nwBHWJNXX7HRCb5DLQD+UfDjJpNaEaVno15fleMNscOJLlYFd lKHptxEmkdEsQn494qwvfwK4qwJ8W68xAxm96zkSW7r1enykxcAngO2ODUXxR64gcq hEpfVCE26m6HABTi/NoQKeb/1GDQlfH5rDAEtLqybZscLfAnzf4edibK1PlH4w2RBC No0qWZ+LIxQrw== Subject: [PATCH 4/4] SUNRPC: Trace struct svc_sock lifetime events From: Chuck Lever To: linux-nfs@vger.kernel.org Cc: Chuck Lever Date: Mon, 15 May 2023 09:33:00 -0400 Message-ID: <168415758025.9504.3906067170627211847.stgit@manet.1015granger.net> In-Reply-To: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> References: <168415745478.9504.1882537002036193828.stgit@manet.1015granger.net> User-Agent: StGit/1.5 MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-nfs@vger.kernel.org From: Chuck Lever 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. Signed-off-by: Chuck Lever --- include/trace/events/sunrpc.h | 39 +++++++++++++++++++++++++++------------ net/sunrpc/svcsock.c | 4 +++- 2 files changed, 30 insertions(+), 13 deletions(-) diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h index 31bc7025cb44..69e42ef30979 100644 --- a/include/trace/events/sunrpc.h +++ b/include/trace/events/sunrpc.h @@ -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( diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c index 2058641ab9f6..e30716248989 100644 --- a/net/sunrpc/svcsock.c +++ b/net/sunrpc/svcsock.c @@ -1476,7 +1476,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; } @@ -1669,6 +1669,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);