On Fri, Apr 05, 2024 at 02:40:50PM -0400, Jeff Layton wrote:
> Replace a dprintk in check_slot_seqid with a new tracepoint. Add a
> nfs4_client argument to check_slot_seqid so that we can pass the
> appropriate info to the tracepoint.
>
> Signed-off-by: Jeffrey Layton <[email protected]>
> ---
> fs/nfsd/nfs4state.c | 12 ++++++------
> fs/nfsd/trace.h | 34 ++++++++++++++++++++++++++++++++++
> 2 files changed, 40 insertions(+), 6 deletions(-)
>
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index 3cef81e196c6..5891bc3e2b0b 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -3642,10 +3642,9 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> }
>
> static __be32
> -check_slot_seqid(u32 seqid, u32 slot_seqid, int slot_inuse)
> +check_slot_seqid(struct nfs4_client *clp, u32 seqid, u32 slot_seqid, bool slot_inuse)
> {
> - dprintk("%s enter. seqid %d slot_seqid %d\n", __func__, seqid,
> - slot_seqid);
> + trace_check_slot_seqid(clp, seqid, slot_seqid, slot_inuse);
Getting rid of the dprintk: +1
Tracing slot seqid checks: +1
But I'd like something a little different for the tracepoint
itself. I can make these changes if you like to just hand this off.
Let's make this trace point into three separate trace events, one
at the nfsd4_sequence check_slot_seqid() call site, and two in
nfsd4_create_session(), like below.
Two reasons for this change:
1. Separate tracepoints in nfsd4_create_session will show whether
the client is confirmed or not
2. The tracepoint in nfsd4_sequence will normally be noisy, so
having a separate tracepoint for that case makes it easy to
disable that one while leaving the create_session tracepoints
enabled.
And, bonus: you won't have to change the synopsis of
check_slot_seqid().
> /* The slot is in use, and no response has been sent. */
> if (slot_inuse) {
> @@ -3827,7 +3826,8 @@ nfsd4_create_session(struct svc_rqst *rqstp,
> cs_slot = &conf->cl_cs_slot;
trace_nfsd_slot_seqid_confirmed
> else
> cs_slot = &unconf->cl_cs_slot;
trace_nfsd_slot_seqid_unconfirmed
> - status = check_slot_seqid(cr_ses->seqid, cs_slot->sl_seqid, 0);
> + status = check_slot_seqid(conf ? conf : unconf, cr_ses->seqid,
> + cs_slot->sl_seqid, false);
> switch (status) {
> case nfs_ok:
> cs_slot->sl_seqid++;
> @@ -4221,8 +4221,8 @@ nfsd4_sequence(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> * sr_highest_slotid and the sr_target_slot id to maxslots */
> seq->maxslots = session->se_fchannel.maxreqs;
>
trace_nfsd_slot_seqid_sequence
> - status = check_slot_seqid(seq->seqid, slot->sl_seqid,
> - slot->sl_flags & NFSD4_SLOT_INUSE);
> + status = check_slot_seqid(clp, seq->seqid, slot->sl_seqid,
> + slot->sl_flags & NFSD4_SLOT_INUSE);
> if (status == nfserr_replay_cache) {
> status = nfserr_seq_misordered;
> if (!(slot->sl_flags & NFSD4_SLOT_INITIALIZED))
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 7f1a6d568bdb..ec00ca7ecfc8 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -1542,6 +1542,40 @@ TRACE_EVENT(nfsd_cb_seq_status,
> )
> );
>
> +TRACE_EVENT(check_slot_seqid,
Nit: NFSD tracepoint names should start with "nfsd_".
> + TP_PROTO(
> + const struct nfs4_client *clp,
> + u32 seqid,
> + u32 slot_seqid,
> + bool inuse
> + ),
> + TP_ARGS(clp, seqid, slot_seqid, inuse),
> + TP_STRUCT__entry(
> + __field(u32, seqid)
> + __field(u32, slot_seqid)
> + __field(u32, cl_boot)
> + __field(u32, cl_id)
> + __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
> + __field(bool, conf)
> + __field(bool, inuse)
> + ),
> + TP_fast_assign(
> + __entry->cl_boot = clp->cl_clientid.cl_boot;
> + __entry->cl_id = clp->cl_clientid.cl_id;
> + __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
> + clp->cl_cb_conn.cb_addrlen);
> + __entry->seqid = seqid;
> + __entry->slot_seqid = slot_seqid;
> + __entry->conf = test_bit(NFSD4_CLIENT_CONFIRMED, &clp->cl_flags);
> + __entry->inuse = inuse;
> + ),
> + TP_printk("addr=%pISpc %s client %08x:%08x seqid=%u slot_seqid=%u inuse=%d",
> + __get_sockaddr(addr), __entry->conf ? "conf" : "unconf",
> + __entry->cl_boot, __entry->cl_id,
> + __entry->seqid, __entry->slot_seqid, __entry->inuse
Nit: How about: __entry->in_use ? "(in use)" : "(not in use)"
Since TP_printk is for human readers.
> + )
> +);
> +
> TRACE_EVENT(nfsd_cb_free_slot,
> TP_PROTO(
> const struct rpc_task *task,
>
> --
> 2.44.0
>
--
Chuck Lever
On Fri, 2024-04-05 at 15:03 -0400, Chuck Lever wrote:
> On Fri, Apr 05, 2024 at 02:40:50PM -0400, Jeff Layton wrote:
> > Replace a dprintk in check_slot_seqid with a new tracepoint. Add a
> > nfs4_client argument to check_slot_seqid so that we can pass the
> > appropriate info to the tracepoint.
> >
> > Signed-off-by: Jeffrey Layton <[email protected]>
> > ---
> > fs/nfsd/nfs4state.c | 12 ++++++------
> > fs/nfsd/trace.h | 34 ++++++++++++++++++++++++++++++++++
> > 2 files changed, 40 insertions(+), 6 deletions(-)
> >
> > diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> > index 3cef81e196c6..5891bc3e2b0b 100644
> > --- a/fs/nfsd/nfs4state.c
> > +++ b/fs/nfsd/nfs4state.c
> > @@ -3642,10 +3642,9 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> > }
> >
> > static __be32
> > -check_slot_seqid(u32 seqid, u32 slot_seqid, int slot_inuse)
> > +check_slot_seqid(struct nfs4_client *clp, u32 seqid, u32 slot_seqid, bool slot_inuse)
> > {
> > - dprintk("%s enter. seqid %d slot_seqid %d\n", __func__, seqid,
> > - slot_seqid);
> > + trace_check_slot_seqid(clp, seqid, slot_seqid, slot_inuse);
>
> Getting rid of the dprintk: +1
>
> Tracing slot seqid checks: +1
>
> But I'd like something a little different for the tracepoint
> itself. I can make these changes if you like to just hand this off.
>
> Let's make this trace point into three separate trace events, one
> at the nfsd4_sequence check_slot_seqid() call site, and two in
> nfsd4_create_session(), like below.
>
> Two reasons for this change:
>
> 1. Separate tracepoints in nfsd4_create_session will show whether
> the client is confirmed or not
>
> 2. The tracepoint in nfsd4_sequence will normally be noisy, so
> having a separate tracepoint for that case makes it easy to
> disable that one while leaving the create_session tracepoints
> enabled.
>
> And, bonus: you won't have to change the synopsis of
> check_slot_seqid().
>
>
> > /* The slot is in use, and no response has been sent. */
> > if (slot_inuse) {
> > @@ -3827,7 +3826,8 @@ nfsd4_create_session(struct svc_rqst *rqstp,
> > cs_slot = &conf->cl_cs_slot;
> trace_nfsd_slot_seqid_confirmed
> > else
> > cs_slot = &unconf->cl_cs_slot;
> trace_nfsd_slot_seqid_unconfirmed
> > - status = check_slot_seqid(cr_ses->seqid, cs_slot->sl_seqid, 0);
> > + status = check_slot_seqid(conf ? conf : unconf, cr_ses->seqid,
> > + cs_slot->sl_seqid, false);
> > switch (status) {
> > case nfs_ok:
> > cs_slot->sl_seqid++;
> > @@ -4221,8 +4221,8 @@ nfsd4_sequence(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> > * sr_highest_slotid and the sr_target_slot id to maxslots */
> > seq->maxslots = session->se_fchannel.maxreqs;
> >
> trace_nfsd_slot_seqid_sequence
> > - status = check_slot_seqid(seq->seqid, slot->sl_seqid,
> > - slot->sl_flags & NFSD4_SLOT_INUSE);
> > + status = check_slot_seqid(clp, seq->seqid, slot->sl_seqid,
> > + slot->sl_flags & NFSD4_SLOT_INUSE);
> > if (status == nfserr_replay_cache) {
> > status = nfserr_seq_misordered;
> > if (!(slot->sl_flags & NFSD4_SLOT_INITIALIZED))
> > diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> > index 7f1a6d568bdb..ec00ca7ecfc8 100644
> > --- a/fs/nfsd/trace.h
> > +++ b/fs/nfsd/trace.h
> > @@ -1542,6 +1542,40 @@ TRACE_EVENT(nfsd_cb_seq_status,
> > )
> > );
> >
> > +TRACE_EVENT(check_slot_seqid,
>
> Nit: NFSD tracepoint names should start with "nfsd_".
>
>
> > + TP_PROTO(
> > + const struct nfs4_client *clp,
> > + u32 seqid,
> > + u32 slot_seqid,
> > + bool inuse
> > + ),
> > + TP_ARGS(clp, seqid, slot_seqid, inuse),
> > + TP_STRUCT__entry(
> > + __field(u32, seqid)
> > + __field(u32, slot_seqid)
> > + __field(u32, cl_boot)
> > + __field(u32, cl_id)
> > + __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
> > + __field(bool, conf)
> > + __field(bool, inuse)
> > + ),
> > + TP_fast_assign(
> > + __entry->cl_boot = clp->cl_clientid.cl_boot;
> > + __entry->cl_id = clp->cl_clientid.cl_id;
> > + __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
> > + clp->cl_cb_conn.cb_addrlen);
> > + __entry->seqid = seqid;
> > + __entry->slot_seqid = slot_seqid;
> > + __entry->conf = test_bit(NFSD4_CLIENT_CONFIRMED, &clp->cl_flags);
> > + __entry->inuse = inuse;
> > + ),
> > + TP_printk("addr=%pISpc %s client %08x:%08x seqid=%u slot_seqid=%u inuse=%d",
> > + __get_sockaddr(addr), __entry->conf ? "conf" : "unconf",
> > + __entry->cl_boot, __entry->cl_id,
> > + __entry->seqid, __entry->slot_seqid, __entry->inuse
>
> Nit: How about: __entry->in_use ? "(in use)" : "(not in use)"
>
> Since TP_printk is for human readers.
>
>
> > + )
> > +);
> > +
> > TRACE_EVENT(nfsd_cb_free_slot,
> > TP_PROTO(
> > const struct rpc_task *task,
> >
> > --
> > 2.44.0
> >
>
Sure, those all sound like fine changes. If you're fine making them,
thats good with me too. I mostly posted these since I used these to help
track down the CB_RECALL_ANY issue.
--
Jeff Layton <[email protected]>