2021-10-13 14:47:20

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 0/6] Deprecate dprintk in svcrdma

This patch series moves forward with the removal of dprintk in
SUNRPC in favor of tracepoints. This is the last step for the
svcrdma component.

---

Chuck Lever (6):
svcrdma: Remove dprintk() call sites in module handlers
svcrdma: Remove dprintk call site in svc_rdma_create_xprt()
svcrdma: Remove dprintk call site in svc_rdma_parse_connect_private()
svcrdma: Remove dprintk call sites during QP creation
svcrdma: Remove dprintk call sites during accept
svcrdma: Remove include/linux/sunrpc/debug.h


net/sunrpc/xprtrdma/svc_rdma.c | 9 ------
net/sunrpc/xprtrdma/svc_rdma_recvfrom.c | 1 -
net/sunrpc/xprtrdma/svc_rdma_sendto.c | 1 -
net/sunrpc/xprtrdma/svc_rdma_transport.c | 37 ++----------------------
4 files changed, 3 insertions(+), 45 deletions(-)

--
Chuck Lever


2021-10-13 14:47:30

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 2/6] svcrdma: Remove dprintk call site in svc_rdma_create_xprt()

Deprecation. Generally a dprintk() that appears during a memory
exhaustion scenario is unnecessary and can even be
counterproductive.

Signed-off-by: Chuck Lever <[email protected]>
---
net/sunrpc/xprtrdma/svc_rdma_transport.c | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/net/sunrpc/xprtrdma/svc_rdma_transport.c b/net/sunrpc/xprtrdma/svc_rdma_transport.c
index 94b20fb47135..9aea253af2da 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_transport.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_transport.c
@@ -129,10 +129,9 @@ static struct svcxprt_rdma *svc_rdma_create_xprt(struct svc_serv *serv,
{
struct svcxprt_rdma *cma_xprt = kzalloc(sizeof *cma_xprt, GFP_KERNEL);

- if (!cma_xprt) {
- dprintk("svcrdma: failed to create new transport\n");
+ if (!cma_xprt)
return NULL;
- }
+
svc_xprt_init(net, &svc_rdma_class, &cma_xprt->sc_xprt, serv);
INIT_LIST_HEAD(&cma_xprt->sc_accept_q);
INIT_LIST_HEAD(&cma_xprt->sc_rq_dto_q);

2021-10-13 14:47:53

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 5/6] svcrdma: Remove dprintk call sites during accept

Deprecation. Most of this information is available from other
tracepoints.

Signed-off-by: Chuck Lever <[email protected]>
---
net/sunrpc/xprtrdma/svc_rdma_transport.c | 16 ----------------
1 file changed, 16 deletions(-)

diff --git a/net/sunrpc/xprtrdma/svc_rdma_transport.c b/net/sunrpc/xprtrdma/svc_rdma_transport.c
index e105e2d89b9b..acfde6e1594c 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_transport.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_transport.c
@@ -54,14 +54,12 @@
#include <rdma/rw.h>

#include <linux/sunrpc/addr.h>
-#include <linux/sunrpc/debug.h>
#include <linux/sunrpc/svc_xprt.h>
#include <linux/sunrpc/svc_rdma.h>

#include "xprt_rdma.h"
#include <trace/events/rpcrdma.h>

-#define RPCDBG_FACILITY RPCDBG_SVCXPRT

static struct svcxprt_rdma *svc_rdma_create_xprt(struct svc_serv *serv,
struct net *net);
@@ -365,7 +363,6 @@ static struct svc_xprt *svc_rdma_accept(struct svc_xprt *xprt)
unsigned int ctxts, rq_depth;
struct ib_device *dev;
int ret = 0;
- RPC_IFDEBUG(struct sockaddr *sap);

listen_rdma = container_of(xprt, struct svcxprt_rdma, sc_xprt);
clear_bit(XPT_CONN, &xprt->xpt_flags);
@@ -492,19 +489,6 @@ static struct svc_xprt *svc_rdma_accept(struct svc_xprt *xprt)
goto errout;
}

-#if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
- dprintk("svcrdma: new connection %p accepted:\n", newxprt);
- sap = (struct sockaddr *)&newxprt->sc_cm_id->route.addr.src_addr;
- dprintk(" local address : %pIS:%u\n", sap, rpc_get_port(sap));
- sap = (struct sockaddr *)&newxprt->sc_cm_id->route.addr.dst_addr;
- dprintk(" remote address : %pIS:%u\n", sap, rpc_get_port(sap));
- dprintk(" max_sge : %d\n", newxprt->sc_max_send_sges);
- dprintk(" sq_depth : %d\n", newxprt->sc_sq_depth);
- dprintk(" rdma_rw_ctxs : %d\n", ctxts);
- dprintk(" max_requests : %d\n", newxprt->sc_max_requests);
- dprintk(" ord : %d\n", conn_param.initiator_depth);
-#endif
-
return &newxprt->sc_xprt;

errout:

2021-10-13 14:47:56

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 3/6] svcrdma: Remove dprintk call site in svc_rdma_parse_connect_private()

Deprecation. The effect of the RPCRDMA_CMP_F_SND_W_INV_OK setting is
obvious from subsequent server activity.

Signed-off-by: Chuck Lever <[email protected]>
---
net/sunrpc/xprtrdma/svc_rdma_transport.c | 9 +--------
1 file changed, 1 insertion(+), 8 deletions(-)

diff --git a/net/sunrpc/xprtrdma/svc_rdma_transport.c b/net/sunrpc/xprtrdma/svc_rdma_transport.c
index 9aea253af2da..11cecfb7761a 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_transport.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_transport.c
@@ -164,16 +164,9 @@ svc_rdma_parse_connect_private(struct svcxprt_rdma *newxprt,

if (pmsg &&
pmsg->cp_magic == rpcrdma_cmp_magic &&
- pmsg->cp_version == RPCRDMA_CMP_VERSION) {
+ pmsg->cp_version == RPCRDMA_CMP_VERSION)
newxprt->sc_snd_w_inv = pmsg->cp_flags &
RPCRDMA_CMP_F_SND_W_INV_OK;
-
- dprintk("svcrdma: client send_size %u, recv_size %u "
- "remote inv %ssupported\n",
- rpcrdma_decode_buffer_size(pmsg->cp_send_size),
- rpcrdma_decode_buffer_size(pmsg->cp_recv_size),
- newxprt->sc_snd_w_inv ? "" : "un");
- }
}

/*

2021-10-13 14:48:04

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 6/6] svcrdma: Remove include/linux/sunrpc/debug.h

Deprecation. svcrdma no longer uses dprintk.

Signed-off-by: Chuck Lever <[email protected]>
---
net/sunrpc/xprtrdma/svc_rdma_recvfrom.c | 1 -
net/sunrpc/xprtrdma/svc_rdma_sendto.c | 1 -
2 files changed, 2 deletions(-)

diff --git a/net/sunrpc/xprtrdma/svc_rdma_recvfrom.c b/net/sunrpc/xprtrdma/svc_rdma_recvfrom.c
index cf76a6ad127b..3be39fc5cec4 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_recvfrom.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_recvfrom.c
@@ -99,7 +99,6 @@
#include <rdma/rdma_cm.h>

#include <linux/sunrpc/xdr.h>
-#include <linux/sunrpc/debug.h>
#include <linux/sunrpc/rpc_rdma.h>
#include <linux/sunrpc/svc_rdma.h>

diff --git a/net/sunrpc/xprtrdma/svc_rdma_sendto.c b/net/sunrpc/xprtrdma/svc_rdma_sendto.c
index 22a871e6fe4d..e973e5b3ce08 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_sendto.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_sendto.c
@@ -105,7 +105,6 @@
#include <rdma/ib_verbs.h>
#include <rdma/rdma_cm.h>

-#include <linux/sunrpc/debug.h>
#include <linux/sunrpc/svc_rdma.h>

#include "xprt_rdma.h"

2021-10-13 14:48:34

by Chuck Lever III

[permalink] [raw]
Subject: [PATCH v1 4/6] svcrdma: Remove dprintk call sites during QP creation

Deprecation. Printing pointer addresses in the log isn't valuable,
and the other information is now available from the core's qp_create
tracepoint.

Signed-off-by: Chuck Lever <[email protected]>
---
net/sunrpc/xprtrdma/svc_rdma_transport.c | 7 -------
1 file changed, 7 deletions(-)

diff --git a/net/sunrpc/xprtrdma/svc_rdma_transport.c b/net/sunrpc/xprtrdma/svc_rdma_transport.c
index 11cecfb7761a..e105e2d89b9b 100644
--- a/net/sunrpc/xprtrdma/svc_rdma_transport.c
+++ b/net/sunrpc/xprtrdma/svc_rdma_transport.c
@@ -445,13 +445,6 @@ static struct svc_xprt *svc_rdma_accept(struct svc_xprt *xprt)
qp_attr.qp_type = IB_QPT_RC;
qp_attr.send_cq = newxprt->sc_sq_cq;
qp_attr.recv_cq = newxprt->sc_rq_cq;
- dprintk("svcrdma: newxprt->sc_cm_id=%p, newxprt->sc_pd=%p\n",
- newxprt->sc_cm_id, newxprt->sc_pd);
- dprintk(" cap.max_send_wr = %d, cap.max_recv_wr = %d\n",
- qp_attr.cap.max_send_wr, qp_attr.cap.max_recv_wr);
- dprintk(" cap.max_send_sge = %d, cap.max_recv_sge = %d\n",
- qp_attr.cap.max_send_sge, qp_attr.cap.max_recv_sge);
-
ret = rdma_create_qp(newxprt->sc_cm_id, newxprt->sc_pd, &qp_attr);
if (ret) {
trace_svcrdma_qp_err(newxprt, ret);

2021-10-13 16:03:20

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH v1 0/6] Deprecate dprintk in svcrdma

On Wed, Oct 13, 2021 at 10:46:49AM -0400, Chuck Lever wrote:
> This patch series moves forward with the removal of dprintk in
> SUNRPC in favor of tracepoints. This is the last step for the
> svcrdma component.

Makes sense to me.

I would like some (very short) documentation, somewhere. Partly just
for my sake! I'm not sure exactly what to recommend to bug reporters.

I guess

trace-cmd record -e 'sunrpc:*
trace-cmd report

would be a rough substitute for "rpcdebug -m rpc -s all"?

Do we have a couple examples of issues that could be diagnosed with
tracepoints? In the past I don't feel like I've ended up using dprintks
all that much; somehow they're not usually where I need them. But maybe
that's just me. And maybe as we put more thought into where tracepoints
should be, they'll get more useful.

Documentation/filesystems/nfs/, or the linux-nfs wiki, could be easy
places to put it. Though *something* in the man pages would be nice.
At a minimum, a warning in rpcdebug(8) that we're gradually phasing out
dprintks.

--b.

>
> ---
>
> Chuck Lever (6):
> svcrdma: Remove dprintk() call sites in module handlers
> svcrdma: Remove dprintk call site in svc_rdma_create_xprt()
> svcrdma: Remove dprintk call site in svc_rdma_parse_connect_private()
> svcrdma: Remove dprintk call sites during QP creation
> svcrdma: Remove dprintk call sites during accept
> svcrdma: Remove include/linux/sunrpc/debug.h
>
>
> net/sunrpc/xprtrdma/svc_rdma.c | 9 ------
> net/sunrpc/xprtrdma/svc_rdma_recvfrom.c | 1 -
> net/sunrpc/xprtrdma/svc_rdma_sendto.c | 1 -
> net/sunrpc/xprtrdma/svc_rdma_transport.c | 37 ++----------------------
> 4 files changed, 3 insertions(+), 45 deletions(-)
>
> --
> Chuck Lever

2021-10-13 16:51:17

by Chuck Lever III

[permalink] [raw]
Subject: Re: [PATCH v1 0/6] Deprecate dprintk in svcrdma



> On Oct 13, 2021, at 11:59 AM, J. Bruce Fields <[email protected]> wrote:
>
> On Wed, Oct 13, 2021 at 10:46:49AM -0400, Chuck Lever wrote:
>> This patch series moves forward with the removal of dprintk in
>> SUNRPC in favor of tracepoints. This is the last step for the
>> svcrdma component.
>
> Makes sense to me.
>
> I would like some (very short) documentation, somewhere. Partly just
> for my sake! I'm not sure exactly what to recommend to bug reporters.
>
> I guess
>
> trace-cmd record -e 'sunrpc:*'
> trace-cmd report
>
> would be a rough substitute for "rpcdebug -m rpc -s all"?

It would, but tracepoints can be enabled one event
at a time. If you're looking for a direct replacement
for a specific rpcdebug invocation, it might be better
to examine the current sunrpc debug facilities and
provide specific command lines to mimic those.

"rpcdebug -vh" gives us:

rpc xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache all
nfs vfs dircache lookupcache pagecache proc xdr file root callback client mount fscache pnfs pnfs_ld state all
nfsd sock fh export svc proc fileop auth repcache xdr lockd all
nlm svc client clntlock svclock monitor clntsubs svcsubs hostcache xdr all


If tracepoints are named carefully, we can provide
specific command lines to enable them as groups. So,
for instance, I was thinking rpcdebug might display:

trace-cmd list | grep svcrdma

to list tracepoints related to server side RDMA, or:

trace-cmd list | grep svcsock

to show tracepoints related to server side sockets.
Then:

trace-cmd record -e sunrpc:svcsock\*

enables just the socket-related trace events, which
coincidentally happens to line up with:

rpcdebug -m rpc -s svcsock


> Do we have a couple examples of issues that could be diagnosed with
> tracepoints?

Anything you can do with dprintk you can do with trace
points. Plus because tracepoints are lower overhead, they
can be enabled and used in production environments,
unlike dprintk.

Also, tracepoints can trigger specific user space actions
when they fire. You could for example set up a tracepoint
in the RPC client that fires when a retransmit timeout
occurs, and it could trigger a script to start tcpdump.


> In the past I don't feel like I've ended up using dprintks
> all that much; somehow they're not usually where I need them. But maybe
> that's just me. And maybe as we put more thought into where tracepoints
> should be, they'll get more useful.

> Documentation/filesystems/nfs/, or the linux-nfs wiki, could be easy
> places to put it. Though *something* in the man pages would be nice.
> At a minimum, a warning in rpcdebug(8) that we're gradually phasing out
> dprintks.

As I understood the conversation last week, SteveD and
DaveW volunteered to be responsible for changes to
rpcdebug?

So far we haven't had much documentation for dprintk. That
means we are starting more or less from scratch for
explaining observability in the NFS stacks. Free rein, and
all that.

--
Chuck Lever



2021-10-13 18:37:25

by David Wysochanski

[permalink] [raw]
Subject: Re: [PATCH v1 0/6] Deprecate dprintk in svcrdma

On Wed, Oct 13, 2021 at 12:50 PM Chuck Lever III <[email protected]> wrote:
>
>
>
> > On Oct 13, 2021, at 11:59 AM, J. Bruce Fields <[email protected]> wrote:
> >
> > On Wed, Oct 13, 2021 at 10:46:49AM -0400, Chuck Lever wrote:
> >> This patch series moves forward with the removal of dprintk in
> >> SUNRPC in favor of tracepoints. This is the last step for the
> >> svcrdma component.
> >
> > Makes sense to me.
> >
> > I would like some (very short) documentation, somewhere. Partly just
> > for my sake! I'm not sure exactly what to recommend to bug reporters.
> >
> > I guess
> >
> > trace-cmd record -e 'sunrpc:*'
> > trace-cmd report
> >
> > would be a rough substitute for "rpcdebug -m rpc -s all"?
>
> It would, but tracepoints can be enabled one event
> at a time. If you're looking for a direct replacement
> for a specific rpcdebug invocation, it might be better
> to examine the current sunrpc debug facilities and
> provide specific command lines to mimic those.
>
> "rpcdebug -vh" gives us:
>
> rpc xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache all
> nfs vfs dircache lookupcache pagecache proc xdr file root callback client mount fscache pnfs pnfs_ld state all
> nfsd sock fh export svc proc fileop auth repcache xdr lockd all
> nlm svc client clntlock svclock monitor clntsubs svcsubs hostcache xdr all
>
>
> If tracepoints are named carefully, we can provide
> specific command lines to enable them as groups. So,
> for instance, I was thinking rpcdebug might display:
>
> trace-cmd list | grep svcrdma
>
> to list tracepoints related to server side RDMA, or:
>
> trace-cmd list | grep svcsock
>
> to show tracepoints related to server side sockets.
> Then:
>
> trace-cmd record -e sunrpc:svcsock\*
>
> enables just the socket-related trace events, which
> coincidentally happens to line up with:
>
> rpcdebug -m rpc -s svcsock
>
>
> > Do we have a couple examples of issues that could be diagnosed with
> > tracepoints?
>
> Anything you can do with dprintk you can do with trace
> points. Plus because tracepoints are lower overhead, they
> can be enabled and used in production environments,
> unlike dprintk.
>
> Also, tracepoints can trigger specific user space actions
> when they fire. You could for example set up a tracepoint
> in the RPC client that fires when a retransmit timeout
> occurs, and it could trigger a script to start tcpdump.
>
>
> > In the past I don't feel like I've ended up using dprintks
> > all that much; somehow they're not usually where I need them. But maybe
> > that's just me. And maybe as we put more thought into where tracepoints
> > should be, they'll get more useful.
>
> > Documentation/filesystems/nfs/, or the linux-nfs wiki, could be easy
> > places to put it. Though *something* in the man pages would be nice.
> > At a minimum, a warning in rpcdebug(8) that we're gradually phasing out
> > dprintks.
>
> As I understood the conversation last week, SteveD and
> DaveW volunteered to be responsible for changes to
> rpcdebug?
>

Well I don't remember it exactly like that, but it's probably close.

I made a suggestion for the last kernel patch that deprecates any
rpcdebug facility, to leave one dfprintk in, stating there is no
information in the kernel anymore for this facility, so not to expect
this rpcdebug flag to produce any meaningful debug output, and
possibly redirect to ftrace facilities. I brought that idea up
because of my fscache patches which totally removed the last dfprintk
in NFS fscache, and I wasn't sure what the deprecation procedure
was. As I recall you didn't like that idea as it was never done before
with other rpcdebug flag deprecations, and it was shot down.

I suppose we could put the same type of userspace patch to rpcdebug
that looks for kernel versions and prints a message if someone tries
to use a deprecated flag? Would that be better?


> So far we haven't had much documentation for dprintk. That
> means we are starting more or less from scratch for
> explaining observability in the NFS stacks. Free rein, and
> all that.
>
> --
> Chuck Lever
>
>
>

2021-10-13 21:04:53

by Chuck Lever III

[permalink] [raw]
Subject: Re: [PATCH v1 0/6] Deprecate dprintk in svcrdma



> On Oct 13, 2021, at 2:35 PM, David Wysochanski <[email protected]> wrote:
>
> On Wed, Oct 13, 2021 at 12:50 PM Chuck Lever III <[email protected]> wrote:
>>
>>
>>
>>> On Oct 13, 2021, at 11:59 AM, J. Bruce Fields <[email protected]> wrote:
>>>
>>> On Wed, Oct 13, 2021 at 10:46:49AM -0400, Chuck Lever wrote:
>>>> This patch series moves forward with the removal of dprintk in
>>>> SUNRPC in favor of tracepoints. This is the last step for the
>>>> svcrdma component.
>>>
>>> Makes sense to me.
>>>
>>> I would like some (very short) documentation, somewhere. Partly just
>>> for my sake! I'm not sure exactly what to recommend to bug reporters.
>>>
>>> I guess
>>>
>>> trace-cmd record -e 'sunrpc:*'
>>> trace-cmd report
>>>
>>> would be a rough substitute for "rpcdebug -m rpc -s all"?
>>
>> It would, but tracepoints can be enabled one event
>> at a time. If you're looking for a direct replacement
>> for a specific rpcdebug invocation, it might be better
>> to examine the current sunrpc debug facilities and
>> provide specific command lines to mimic those.
>>
>> "rpcdebug -vh" gives us:
>>
>> rpc xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache all
>> nfs vfs dircache lookupcache pagecache proc xdr file root callback client mount fscache pnfs pnfs_ld state all
>> nfsd sock fh export svc proc fileop auth repcache xdr lockd all
>> nlm svc client clntlock svclock monitor clntsubs svcsubs hostcache xdr all
>>
>>
>> If tracepoints are named carefully, we can provide
>> specific command lines to enable them as groups. So,
>> for instance, I was thinking rpcdebug might display:
>>
>> trace-cmd list | grep svcrdma
>>
>> to list tracepoints related to server side RDMA, or:
>>
>> trace-cmd list | grep svcsock
>>
>> to show tracepoints related to server side sockets.
>> Then:
>>
>> trace-cmd record -e sunrpc:svcsock\*
>>
>> enables just the socket-related trace events, which
>> coincidentally happens to line up with:
>>
>> rpcdebug -m rpc -s svcsock
>>
>>
>>> Do we have a couple examples of issues that could be diagnosed with
>>> tracepoints?
>>
>> Anything you can do with dprintk you can do with trace
>> points. Plus because tracepoints are lower overhead, they
>> can be enabled and used in production environments,
>> unlike dprintk.
>>
>> Also, tracepoints can trigger specific user space actions
>> when they fire. You could for example set up a tracepoint
>> in the RPC client that fires when a retransmit timeout
>> occurs, and it could trigger a script to start tcpdump.
>>
>>
>>> In the past I don't feel like I've ended up using dprintks
>>> all that much; somehow they're not usually where I need them. But maybe
>>> that's just me. And maybe as we put more thought into where tracepoints
>>> should be, they'll get more useful.
>>
>>> Documentation/filesystems/nfs/, or the linux-nfs wiki, could be easy
>>> places to put it. Though *something* in the man pages would be nice.
>>> At a minimum, a warning in rpcdebug(8) that we're gradually phasing out
>>> dprintks.
>>
>> As I understood the conversation last week, SteveD and
>> DaveW volunteered to be responsible for changes to
>> rpcdebug?
>>
>
> Well I don't remember it exactly like that, but it's probably close.
>
> I made a suggestion for the last kernel patch that deprecates any
> rpcdebug facility, to leave one dfprintk in, stating there is no
> information in the kernel anymore for this facility, so not to expect
> this rpcdebug flag to produce any meaningful debug output, and
> possibly redirect to ftrace facilities. I brought that idea up
> because of my fscache patches which totally removed the last dfprintk
> in NFS fscache, and I wasn't sure what the deprecation procedure
> was. As I recall you didn't like that idea as it was never done before
> with other rpcdebug flag deprecations, and it was shot down.
>
> I suppose we could put the same type of userspace patch to rpcdebug
> that looks for kernel versions and prints a message if someone tries
> to use a deprecated flag? Would that be better?

I don't recall discussing leaving one dprintk in place for
each facility. My impression is that changing rpcdebug in
this manner is what was decided during that conversation.


>> So far we haven't had much documentation for dprintk. That
>> means we are starting more or less from scratch for
>> explaining observability in the NFS stacks. Free rein, and
>> all that.
>>
>> --
>> Chuck Lever

--
Chuck Lever



2021-11-03 07:58:08

by David Wysochanski

[permalink] [raw]
Subject: Re: [PATCH v1 0/6] Deprecate dprintk in svcrdma

On Wed, Oct 13, 2021 at 5:03 PM Chuck Lever III <[email protected]> wrote:
>
>
>
> > On Oct 13, 2021, at 2:35 PM, David Wysochanski <[email protected]> wrote:
> >
> > On Wed, Oct 13, 2021 at 12:50 PM Chuck Lever III <[email protected]> wrote:
> >>
> >>
> >>
> >>> On Oct 13, 2021, at 11:59 AM, J. Bruce Fields <[email protected]> wrote:
> >>>
> >>> On Wed, Oct 13, 2021 at 10:46:49AM -0400, Chuck Lever wrote:
> >>>> This patch series moves forward with the removal of dprintk in
> >>>> SUNRPC in favor of tracepoints. This is the last step for the
> >>>> svcrdma component.
> >>>
> >>> Makes sense to me.
> >>>
> >>> I would like some (very short) documentation, somewhere. Partly just
> >>> for my sake! I'm not sure exactly what to recommend to bug reporters.
> >>>
> >>> I guess
> >>>
> >>> trace-cmd record -e 'sunrpc:*'
> >>> trace-cmd report
> >>>
> >>> would be a rough substitute for "rpcdebug -m rpc -s all"?
> >>
> >> It would, but tracepoints can be enabled one event
> >> at a time. If you're looking for a direct replacement
> >> for a specific rpcdebug invocation, it might be better
> >> to examine the current sunrpc debug facilities and
> >> provide specific command lines to mimic those.
> >>
> >> "rpcdebug -vh" gives us:
> >>
> >> rpc xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache all
> >> nfs vfs dircache lookupcache pagecache proc xdr file root callback client mount fscache pnfs pnfs_ld state all
> >> nfsd sock fh export svc proc fileop auth repcache xdr lockd all
> >> nlm svc client clntlock svclock monitor clntsubs svcsubs hostcache xdr all
> >>
> >>
> >> If tracepoints are named carefully, we can provide
> >> specific command lines to enable them as groups. So,
> >> for instance, I was thinking rpcdebug might display:
> >>
> >> trace-cmd list | grep svcrdma
> >>
> >> to list tracepoints related to server side RDMA, or:
> >>
> >> trace-cmd list | grep svcsock
> >>
> >> to show tracepoints related to server side sockets.
> >> Then:
> >>
> >> trace-cmd record -e sunrpc:svcsock\*
> >>
> >> enables just the socket-related trace events, which
> >> coincidentally happens to line up with:
> >>
> >> rpcdebug -m rpc -s svcsock
> >>
> >>
> >>> Do we have a couple examples of issues that could be diagnosed with
> >>> tracepoints?
> >>
> >> Anything you can do with dprintk you can do with trace
> >> points. Plus because tracepoints are lower overhead, they
> >> can be enabled and used in production environments,
> >> unlike dprintk.
> >>
> >> Also, tracepoints can trigger specific user space actions
> >> when they fire. You could for example set up a tracepoint
> >> in the RPC client that fires when a retransmit timeout
> >> occurs, and it could trigger a script to start tcpdump.
> >>
> >>
> >>> In the past I don't feel like I've ended up using dprintks
> >>> all that much; somehow they're not usually where I need them. But maybe
> >>> that's just me. And maybe as we put more thought into where tracepoints
> >>> should be, they'll get more useful.
> >>
> >>> Documentation/filesystems/nfs/, or the linux-nfs wiki, could be easy
> >>> places to put it. Though *something* in the man pages would be nice.
> >>> At a minimum, a warning in rpcdebug(8) that we're gradually phasing out
> >>> dprintks.
> >>
> >> As I understood the conversation last week, SteveD and
> >> DaveW volunteered to be responsible for changes to
> >> rpcdebug?
> >>
> >
> > Well I don't remember it exactly like that, but it's probably close.
> >
> > I made a suggestion for the last kernel patch that deprecates any
> > rpcdebug facility, to leave one dfprintk in, stating there is no
> > information in the kernel anymore for this facility, so not to expect
> > this rpcdebug flag to produce any meaningful debug output, and
> > possibly redirect to ftrace facilities. I brought that idea up
> > because of my fscache patches which totally removed the last dfprintk
> > in NFS fscache, and I wasn't sure what the deprecation procedure
> > was. As I recall you didn't like that idea as it was never done before
> > with other rpcdebug flag deprecations, and it was shot down.
> >
> > I suppose we could put the same type of userspace patch to rpcdebug
> > that looks for kernel versions and prints a message if someone tries
> > to use a deprecated flag? Would that be better?
>
> I don't recall discussing leaving one dprintk in place for
> each facility. My impression is that changing rpcdebug in
> this manner is what was decided during that conversation.
>

Just to follow up on this since I think this was an action item more
appropriate for me.
FYI, I have spoken to a couple Red Hat support engineers and asked
them to work on:
1. man page update for rpcdebug
2. rpcdebug warning if a flag is enabled on a kernel that does not
produce any output

They are making good progress and I hope they will post something to
the list within week or two.



>
> >> So far we haven't had much documentation for dprintk. That
> >> means we are starting more or less from scratch for
> >> explaining observability in the NFS stacks. Free rein, and
> >> all that.
> >>
> >> --
> >> Chuck Lever
>
> --
> Chuck Lever
>
>
>