diff mbox series

[v4,3/3] NFSD: add CB_RECALL_ANY tracepoints

Message ID 1668053831-7662-4-git-send-email-dai.ngo@oracle.com (mailing list archive)
State New, archived
Headers show
Series add support for CB_RECALL_ANY and the delegation shrinker | expand

Commit Message

Dai Ngo Nov. 10, 2022, 4:17 a.m. UTC
Add tracepoints to trace start and end of CB_RECALL_ANY operation.

Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
---
 fs/nfsd/nfs4state.c |  2 ++
 fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 55 insertions(+)

Comments

Chuck Lever Nov. 11, 2022, 3:25 p.m. UTC | #1
> On Nov 9, 2022, at 11:17 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
> 
> Add tracepoints to trace start and end of CB_RECALL_ANY operation.
> 
> Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
> ---
> fs/nfsd/nfs4state.c |  2 ++
> fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
> 2 files changed, 55 insertions(+)
> 
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index 813cdb67b370..eac7212c9218 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -2859,6 +2859,7 @@ static int
> nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
> 				struct rpc_task *task)
> {
> +	trace_nfsd_cb_recall_any_done(cb, task);
> 	switch (task->tk_status) {
> 	case -NFS4ERR_DELAY:
> 		rpc_delay(task, 2 * HZ);
> @@ -6242,6 +6243,7 @@ deleg_reaper(struct work_struct *deleg_work)
> 		clp->cl_ra->ra_keep = 0;
> 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
> 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
> +		trace_nfsd_cb_recall_any(clp->cl_ra);
> 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
> 	}
> 
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 06a96e955bd0..efc69c96bcbd 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -9,9 +9,11 @@
> #define _NFSD_TRACE_H
> 
> #include <linux/tracepoint.h>
> +#include <linux/sunrpc/xprt.h>
> 
> #include "export.h"
> #include "nfsfh.h"
> +#include "xdr4.h"
> 
> #define NFSD_TRACE_PROC_RES_FIELDS \
> 		__field(unsigned int, netns_ino) \
> @@ -1510,6 +1512,57 @@ DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
> 
> +TRACE_EVENT(nfsd_cb_recall_any,
> +	TP_PROTO(
> +		const struct nfsd4_cb_recall_any *ra
> +	),
> +	TP_ARGS(ra),
> +	TP_STRUCT__entry(
> +		__field(u32, cl_boot)
> +		__field(u32, cl_id)
> +		__field(u32, ra_keep)
> +		__field(u32, ra_bmval)
> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +	),
> +	TP_fast_assign(
> +		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
> +		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
> +		__entry->ra_keep = ra->ra_keep;
> +		__entry->ra_bmval = ra->ra_bmval[0];
> +		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
> +			sizeof(struct sockaddr_in6));
> +	),
> +	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
> +		__entry->cl_boot, __entry->cl_id,
> +		__entry->addr, __entry->ra_keep, __entry->ra_bmval
> +	)
> +);

This one should go earlier in the file, after "TRACE_EVENT(nfsd_cb_offload,"

And let's use __sockaddr() and friends like the other nfsd_cb_ tracepoints.


> +
> +TRACE_EVENT(nfsd_cb_recall_any_done,
> +	TP_PROTO(
> +		const struct nfsd4_callback *cb,
> +		const struct rpc_task *task
> +	),
> +	TP_ARGS(cb, task),
> +	TP_STRUCT__entry(
> +		__field(u32, cl_boot)
> +		__field(u32, cl_id)
> +		__field(int, status)
> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +	),
> +	TP_fast_assign(
> +		__entry->status = task->tk_status;
> +		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
> +		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
> +		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
> +			sizeof(struct sockaddr_in6));
> +	),
> +	TP_printk("client %08x:%08x addr=%pISpc status=%d",
> +		__entry->cl_boot, __entry->cl_id,
> +		__entry->addr, __entry->status
> +	)
> +);

I'd like you to change this to

DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_recall_any_done);


> +
> #endif /* _NFSD_TRACE_H */
> 
> #undef TRACE_INCLUDE_PATH
> -- 
> 2.9.5
> 

--
Chuck Lever
Dai Ngo Nov. 11, 2022, 9:34 p.m. UTC | #2
On 11/11/22 7:25 AM, Chuck Lever III wrote:
>
>> On Nov 9, 2022, at 11:17 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
>>
>> Add tracepoints to trace start and end of CB_RECALL_ANY operation.
>>
>> Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
>> ---
>> fs/nfsd/nfs4state.c |  2 ++
>> fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
>> 2 files changed, 55 insertions(+)
>>
>> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
>> index 813cdb67b370..eac7212c9218 100644
>> --- a/fs/nfsd/nfs4state.c
>> +++ b/fs/nfsd/nfs4state.c
>> @@ -2859,6 +2859,7 @@ static int
>> nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
>> 				struct rpc_task *task)
>> {
>> +	trace_nfsd_cb_recall_any_done(cb, task);
>> 	switch (task->tk_status) {
>> 	case -NFS4ERR_DELAY:
>> 		rpc_delay(task, 2 * HZ);
>> @@ -6242,6 +6243,7 @@ deleg_reaper(struct work_struct *deleg_work)
>> 		clp->cl_ra->ra_keep = 0;
>> 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
>> 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
>> +		trace_nfsd_cb_recall_any(clp->cl_ra);
>> 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
>> 	}
>>
>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>> index 06a96e955bd0..efc69c96bcbd 100644
>> --- a/fs/nfsd/trace.h
>> +++ b/fs/nfsd/trace.h
>> @@ -9,9 +9,11 @@
>> #define _NFSD_TRACE_H
>>
>> #include <linux/tracepoint.h>
>> +#include <linux/sunrpc/xprt.h>
>>
>> #include "export.h"
>> #include "nfsfh.h"
>> +#include "xdr4.h"
>>
>> #define NFSD_TRACE_PROC_RES_FIELDS \
>> 		__field(unsigned int, netns_ino) \
>> @@ -1510,6 +1512,57 @@ DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
>>
>> +TRACE_EVENT(nfsd_cb_recall_any,
>> +	TP_PROTO(
>> +		const struct nfsd4_cb_recall_any *ra
>> +	),
>> +	TP_ARGS(ra),
>> +	TP_STRUCT__entry(
>> +		__field(u32, cl_boot)
>> +		__field(u32, cl_id)
>> +		__field(u32, ra_keep)
>> +		__field(u32, ra_bmval)
>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +	),
>> +	TP_fast_assign(
>> +		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
>> +		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
>> +		__entry->ra_keep = ra->ra_keep;
>> +		__entry->ra_bmval = ra->ra_bmval[0];
>> +		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
>> +			sizeof(struct sockaddr_in6));
>> +	),
>> +	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
>> +		__entry->cl_boot, __entry->cl_id,
>> +		__entry->addr, __entry->ra_keep, __entry->ra_bmval
>> +	)
>> +);
> This one should go earlier in the file, after "TRACE_EVENT(nfsd_cb_offload,"
>
> And let's use __sockaddr() and friends like the other nfsd_cb_ tracepoints.

I tried but it did not work. I got the same error as 'nfsd_cb_args' tracepoint:

[root@nfsvmf24 ~]# uname -r
6.1.0-rc1+
[root@nfsvmf24 ~]# trace-cmd record -e nfsd_cb_args
[root@nfsvmf24 ~]# trace-cmd report
trace-cmd: No such file or directory
   Error: expected type 4 but read 5
   [nfsd:nfsd_cb_args]*function __get_sockaddr not defined*
   cpus=1
     nfsd-3976  [000]   410.956975: nfsd_cb_args: [*FAILED TO PARSE*] cl_boot=1668201586 cl_id=2938128369 prog=1073741824 ident=1 addr=ARRAY[02, 00, 80, 93, 0a, 50, 6f, 5f, 00, ..]

I also tried Fedora 36 and got same error.

Can you verify __get_sockaddr works with tracepoints on your system?

Thanks,
-Dai

>
>
>> +
>> +TRACE_EVENT(nfsd_cb_recall_any_done,
>> +	TP_PROTO(
>> +		const struct nfsd4_callback *cb,
>> +		const struct rpc_task *task
>> +	),
>> +	TP_ARGS(cb, task),
>> +	TP_STRUCT__entry(
>> +		__field(u32, cl_boot)
>> +		__field(u32, cl_id)
>> +		__field(int, status)
>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +	),
>> +	TP_fast_assign(
>> +		__entry->status = task->tk_status;
>> +		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
>> +		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
>> +		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
>> +			sizeof(struct sockaddr_in6));
>> +	),
>> +	TP_printk("client %08x:%08x addr=%pISpc status=%d",
>> +		__entry->cl_boot, __entry->cl_id,
>> +		__entry->addr, __entry->status
>> +	)
>> +);
> I'd like you to change this to
>
> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_recall_any_done);
>
>
>> +
>> #endif /* _NFSD_TRACE_H */
>>
>> #undef TRACE_INCLUDE_PATH
>> -- 
>> 2.9.5
>>
> --
> Chuck Lever
>
>
>
Chuck Lever Nov. 11, 2022, 10:02 p.m. UTC | #3
> On Nov 11, 2022, at 4:34 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
> 
> 
> On 11/11/22 7:25 AM, Chuck Lever III wrote:
>> 
>>> On Nov 9, 2022, at 11:17 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
>>> 
>>> Add tracepoints to trace start and end of CB_RECALL_ANY operation.
>>> 
>>> Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
>>> ---
>>> fs/nfsd/nfs4state.c |  2 ++
>>> fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
>>> 2 files changed, 55 insertions(+)
>>> 
>>> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
>>> index 813cdb67b370..eac7212c9218 100644
>>> --- a/fs/nfsd/nfs4state.c
>>> +++ b/fs/nfsd/nfs4state.c
>>> @@ -2859,6 +2859,7 @@ static int
>>> nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
>>> 				struct rpc_task *task)
>>> {
>>> +	trace_nfsd_cb_recall_any_done(cb, task);
>>> 	switch (task->tk_status) {
>>> 	case -NFS4ERR_DELAY:
>>> 		rpc_delay(task, 2 * HZ);
>>> @@ -6242,6 +6243,7 @@ deleg_reaper(struct work_struct *deleg_work)
>>> 		clp->cl_ra->ra_keep = 0;
>>> 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
>>> 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
>>> +		trace_nfsd_cb_recall_any(clp->cl_ra);
>>> 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
>>> 	}
>>> 
>>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>>> index 06a96e955bd0..efc69c96bcbd 100644
>>> --- a/fs/nfsd/trace.h
>>> +++ b/fs/nfsd/trace.h
>>> @@ -9,9 +9,11 @@
>>> #define _NFSD_TRACE_H
>>> 
>>> #include <linux/tracepoint.h>
>>> +#include <linux/sunrpc/xprt.h>
>>> 
>>> #include "export.h"
>>> #include "nfsfh.h"
>>> +#include "xdr4.h"
>>> 
>>> #define NFSD_TRACE_PROC_RES_FIELDS \
>>> 		__field(unsigned int, netns_ino) \
>>> @@ -1510,6 +1512,57 @@ DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
>>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
>>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
>>> 
>>> +TRACE_EVENT(nfsd_cb_recall_any,
>>> +	TP_PROTO(
>>> +		const struct nfsd4_cb_recall_any *ra
>>> +	),
>>> +	TP_ARGS(ra),
>>> +	TP_STRUCT__entry(
>>> +		__field(u32, cl_boot)
>>> +		__field(u32, cl_id)
>>> +		__field(u32, ra_keep)
>>> +		__field(u32, ra_bmval)
>>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>>> +	),
>>> +	TP_fast_assign(
>>> +		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
>>> +		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
>>> +		__entry->ra_keep = ra->ra_keep;
>>> +		__entry->ra_bmval = ra->ra_bmval[0];
>>> +		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
>>> +			sizeof(struct sockaddr_in6));
>>> +	),
>>> +	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
>>> +		__entry->cl_boot, __entry->cl_id,
>>> +		__entry->addr, __entry->ra_keep, __entry->ra_bmval
>>> +	)
>>> +);
>> This one should go earlier in the file, after "TRACE_EVENT(nfsd_cb_offload,"
>> 
>> And let's use __sockaddr() and friends like the other nfsd_cb_ tracepoints.
> 
> I tried but it did not work. I got the same error as 'nfsd_cb_args' tracepoint:
> 
> [root@nfsvmf24 ~]# uname -r
> 6.1.0-rc1+
> [root@nfsvmf24 ~]# trace-cmd record -e nfsd_cb_args
> [root@nfsvmf24 ~]# trace-cmd report
> trace-cmd: No such file or directory
>  Error: expected type 4 but read 5
>  [nfsd:nfsd_cb_args]*function __get_sockaddr not defined*
>  cpus=1
>    nfsd-3976  [000]   410.956975: nfsd_cb_args: [*FAILED TO PARSE*] cl_boot=1668201586 cl_id=2938128369 prog=1073741824 ident=1 addr=ARRAY[02, 00, 80, 93, 0a, 50, 6f, 5f, 00, ..]
> 
> I also tried Fedora 36 and got same error.
> 
> Can you verify __get_sockaddr works with tracepoints on your system?

The user space libraries still don't have support for __get_sockaddr().

Assuming that eventually those libraries will get the proper support,
in this case I'm willing to take tracepoints that don't parse.


> Thanks,
> -Dai
> 
>> 
>> 
>>> +
>>> +TRACE_EVENT(nfsd_cb_recall_any_done,
>>> +	TP_PROTO(
>>> +		const struct nfsd4_callback *cb,
>>> +		const struct rpc_task *task
>>> +	),
>>> +	TP_ARGS(cb, task),
>>> +	TP_STRUCT__entry(
>>> +		__field(u32, cl_boot)
>>> +		__field(u32, cl_id)
>>> +		__field(int, status)
>>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>>> +	),
>>> +	TP_fast_assign(
>>> +		__entry->status = task->tk_status;
>>> +		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
>>> +		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
>>> +		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
>>> +			sizeof(struct sockaddr_in6));
>>> +	),
>>> +	TP_printk("client %08x:%08x addr=%pISpc status=%d",
>>> +		__entry->cl_boot, __entry->cl_id,
>>> +		__entry->addr, __entry->status
>>> +	)
>>> +);
>> I'd like you to change this to
>> 
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_recall_any_done);
>> 
>> 
>>> +
>>> #endif /* _NFSD_TRACE_H */
>>> 
>>> #undef TRACE_INCLUDE_PATH
>>> -- 
>>> 2.9.5
>>> 
>> --
>> Chuck Lever

--
Chuck Lever
Dai Ngo Nov. 15, 2022, 5:08 a.m. UTC | #4
On 11/11/22 7:25 AM, Chuck Lever III wrote:
>
>> On Nov 9, 2022, at 11:17 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
>>
>> Add tracepoints to trace start and end of CB_RECALL_ANY operation.
>>
>> Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
>> ---
>> fs/nfsd/nfs4state.c |  2 ++
>> fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
>> 2 files changed, 55 insertions(+)
>>
>> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
>> index 813cdb67b370..eac7212c9218 100644
>> --- a/fs/nfsd/nfs4state.c
>> +++ b/fs/nfsd/nfs4state.c
>> @@ -2859,6 +2859,7 @@ static int
>> nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
>> 				struct rpc_task *task)
>> {
>> +	trace_nfsd_cb_recall_any_done(cb, task);
>> 	switch (task->tk_status) {
>> 	case -NFS4ERR_DELAY:
>> 		rpc_delay(task, 2 * HZ);
>> @@ -6242,6 +6243,7 @@ deleg_reaper(struct work_struct *deleg_work)
>> 		clp->cl_ra->ra_keep = 0;
>> 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
>> 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
>> +		trace_nfsd_cb_recall_any(clp->cl_ra);
>> 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
>> 	}
>>
>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>> index 06a96e955bd0..efc69c96bcbd 100644
>> --- a/fs/nfsd/trace.h
>> +++ b/fs/nfsd/trace.h
>> @@ -9,9 +9,11 @@
>> #define _NFSD_TRACE_H
>>
>> #include <linux/tracepoint.h>
>> +#include <linux/sunrpc/xprt.h>
>>
>> #include "export.h"
>> #include "nfsfh.h"
>> +#include "xdr4.h"
>>
>> #define NFSD_TRACE_PROC_RES_FIELDS \
>> 		__field(unsigned int, netns_ino) \
>> @@ -1510,6 +1512,57 @@ DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
>>
>> +TRACE_EVENT(nfsd_cb_recall_any,
>> +	TP_PROTO(
>> +		const struct nfsd4_cb_recall_any *ra
>> +	),
>> +	TP_ARGS(ra),
>> +	TP_STRUCT__entry(
>> +		__field(u32, cl_boot)
>> +		__field(u32, cl_id)
>> +		__field(u32, ra_keep)
>> +		__field(u32, ra_bmval)
>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +	),
>> +	TP_fast_assign(
>> +		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
>> +		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
>> +		__entry->ra_keep = ra->ra_keep;
>> +		__entry->ra_bmval = ra->ra_bmval[0];
>> +		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
>> +			sizeof(struct sockaddr_in6));
>> +	),
>> +	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
>> +		__entry->cl_boot, __entry->cl_id,
>> +		__entry->addr, __entry->ra_keep, __entry->ra_bmval
>> +	)
>> +);
> This one should go earlier in the file, after "TRACE_EVENT(nfsd_cb_offload,"
>
> And let's use __sockaddr() and friends like the other nfsd_cb_ tracepoints.
>
>
>> +
>> +TRACE_EVENT(nfsd_cb_recall_any_done,
>> +	TP_PROTO(
>> +		const struct nfsd4_callback *cb,
>> +		const struct rpc_task *task
>> +	),
>> +	TP_ARGS(cb, task),
>> +	TP_STRUCT__entry(
>> +		__field(u32, cl_boot)
>> +		__field(u32, cl_id)
>> +		__field(int, status)
>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +	),
>> +	TP_fast_assign(
>> +		__entry->status = task->tk_status;
>> +		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
>> +		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
>> +		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
>> +			sizeof(struct sockaddr_in6));
>> +	),
>> +	TP_printk("client %08x:%08x addr=%pISpc status=%d",
>> +		__entry->cl_boot, __entry->cl_id,
>> +		__entry->addr, __entry->status
>> +	)
>> +);
> I'd like you to change this to
>
> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_recall_any_done);

TP_PRORO of DEFINE_NFSD_CB_DONE_EVENT requires a stateid_t which
CB_RECALL_ANY does not have. Can we can create a dummy stateid_t
for nfsd_cb_recall_any_done?

Note that nfsd_cb_done_class does not print the server IP address
which is more useful for tracing. Should I modify nfsd_cb_recall_any_done
class to print the IP address from rpc_xprt?

-Dai

>
>
>> +
>> #endif /* _NFSD_TRACE_H */
>>
>> #undef TRACE_INCLUDE_PATH
>> -- 
>> 2.9.5
>>
> --
> Chuck Lever
>
>
>
Chuck Lever Nov. 15, 2022, 2:21 p.m. UTC | #5
> On Nov 15, 2022, at 12:08 AM, Dai Ngo <dai.ngo@oracle.com> wrote:
> 
> 
> On 11/11/22 7:25 AM, Chuck Lever III wrote:
>> 
>>> On Nov 9, 2022, at 11:17 PM, Dai Ngo <dai.ngo@oracle.com> wrote:
>>> 
>>> Add tracepoints to trace start and end of CB_RECALL_ANY operation.
>>> 
>>> Signed-off-by: Dai Ngo <dai.ngo@oracle.com>
>>> ---
>>> fs/nfsd/nfs4state.c |  2 ++
>>> fs/nfsd/trace.h     | 53 +++++++++++++++++++++++++++++++++++++++++++++++++++++
>>> 2 files changed, 55 insertions(+)
>>> 
>>> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
>>> index 813cdb67b370..eac7212c9218 100644
>>> --- a/fs/nfsd/nfs4state.c
>>> +++ b/fs/nfsd/nfs4state.c
>>> @@ -2859,6 +2859,7 @@ static int
>>> nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
>>> 				struct rpc_task *task)
>>> {
>>> +	trace_nfsd_cb_recall_any_done(cb, task);
>>> 	switch (task->tk_status) {
>>> 	case -NFS4ERR_DELAY:
>>> 		rpc_delay(task, 2 * HZ);
>>> @@ -6242,6 +6243,7 @@ deleg_reaper(struct work_struct *deleg_work)
>>> 		clp->cl_ra->ra_keep = 0;
>>> 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
>>> 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
>>> +		trace_nfsd_cb_recall_any(clp->cl_ra);
>>> 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
>>> 	}
>>> 
>>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>>> index 06a96e955bd0..efc69c96bcbd 100644
>>> --- a/fs/nfsd/trace.h
>>> +++ b/fs/nfsd/trace.h
>>> @@ -9,9 +9,11 @@
>>> #define _NFSD_TRACE_H
>>> 
>>> #include <linux/tracepoint.h>
>>> +#include <linux/sunrpc/xprt.h>
>>> 
>>> #include "export.h"
>>> #include "nfsfh.h"
>>> +#include "xdr4.h"
>>> 
>>> #define NFSD_TRACE_PROC_RES_FIELDS \
>>> 		__field(unsigned int, netns_ino) \
>>> @@ -1510,6 +1512,57 @@ DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
>>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
>>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
>>> 
>>> +TRACE_EVENT(nfsd_cb_recall_any,
>>> +	TP_PROTO(
>>> +		const struct nfsd4_cb_recall_any *ra
>>> +	),
>>> +	TP_ARGS(ra),
>>> +	TP_STRUCT__entry(
>>> +		__field(u32, cl_boot)
>>> +		__field(u32, cl_id)
>>> +		__field(u32, ra_keep)
>>> +		__field(u32, ra_bmval)
>>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>>> +	),
>>> +	TP_fast_assign(
>>> +		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
>>> +		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
>>> +		__entry->ra_keep = ra->ra_keep;
>>> +		__entry->ra_bmval = ra->ra_bmval[0];
>>> +		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
>>> +			sizeof(struct sockaddr_in6));
>>> +	),
>>> +	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
>>> +		__entry->cl_boot, __entry->cl_id,
>>> +		__entry->addr, __entry->ra_keep, __entry->ra_bmval
>>> +	)
>>> +);
>> This one should go earlier in the file, after "TRACE_EVENT(nfsd_cb_offload,"
>> 
>> And let's use __sockaddr() and friends like the other nfsd_cb_ tracepoints.
>> 
>> 
>>> +
>>> +TRACE_EVENT(nfsd_cb_recall_any_done,
>>> +	TP_PROTO(
>>> +		const struct nfsd4_callback *cb,
>>> +		const struct rpc_task *task
>>> +	),
>>> +	TP_ARGS(cb, task),
>>> +	TP_STRUCT__entry(
>>> +		__field(u32, cl_boot)
>>> +		__field(u32, cl_id)
>>> +		__field(int, status)
>>> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
>>> +	),
>>> +	TP_fast_assign(
>>> +		__entry->status = task->tk_status;
>>> +		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
>>> +		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
>>> +		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
>>> +			sizeof(struct sockaddr_in6));
>>> +	),
>>> +	TP_printk("client %08x:%08x addr=%pISpc status=%d",
>>> +		__entry->cl_boot, __entry->cl_id,
>>> +		__entry->addr, __entry->status
>>> +	)
>>> +);
>> I'd like you to change this to
>> 
>> DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_recall_any_done);
> 
> TP_PRORO of DEFINE_NFSD_CB_DONE_EVENT requires a stateid_t which
> CB_RECALL_ANY does not have. Can we can create a dummy stateid_t
> for nfsd_cb_recall_any_done?

Ah, I didn't remember that a state ID was recorded. OK, then a
separate TRACE_EVENT is appropriate for nfsd_cb_recall_any_done.


> Note that nfsd_cb_done_class does not print the server IP address
> which is more useful for tracing. Should I modify nfsd_cb_recall_any_done
> class to print the IP address from rpc_xprt?

The IP address is recorded by the Call side tracepoints. I'm OK
leaving the IP address out of the Reply side tracepoints.


> -Dai
> 
>> 
>> 
>>> +
>>> #endif /* _NFSD_TRACE_H */
>>> 
>>> #undef TRACE_INCLUDE_PATH
>>> -- 
>>> 2.9.5
>>> 
>> --
>> Chuck Lever

--
Chuck Lever
diff mbox series

Patch

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 813cdb67b370..eac7212c9218 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -2859,6 +2859,7 @@  static int
 nfsd4_cb_recall_any_done(struct nfsd4_callback *cb,
 				struct rpc_task *task)
 {
+	trace_nfsd_cb_recall_any_done(cb, task);
 	switch (task->tk_status) {
 	case -NFS4ERR_DELAY:
 		rpc_delay(task, 2 * HZ);
@@ -6242,6 +6243,7 @@  deleg_reaper(struct work_struct *deleg_work)
 		clp->cl_ra->ra_keep = 0;
 		clp->cl_ra->ra_bmval[0] = BIT(RCA4_TYPE_MASK_RDATA_DLG) |
 						BIT(RCA4_TYPE_MASK_WDATA_DLG);
+		trace_nfsd_cb_recall_any(clp->cl_ra);
 		nfsd4_run_cb(&clp->cl_ra->ra_cb);
 	}
 
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 06a96e955bd0..efc69c96bcbd 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -9,9 +9,11 @@ 
 #define _NFSD_TRACE_H
 
 #include <linux/tracepoint.h>
+#include <linux/sunrpc/xprt.h>
 
 #include "export.h"
 #include "nfsfh.h"
+#include "xdr4.h"
 
 #define NFSD_TRACE_PROC_RES_FIELDS \
 		__field(unsigned int, netns_ino) \
@@ -1510,6 +1512,57 @@  DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_notify_lock_done);
 DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_layout_done);
 DEFINE_NFSD_CB_DONE_EVENT(nfsd_cb_offload_done);
 
+TRACE_EVENT(nfsd_cb_recall_any,
+	TP_PROTO(
+		const struct nfsd4_cb_recall_any *ra
+	),
+	TP_ARGS(ra),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(u32, ra_keep)
+		__field(u32, ra_bmval)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		__entry->cl_boot = ra->ra_cb.cb_clp->cl_clientid.cl_boot;
+		__entry->cl_id = ra->ra_cb.cb_clp->cl_clientid.cl_id;
+		__entry->ra_keep = ra->ra_keep;
+		__entry->ra_bmval = ra->ra_bmval[0];
+		memcpy(__entry->addr, &ra->ra_cb.cb_clp->cl_addr,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("client %08x:%08x addr=%pISpc ra_keep=%d ra_bmval=0x%x",
+		__entry->cl_boot, __entry->cl_id,
+		__entry->addr, __entry->ra_keep, __entry->ra_bmval
+	)
+);
+
+TRACE_EVENT(nfsd_cb_recall_any_done,
+	TP_PROTO(
+		const struct nfsd4_callback *cb,
+		const struct rpc_task *task
+	),
+	TP_ARGS(cb, task),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(int, status)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		__entry->status = task->tk_status;
+		__entry->cl_boot = cb->cb_clp->cl_clientid.cl_boot;
+		__entry->cl_id = cb->cb_clp->cl_clientid.cl_id;
+		memcpy(__entry->addr, &cb->cb_clp->cl_addr,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("client %08x:%08x addr=%pISpc status=%d",
+		__entry->cl_boot, __entry->cl_id,
+		__entry->addr, __entry->status
+	)
+);
+
 #endif /* _NFSD_TRACE_H */
 
 #undef TRACE_INCLUDE_PATH