First a patch to remove a few newlines from existing tracepoint string
formats, and then a couple of new tracepoints to instrument some of the
activity around CREATE_SESSION and client expiry. Probably reasonable
for v6.10.
Signed-off-by: Jeff Layton <[email protected]>
---
Jeff Layton (3):
nfsd: drop extraneous newline from nfsd tracepoints
nfsd: new tracepoint for check_slot_seqid
nfsd: add tracepoint in mark_client_expired_locked
fs/nfsd/nfs4state.c | 18 +++++++++------
fs/nfsd/trace.h | 64 ++++++++++++++++++++++++++++++++++++++++++++++++++---
2 files changed, 72 insertions(+), 10 deletions(-)
---
base-commit: 10396f4df8b75ff6ab0aa2cd74296565466f2c8d
change-id: 20240405-nfsd-fixes-adc4524ae2bf
Best regards,
--
Jeff Layton <[email protected]>
We never want a newline in tracepoint output.
Signed-off-by: Jeff Layton <[email protected]>
---
fs/nfsd/trace.h | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index e545e92c4408..7f1a6d568bdb 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -1534,7 +1534,7 @@ TRACE_EVENT(nfsd_cb_seq_status,
__entry->seq_status = cb->cb_seq_status;
),
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER
- " sessionid=%08x:%08x:%08x:%08x tk_status=%d seq_status=%d\n",
+ " sessionid=%08x:%08x:%08x:%08x tk_status=%d seq_status=%d",
__entry->task_id, __entry->client_id,
__entry->cl_boot, __entry->cl_id,
__entry->seqno, __entry->reserved,
@@ -1573,7 +1573,7 @@ TRACE_EVENT(nfsd_cb_free_slot,
__entry->slot_seqno = session->se_cb_seq_nr;
),
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER
- " sessionid=%08x:%08x:%08x:%08x new slot seqno=%u\n",
+ " sessionid=%08x:%08x:%08x:%08x new slot seqno=%u",
__entry->task_id, __entry->client_id,
__entry->cl_boot, __entry->cl_id,
__entry->seqno, __entry->reserved,
@@ -1978,7 +1978,7 @@ TRACE_EVENT(nfsd_ctl_time,
__entry->time = time;
__assign_str_len(name, name, namelen);
),
- TP_printk("file=%s time=%d\n",
+ TP_printk("file=%s time=%d",
__get_str(name), __entry->time
)
);
--
2.44.0
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);
/* 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;
else
cs_slot = &unconf->cl_cs_slot;
- 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;
- 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,
+ 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
+ )
+);
+
TRACE_EVENT(nfsd_cb_free_slot,
TP_PROTO(
const struct rpc_task *task,
--
2.44.0
Show client info alongside the number of cl_rpc_users. If that's
elevated, then we can infer that this function returned nfserr_jukebox.
Signed-off-by: Jeff Layton <[email protected]>
---
fs/nfsd/nfs4state.c | 6 +++++-
fs/nfsd/trace.h | 24 ++++++++++++++++++++++++
2 files changed, 29 insertions(+), 1 deletion(-)
diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 5891bc3e2b0b..2b5dadeed8c9 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -2352,7 +2352,11 @@ unhash_client(struct nfs4_client *clp)
static __be32 mark_client_expired_locked(struct nfs4_client *clp)
{
- if (atomic_read(&clp->cl_rpc_users))
+ int users = atomic_read(&clp->cl_rpc_users);
+
+ trace_mark_client_expired_locked(clp, users);
+
+ if (users)
return nfserr_jukebox;
unhash_client_locked(clp);
return nfs_ok;
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index ec00ca7ecfc8..b50d6a71c7d9 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -1576,6 +1576,30 @@ TRACE_EVENT(check_slot_seqid,
)
);
+TRACE_EVENT(mark_client_expired_locked,
+ TP_PROTO(
+ const struct nfs4_client *clp,
+ int cl_rpc_users
+ ),
+ TP_ARGS(clp, cl_rpc_users),
+ TP_STRUCT__entry(
+ __field(int, cl_rpc_users)
+ __field(u32, cl_boot)
+ __field(u32, cl_id)
+ __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
+ ),
+ TP_fast_assign(
+ __entry->cl_rpc_users = cl_rpc_users;
+ __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)
+ ),
+ TP_printk("addr=%pISpc client %08x:%08x cl_rpc_users=%d",
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
+ __entry->cl_rpc_users)
+);
+
TRACE_EVENT(nfsd_cb_free_slot,
TP_PROTO(
const struct rpc_task *task,
--
2.44.0