linux-nfs.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH RFC 00/21] NFSD callback and lease management observability
@ 2021-05-10 15:51 Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 01/21] NFSD: Constify @fh argument of knfsd_fh_hash() Chuck Lever
                   ` (21 more replies)
  0 siblings, 22 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:51 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Happy Monday.

I've hacked together some improvements to the tracepoints that record
server callback and lease management activity. I'm interested in
review comments and testing. I'm sure I've missed your favorite edge
case, so please let me know what it is!

---

Chuck Lever (21):
      NFSD: Constify @fh argument of knfsd_fh_hash()
      NFSD: Capture every CB state transition
      NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros
      NFSD: Add cb_lost tracepoint
      NFSD: Adjust cb_shutdown tracepoint
      NFSD: Remove spurious cb_setup_err tracepoint
      NFSD: Enhance the nfsd_cb_setup tracepoint
      NFSD: Add an nfsd_cb_lm_notify tracepoint
      NFSD: Add an nfsd_cb_offload tracepoint
      NFSD: Replace the nfsd_deleg_break tracepoint
      NFSD: Add an nfsd_cb_probe tracepoint
      NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints
      NFSD: Update nfsd_cb_args tracepoint
      NFSD: Add nfsd_clid_cred_mismatch tracepoint
      NFSD: Add nfsd_clid_verf_mismatch tracepoint
      NFSD: Remove nfsd_clid_inuse_err
      NFSD: Add nfsd_clid_confirmed tracepoint
      NFSD: Add nfsd_clid_destroyed tracepoint
      NFSD: Add a couple more nfsd_clid_expired call sites
      NFSD: Rename nfsd_clid_class
      NFSD: Add tracepoints to observe clientID activity


 fs/nfsd/nfs4callback.c |  45 ++++----
 fs/nfsd/nfs4proc.c     |   1 +
 fs/nfsd/nfs4state.c    |  56 +++++++---
 fs/nfsd/nfsfh.h        |   7 +-
 fs/nfsd/trace.h        | 227 ++++++++++++++++++++++++++++++++++-------
 5 files changed, 254 insertions(+), 82 deletions(-)

--
Chuck Lever


^ permalink raw reply	[flat|nested] 35+ messages in thread

* [PATCH RFC 01/21] NFSD: Constify @fh argument of knfsd_fh_hash()
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
@ 2021-05-10 15:51 ` Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 02/21] NFSD: Capture every CB state transition Chuck Lever
                   ` (20 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:51 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Enable knfsd_fh_hash() to be invoked in functions where the
filehandle pointer is a const.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfsfh.h |    7 ++-----
 1 file changed, 2 insertions(+), 5 deletions(-)

diff --git a/fs/nfsd/nfsfh.h b/fs/nfsd/nfsfh.h
index aff2cda5c6c3..6106697adc04 100644
--- a/fs/nfsd/nfsfh.h
+++ b/fs/nfsd/nfsfh.h
@@ -225,15 +225,12 @@ static inline bool fh_fsid_match(struct knfsd_fh *fh1, struct knfsd_fh *fh2)
  * returns a crc32 hash for the filehandle that is compatible with
  * the one displayed by "wireshark".
  */
-
-static inline u32
-knfsd_fh_hash(struct knfsd_fh *fh)
+static inline u32 knfsd_fh_hash(const struct knfsd_fh *fh)
 {
 	return ~crc32_le(0xFFFFFFFF, (unsigned char *)&fh->fh_base, fh->fh_size);
 }
 #else
-static inline u32
-knfsd_fh_hash(struct knfsd_fh *fh)
+static inline u32 knfsd_fh_hash(const struct knfsd_fh *fh)
 {
 	return 0;
 }



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 02/21] NFSD: Capture every CB state transition
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 01/21] NFSD: Constify @fh argument of knfsd_fh_hash() Chuck Lever
@ 2021-05-10 15:51 ` Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 03/21] NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros Chuck Lever
                   ` (19 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:51 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

We were missing one.

As a clean-up, add a helper that sets the new CB state and fires
a tracepoint. The tracepoint fires only when the state changes, to
help reduce trace log noise.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |   28 +++++++++++++++-------------
 1 file changed, 15 insertions(+), 13 deletions(-)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index 7325592b456e..b6cc51a9f37c 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -945,20 +945,26 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
 	return 0;
 }
 
+static void nfsd4_mark_cb_state(struct nfs4_client *clp, int newstate)
+{
+	if (clp->cl_cb_state != newstate) {
+		clp->cl_cb_state = newstate;
+		trace_nfsd_cb_state(clp);
+	}
+}
+
 static void nfsd4_mark_cb_down(struct nfs4_client *clp, int reason)
 {
 	if (test_bit(NFSD4_CLIENT_CB_UPDATE, &clp->cl_flags))
 		return;
-	clp->cl_cb_state = NFSD4_CB_DOWN;
-	trace_nfsd_cb_state(clp);
+	nfsd4_mark_cb_state(clp, NFSD4_CB_DOWN);
 }
 
 static void nfsd4_mark_cb_fault(struct nfs4_client *clp, int reason)
 {
 	if (test_bit(NFSD4_CLIENT_CB_UPDATE, &clp->cl_flags))
 		return;
-	clp->cl_cb_state = NFSD4_CB_FAULT;
-	trace_nfsd_cb_state(clp);
+	nfsd4_mark_cb_state(clp, NFSD4_CB_FAULT);
 }
 
 static void nfsd4_cb_probe_done(struct rpc_task *task, void *calldata)
@@ -968,10 +974,8 @@ static void nfsd4_cb_probe_done(struct rpc_task *task, void *calldata)
 	trace_nfsd_cb_done(clp, task->tk_status);
 	if (task->tk_status)
 		nfsd4_mark_cb_down(clp, task->tk_status);
-	else {
-		clp->cl_cb_state = NFSD4_CB_UP;
-		trace_nfsd_cb_state(clp);
-	}
+	else
+		nfsd4_mark_cb_state(clp, NFSD4_CB_UP);
 }
 
 static void nfsd4_cb_probe_release(void *calldata)
@@ -995,8 +999,7 @@ static const struct rpc_call_ops nfsd4_cb_probe_ops = {
  */
 void nfsd4_probe_callback(struct nfs4_client *clp)
 {
-	clp->cl_cb_state = NFSD4_CB_UNKNOWN;
-	trace_nfsd_cb_state(clp);
+	nfsd4_mark_cb_state(clp, NFSD4_CB_UNKNOWN);
 	set_bit(NFSD4_CLIENT_CB_UPDATE, &clp->cl_flags);
 	nfsd4_run_cb(&clp->cl_cb_null);
 }
@@ -1009,11 +1012,10 @@ void nfsd4_probe_callback_sync(struct nfs4_client *clp)
 
 void nfsd4_change_callback(struct nfs4_client *clp, struct nfs4_cb_conn *conn)
 {
-	clp->cl_cb_state = NFSD4_CB_UNKNOWN;
+	nfsd4_mark_cb_state(clp, NFSD4_CB_UNKNOWN);
 	spin_lock(&clp->cl_lock);
 	memcpy(&clp->cl_cb_conn, conn, sizeof(struct nfs4_cb_conn));
 	spin_unlock(&clp->cl_lock);
-	trace_nfsd_cb_state(clp);
 }
 
 /*
@@ -1345,7 +1347,7 @@ nfsd4_run_cb_work(struct work_struct *work)
 	 * Don't send probe messages for 4.1 or later.
 	 */
 	if (!cb->cb_ops && clp->cl_minorversion) {
-		clp->cl_cb_state = NFSD4_CB_UP;
+		nfsd4_mark_cb_state(clp, NFSD4_CB_UP);
 		nfsd41_destroy_cb(cb);
 		return;
 	}



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 03/21] NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 01/21] NFSD: Constify @fh argument of knfsd_fh_hash() Chuck Lever
  2021-05-10 15:51 ` [PATCH RFC 02/21] NFSD: Capture every CB state transition Chuck Lever
@ 2021-05-10 15:51 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 04/21] NFSD: Add cb_lost tracepoint Chuck Lever
                   ` (18 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:51 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

TRACE_DEFINE_ENUM() is necessary for enum {} but not for C macros.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/trace.h |    5 -----
 1 file changed, 5 deletions(-)

diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 27a93ebd1d80..9378a6ec4089 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -828,11 +828,6 @@ TRACE_EVENT(nfsd_cb_nodelegs,
 	TP_printk("client %08x:%08x", __entry->cl_boot, __entry->cl_id)
 )
 
-TRACE_DEFINE_ENUM(NFSD4_CB_UP);
-TRACE_DEFINE_ENUM(NFSD4_CB_UNKNOWN);
-TRACE_DEFINE_ENUM(NFSD4_CB_DOWN);
-TRACE_DEFINE_ENUM(NFSD4_CB_FAULT);
-
 #define show_cb_state(val)						\
 	__print_symbolic(val,						\
 		{ NFSD4_CB_UP,		"UP" },				\



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 04/21] NFSD: Add cb_lost tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (2 preceding siblings ...)
  2021-05-10 15:51 ` [PATCH RFC 03/21] NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 05/21] NFSD: Adjust cb_shutdown tracepoint Chuck Lever
                   ` (17 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Provide more clarity about when the callback channel is in trouble.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    2 ++
 fs/nfsd/trace.h     |    1 +
 2 files changed, 3 insertions(+)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index b517a8794400..4b2dc9d97cac 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -1745,6 +1745,8 @@ static void nfsd4_conn_lost(struct svc_xpt_user *u)
 	struct nfsd4_conn *c = container_of(u, struct nfsd4_conn, cn_xpt_user);
 	struct nfs4_client *clp = c->cn_session->se_client;
 
+	trace_nfsd_cb_lost(clp);
+
 	spin_lock(&clp->cl_lock);
 	if (!list_empty(&c->cn_persession)) {
 		list_del(&c->cn_persession);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 9378a6ec4089..7577a4a46861 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -863,6 +863,7 @@ DEFINE_EVENT(nfsd_cb_class, nfsd_cb_##name,		\
 
 DEFINE_NFSD_CB_EVENT(setup);
 DEFINE_NFSD_CB_EVENT(state);
+DEFINE_NFSD_CB_EVENT(lost);
 DEFINE_NFSD_CB_EVENT(shutdown);
 
 TRACE_EVENT(nfsd_cb_setup_err,



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 05/21] NFSD: Adjust cb_shutdown tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (3 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 04/21] NFSD: Add cb_lost tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint Chuck Lever
                   ` (16 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Show when the upper layer requested a shutdown. RPC tracepoints can
already show when rpc_shutdown_client() is called.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |    4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index b6cc51a9f37c..ab1836381e22 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -1233,6 +1233,9 @@ void nfsd4_destroy_callback_queue(void)
 /* must be called under the state lock */
 void nfsd4_shutdown_callback(struct nfs4_client *clp)
 {
+	if (clp->cl_cb_state != NFSD4_CB_UNKNOWN)
+		trace_nfsd_cb_shutdown(clp);
+
 	set_bit(NFSD4_CLIENT_CB_KILL, &clp->cl_flags);
 	/*
 	 * Note this won't actually result in a null callback;
@@ -1278,7 +1281,6 @@ static void nfsd4_process_cb_update(struct nfsd4_callback *cb)
 	 * kill the old client:
 	 */
 	if (clp->cl_cb_client) {
-		trace_nfsd_cb_shutdown(clp);
 		rpc_shutdown_client(clp->cl_cb_client);
 		clp->cl_cb_client = NULL;
 		put_cred(clp->cl_cb_cred);



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (4 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 05/21] NFSD: Adjust cb_shutdown tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 20:27   ` J. Bruce Fields
  2021-05-10 15:52 ` [PATCH RFC 07/21] NFSD: Enhance the nfsd_cb_setup tracepoint Chuck Lever
                   ` (15 subsequent siblings)
  21 siblings, 1 reply; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

This path is not really an error path, so the tracepoint I added
there is just noise.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |    4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index ab1836381e22..15ba16c54793 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -915,10 +915,8 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
 		args.authflavor = clp->cl_cred.cr_flavor;
 		clp->cl_cb_ident = conn->cb_ident;
 	} else {
-		if (!conn->cb_xprt) {
-			trace_nfsd_cb_setup_err(clp, -EINVAL);
+		if (!conn->cb_xprt)
 			return -EINVAL;
-		}
 		clp->cl_cb_conn.cb_xprt = conn->cb_xprt;
 		clp->cl_cb_session = ses;
 		args.bc_xprt = conn->cb_xprt;



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 07/21] NFSD: Enhance the nfsd_cb_setup tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (5 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 08/21] NFSD: Add an nfsd_cb_lm_notify tracepoint Chuck Lever
                   ` (14 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Display the transport protocol and authentication flavor so admins
can see what they might be getting wrong.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |    3 ++-
 fs/nfsd/trace.h        |   43 ++++++++++++++++++++++++++++++++++++++++++-
 2 files changed, 44 insertions(+), 2 deletions(-)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index 15ba16c54793..c2a2a58b3581 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -939,7 +939,8 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
 	}
 	clp->cl_cb_client = client;
 	clp->cl_cb_cred = cred;
-	trace_nfsd_cb_setup(clp);
+	trace_nfsd_cb_setup(clp, rpc_peeraddr2str(client, RPC_DISPLAY_NETID),
+			    args.authflavor);
 	return 0;
 }
 
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 7577a4a46861..d6405852bdd9 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -861,11 +861,52 @@ DEFINE_EVENT(nfsd_cb_class, nfsd_cb_##name,		\
 	TP_PROTO(const struct nfs4_client *clp),	\
 	TP_ARGS(clp))
 
-DEFINE_NFSD_CB_EVENT(setup);
 DEFINE_NFSD_CB_EVENT(state);
 DEFINE_NFSD_CB_EVENT(lost);
 DEFINE_NFSD_CB_EVENT(shutdown);
 
+TRACE_DEFINE_ENUM(RPC_AUTH_NULL);
+TRACE_DEFINE_ENUM(RPC_AUTH_UNIX);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5I);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5P);
+
+#define show_nfsd_authflavor(val)					\
+	__print_symbolic(val,						\
+		{ RPC_AUTH_NULL,		"none" },		\
+		{ RPC_AUTH_UNIX,		"sys" },		\
+		{ RPC_AUTH_GSS,			"gss" },		\
+		{ RPC_AUTH_GSS_KRB5,		"krb5" },		\
+		{ RPC_AUTH_GSS_KRB5I,		"krb5i" },		\
+		{ RPC_AUTH_GSS_KRB5P,		"krb5p" })
+
+TRACE_EVENT(nfsd_cb_setup,
+	TP_PROTO(const struct nfs4_client *clp,
+		 const char *netid,
+		 rpc_authflavor_t authflavor
+	),
+	TP_ARGS(clp, netid, authflavor),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(unsigned long, authflavor)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+		__array(unsigned char, netid, 8)
+	),
+	TP_fast_assign(
+		__entry->cl_boot = clp->cl_clientid.cl_boot;
+		__entry->cl_id = clp->cl_clientid.cl_id;
+		strlcpy(__entry->netid, netid, sizeof(__entry->netid));
+		__entry->authflavor = authflavor;
+		memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("addr=%pISpc client %08x:%08x proto=%s flavor=%s",
+		__entry->addr, __entry->cl_boot, __entry->cl_id,
+		__entry->netid, show_nfsd_authflavor(__entry->authflavor))
+);
+
 TRACE_EVENT(nfsd_cb_setup_err,
 	TP_PROTO(
 		const struct nfs4_client *clp,



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 08/21] NFSD: Add an nfsd_cb_lm_notify tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (6 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 07/21] NFSD: Enhance the nfsd_cb_setup tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint Chuck Lever
                   ` (13 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

When the server kicks off a CB_LM_NOTIFY callback, record its
arguments so we can better observe asynchronous locking behavior.
For example:

            nfsd-998   [002]  1471.705873: nfsd_cb_notify_lock:  addr=192.168.2.51:0 client 6092a47c:35a43fc1 fh_hash=0x8950b23a

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Cc: Jeff Layton <jlayton@redhat.com>
---
 fs/nfsd/nfs4state.c |    4 +++-
 fs/nfsd/trace.h     |   26 ++++++++++++++++++++++++++
 2 files changed, 29 insertions(+), 1 deletion(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 4b2dc9d97cac..b41ecec15e5b 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -6432,8 +6432,10 @@ nfsd4_lm_notify(struct file_lock *fl)
 	}
 	spin_unlock(&nn->blocked_locks_lock);
 
-	if (queue)
+	if (queue) {
+		trace_nfsd_cb_notify_lock(lo, nbl);
 		nfsd4_run_cb(&nbl->nbl_cb);
+	}
 }
 
 static const struct lock_manager_operations nfsd_posix_mng_ops  = {
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index d6405852bdd9..1dce41b3bd4d 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -978,6 +978,32 @@ TRACE_EVENT(nfsd_cb_done,
 		__entry->status)
 );
 
+TRACE_EVENT(nfsd_cb_notify_lock,
+	TP_PROTO(
+		const struct nfs4_lockowner *lo,
+		const struct nfsd4_blocked_lock *nbl
+	),
+	TP_ARGS(lo, nbl),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(u32, fh_hash)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		const struct nfs4_client *clp = lo->lo_owner.so_client;
+
+		__entry->cl_boot = clp->cl_clientid.cl_boot;
+		__entry->cl_id = clp->cl_clientid.cl_id;
+		__entry->fh_hash = knfsd_fh_hash(&nbl->nbl_fh);
+		memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("addr=%pISpc client %08x:%08x fh_hash=0x%08x",
+		__entry->addr, __entry->cl_boot, __entry->cl_id,
+		__entry->fh_hash)
+);
+
 #endif /* _NFSD_TRACE_H */
 
 #undef TRACE_INCLUDE_PATH



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (7 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 08/21] NFSD: Add an nfsd_cb_lm_notify tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-14 18:22   ` Olga Kornievskaia
  2021-05-10 15:52 ` [PATCH RFC 10/21] NFSD: Replace the nfsd_deleg_break tracepoint Chuck Lever
                   ` (12 subsequent siblings)
  21 siblings, 1 reply; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Record the arguments of CB_OFFLOAD callbacks so we can better
observe asynchronous copy-offload behavior. For example:

            nfsd-995   [008]  7721.934222: nfsd_cb_offload:      addr=192.168.2.51:0 client 6092a47c:35a43fc1 fh_hash=0x8739113a

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Cc: Olga Kornievskaia <kolga@netapp.com>
Cc: Dai Ngo <Dai.Ngo@oracle.com>
---
 fs/nfsd/nfs4proc.c |    1 +
 fs/nfsd/trace.h    |   30 ++++++++++++++++++++++++++++++
 2 files changed, 31 insertions(+)

diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
index daf43b980d4b..7a13f6c848c6 100644
--- a/fs/nfsd/nfs4proc.c
+++ b/fs/nfsd/nfs4proc.c
@@ -1497,6 +1497,7 @@ static int nfsd4_do_async_copy(void *data)
 	memcpy(&cb_copy->fh, &copy->fh, sizeof(copy->fh));
 	nfsd4_init_cb(&cb_copy->cp_cb, cb_copy->cp_clp,
 			&nfsd4_cb_offload_ops, NFSPROC4_CLNT_CB_OFFLOAD);
+	trace_nfsd_cb_offload(copy->cp_clp, &copy->cp_res.cb_stateid, &copy->fh);
 	nfsd4_run_cb(&cb_copy->cp_cb);
 out:
 	if (!copy->cp_intra)
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 1dce41b3bd4d..15cacbdac411 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -1004,6 +1004,36 @@ TRACE_EVENT(nfsd_cb_notify_lock,
 		__entry->fh_hash)
 );
 
+TRACE_EVENT(nfsd_cb_offload,
+	TP_PROTO(
+		const struct nfs4_client *clp,
+		const stateid_t *stp,
+		const struct knfsd_fh *fh
+	),
+	TP_ARGS(clp, stp, fh),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(u32, si_id)
+		__field(u32, si_generation)
+		__field(u32, fh_hash)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		__entry->cl_boot = stp->si_opaque.so_clid.cl_boot;
+		__entry->cl_id = stp->si_opaque.so_clid.cl_id;
+		__entry->si_id = stp->si_opaque.so_id;
+		__entry->si_generation = stp->si_generation;
+		__entry->fh_hash = knfsd_fh_hash(fh);
+		memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x fh_hash=0x%08x",
+		__entry->addr, __entry->cl_boot, __entry->cl_id,
+		__entry->si_id, __entry->si_generation,
+		__entry->fh_hash)
+);
+
 #endif /* _NFSD_TRACE_H */
 
 #undef TRACE_INCLUDE_PATH



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 10/21] NFSD: Replace the nfsd_deleg_break tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (8 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 11/21] NFSD: Add an nfsd_cb_probe tracepoint Chuck Lever
                   ` (11 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Renamed so it can be enabled as a set with the other nfsd_cb_
tracepoints. And, consistent with those tracepoints, report the
address of the client, the client ID the server has given it, and
the state ID being recalled.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    2 +-
 fs/nfsd/trace.h     |   32 +++++++++++++++++++++++++++++++-
 2 files changed, 32 insertions(+), 2 deletions(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index b41ecec15e5b..27768a7ed23b 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -4620,7 +4620,7 @@ nfsd_break_deleg_cb(struct file_lock *fl)
 	struct nfs4_delegation *dp = (struct nfs4_delegation *)fl->fl_owner;
 	struct nfs4_file *fp = dp->dl_stid.sc_file;
 
-	trace_nfsd_deleg_break(&dp->dl_stid.sc_stateid);
+	trace_nfsd_cb_recall(&dp->dl_stid);
 
 	/*
 	 * We don't want the locks code to timeout the lease for us;
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 15cacbdac411..13ab373aaa75 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -459,7 +459,6 @@ DEFINE_STATEID_EVENT(layout_recall_release);
 
 DEFINE_STATEID_EVENT(open);
 DEFINE_STATEID_EVENT(deleg_read);
-DEFINE_STATEID_EVENT(deleg_break);
 DEFINE_STATEID_EVENT(deleg_recall);
 
 DECLARE_EVENT_CLASS(nfsd_stateseqid_class,
@@ -978,6 +977,37 @@ TRACE_EVENT(nfsd_cb_done,
 		__entry->status)
 );
 
+TRACE_EVENT(nfsd_cb_recall,
+	TP_PROTO(
+		const struct nfs4_stid *stid
+	),
+	TP_ARGS(stid),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(u32, si_id)
+		__field(u32, si_generation)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		const stateid_t *stp = &stid->sc_stateid;
+		const struct nfs4_client *clp = stid->sc_client;
+
+		__entry->cl_boot = stp->si_opaque.so_clid.cl_boot;
+		__entry->cl_id = stp->si_opaque.so_clid.cl_id;
+		__entry->si_id = stp->si_opaque.so_id;
+		__entry->si_generation = stp->si_generation;
+		if (clp)
+			memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
+				sizeof(struct sockaddr_in6));
+		else
+			memset(__entry->addr, 0, sizeof(struct sockaddr_in6));
+	),
+	TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x",
+		__entry->addr, __entry->cl_boot, __entry->cl_id,
+		__entry->si_id, __entry->si_generation)
+);
+
 TRACE_EVENT(nfsd_cb_notify_lock,
 	TP_PROTO(
 		const struct nfs4_lockowner *lo,



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 11/21] NFSD: Add an nfsd_cb_probe tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (9 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 10/21] NFSD: Replace the nfsd_deleg_break tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 12/21] NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints Chuck Lever
                   ` (10 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Record a tracepoint event when the server performs a callback
probe. This event can be enabled as a group with other nfsd_cb
tracepoints.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |    1 +
 fs/nfsd/trace.h        |    1 +
 2 files changed, 2 insertions(+)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index c2a2a58b3581..ddab969d7865 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -998,6 +998,7 @@ static const struct rpc_call_ops nfsd4_cb_probe_ops = {
  */
 void nfsd4_probe_callback(struct nfs4_client *clp)
 {
+	trace_nfsd_cb_probe(clp);
 	nfsd4_mark_cb_state(clp, NFSD4_CB_UNKNOWN);
 	set_bit(NFSD4_CLIENT_CB_UPDATE, &clp->cl_flags);
 	nfsd4_run_cb(&clp->cl_cb_null);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 13ab373aaa75..0845116cbe3f 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -861,6 +861,7 @@ DEFINE_EVENT(nfsd_cb_class, nfsd_cb_##name,		\
 	TP_ARGS(clp))
 
 DEFINE_NFSD_CB_EVENT(state);
+DEFINE_NFSD_CB_EVENT(probe);
 DEFINE_NFSD_CB_EVENT(lost);
 DEFINE_NFSD_CB_EVENT(shutdown);
 



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 12/21] NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (10 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 11/21] NFSD: Add an nfsd_cb_probe tracepoint Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:52 ` [PATCH RFC 13/21] NFSD: Update nfsd_cb_args tracepoint Chuck Lever
                   ` (9 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Clean up: These are noise in properly working systems. If you really
need to observe the operation of the callback mechanism, use the
sunrpc:rpc\* tracepoints along with the workqueue tracepoints.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4callback.c |    5 -----
 fs/nfsd/trace.h        |   48 ------------------------------------------------
 2 files changed, 53 deletions(-)

diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
index ddab969d7865..84401ca04705 100644
--- a/fs/nfsd/nfs4callback.c
+++ b/fs/nfsd/nfs4callback.c
@@ -970,7 +970,6 @@ static void nfsd4_cb_probe_done(struct rpc_task *task, void *calldata)
 {
 	struct nfs4_client *clp = container_of(calldata, struct nfs4_client, cl_cb_null);
 
-	trace_nfsd_cb_done(clp, task->tk_status);
 	if (task->tk_status)
 		nfsd4_mark_cb_down(clp, task->tk_status);
 	else
@@ -1172,8 +1171,6 @@ static void nfsd4_cb_done(struct rpc_task *task, void *calldata)
 	struct nfsd4_callback *cb = calldata;
 	struct nfs4_client *clp = cb->cb_clp;
 
-	trace_nfsd_cb_done(clp, task->tk_status);
-
 	if (!nfsd4_cb_sequence_done(task, cb))
 		return;
 
@@ -1326,8 +1323,6 @@ nfsd4_run_cb_work(struct work_struct *work)
 	struct rpc_clnt *clnt;
 	int flags;
 
-	trace_nfsd_cb_work(clp, cb->cb_msg.rpc_proc->p_name);
-
 	if (cb->cb_need_restart) {
 		cb->cb_need_restart = false;
 	} else {
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 0845116cbe3f..18f65a403260 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -930,54 +930,6 @@ TRACE_EVENT(nfsd_cb_setup_err,
 		__entry->addr, __entry->cl_boot, __entry->cl_id, __entry->error)
 );
 
-TRACE_EVENT(nfsd_cb_work,
-	TP_PROTO(
-		const struct nfs4_client *clp,
-		const char *procedure
-	),
-	TP_ARGS(clp, procedure),
-	TP_STRUCT__entry(
-		__field(u32, cl_boot)
-		__field(u32, cl_id)
-		__string(procedure, procedure)
-		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
-	),
-	TP_fast_assign(
-		__entry->cl_boot = clp->cl_clientid.cl_boot;
-		__entry->cl_id = clp->cl_clientid.cl_id;
-		__assign_str(procedure, procedure)
-		memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
-			sizeof(struct sockaddr_in6));
-	),
-	TP_printk("addr=%pISpc client %08x:%08x procedure=%s",
-		__entry->addr, __entry->cl_boot, __entry->cl_id,
-		__get_str(procedure))
-);
-
-TRACE_EVENT(nfsd_cb_done,
-	TP_PROTO(
-		const struct nfs4_client *clp,
-		int status
-	),
-	TP_ARGS(clp, status),
-	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->cl_boot = clp->cl_clientid.cl_boot;
-		__entry->cl_id = clp->cl_clientid.cl_id;
-		__entry->status = status;
-		memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
-			sizeof(struct sockaddr_in6));
-	),
-	TP_printk("addr=%pISpc client %08x:%08x status=%d",
-		__entry->addr, __entry->cl_boot, __entry->cl_id,
-		__entry->status)
-);
-
 TRACE_EVENT(nfsd_cb_recall,
 	TP_PROTO(
 		const struct nfs4_stid *stid



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 13/21] NFSD: Update nfsd_cb_args tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (11 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 12/21] NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints Chuck Lever
@ 2021-05-10 15:52 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 14/21] NFSD: Add nfsd_clid_cred_mismatch tracepoint Chuck Lever
                   ` (8 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:52 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Clean-up: Re-order the display of IP address and client ID to be
consistent with other _cb_ tracepoints.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 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 18f65a403260..dd4df6655322 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -808,9 +808,9 @@ TRACE_EVENT(nfsd_cb_args,
 		memcpy(__entry->addr, &conn->cb_addr,
 			sizeof(struct sockaddr_in6));
 	),
-	TP_printk("client %08x:%08x callback addr=%pISpc prog=%u ident=%u",
-		__entry->cl_boot, __entry->cl_id,
-		__entry->addr, __entry->prog, __entry->ident)
+	TP_printk("addr=%pISpc client %08x:%08x prog=%u ident=%u",
+		__entry->addr, __entry->cl_boot, __entry->cl_id,
+		__entry->prog, __entry->ident)
 );
 
 TRACE_EVENT(nfsd_cb_nodelegs,



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 14/21] NFSD: Add nfsd_clid_cred_mismatch tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (12 preceding siblings ...)
  2021-05-10 15:52 ` [PATCH RFC 13/21] NFSD: Update nfsd_cb_args tracepoint Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint Chuck Lever
                   ` (7 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Record when a client tries to establish a lease record but uses an
unexpected credential. This is often a sign of a configuration
problem.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |   14 ++++++++++----
 fs/nfsd/trace.h     |   28 ++++++++++++++++++++++++++++
 2 files changed, 38 insertions(+), 4 deletions(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 27768a7ed23b..4feadb683a2d 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3183,6 +3183,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 		if (!creds_match) { /* case 3 */
 			if (client_has_state(conf)) {
 				status = nfserr_clid_inuse;
+				trace_nfsd_clid_cred_mismatch(conf, rqstp);
 				goto out;
 			}
 			goto out_new;
@@ -3427,9 +3428,10 @@ nfsd4_create_session(struct svc_rqst *rqstp,
 			goto out_free_conn;
 		}
 	} else if (unconf) {
+		status = nfserr_clid_inuse;
 		if (!same_creds(&unconf->cl_cred, &rqstp->rq_cred) ||
 		    !rpc_cmp_addr(sa, (struct sockaddr *) &unconf->cl_addr)) {
-			status = nfserr_clid_inuse;
+			trace_nfsd_clid_cred_mismatch(unconf, rqstp);
 			goto out_free_conn;
 		}
 		status = nfserr_wrong_cred;
@@ -3978,7 +3980,7 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 		if (clp_used_exchangeid(conf))
 			goto out;
 		if (!same_creds(&conf->cl_cred, &rqstp->rq_cred)) {
-			trace_nfsd_clid_inuse_err(conf);
+			trace_nfsd_clid_cred_mismatch(conf, rqstp);
 			goto out;
 		}
 	}
@@ -4036,10 +4038,14 @@ nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
 	 * Nevertheless, RFC 7530 recommends INUSE for this case:
 	 */
 	status = nfserr_clid_inuse;
-	if (unconf && !same_creds(&unconf->cl_cred, &rqstp->rq_cred))
+	if (unconf && !same_creds(&unconf->cl_cred, &rqstp->rq_cred)) {
+		trace_nfsd_clid_cred_mismatch(unconf, rqstp);
 		goto out;
-	if (conf && !same_creds(&conf->cl_cred, &rqstp->rq_cred))
+	}
+	if (conf && !same_creds(&conf->cl_cred, &rqstp->rq_cred)) {
+		trace_nfsd_clid_cred_mismatch(conf, rqstp);
 		goto out;
+	}
 	/* cases below refer to rfc 3530 section 14.2.34: */
 	if (!unconf || !same_verf(&confirm, &unconf->cl_confirm)) {
 		if (conf && same_verf(&confirm, &conf->cl_confirm)) {
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index dd4df6655322..80fd6ca6ae46 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -564,6 +564,34 @@ DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
 DEFINE_CLID_EVENT(find);
 DEFINE_CLID_EVENT(reclaim);
 
+TRACE_EVENT(nfsd_clid_cred_mismatch,
+	TP_PROTO(
+		const struct nfs4_client *clp,
+		const struct svc_rqst *rqstp
+	),
+	TP_ARGS(clp, rqstp),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__field(unsigned long, cl_flavor)
+		__field(unsigned long, new_flavor)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		__entry->cl_boot = clp->cl_clientid.cl_boot;
+		__entry->cl_id = clp->cl_clientid.cl_id;
+		__entry->cl_flavor = clp->cl_cred.cr_flavor;
+		__entry->new_flavor = rqstp->rq_cred.cr_flavor;
+		memcpy(__entry->addr, &rqstp->rq_xprt->xpt_remote,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("client %08x:%08x flavor=%s, conflict=%s from addr=%pISpc",
+		__entry->cl_boot, __entry->cl_id,
+		show_nfsd_authflavor(__entry->cl_flavor),
+		show_nfsd_authflavor(__entry->new_flavor), __entry->addr
+	)
+)
+
 TRACE_EVENT(nfsd_clid_inuse_err,
 	TP_PROTO(const struct nfs4_client *clp),
 	TP_ARGS(clp),



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (13 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 14/21] NFSD: Add nfsd_clid_cred_mismatch tracepoint Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-11 15:49   ` J. Bruce Fields
  2021-05-10 15:53 ` [PATCH RFC 16/21] NFSD: Remove nfsd_clid_inuse_err Chuck Lever
                   ` (6 subsequent siblings)
  21 siblings, 1 reply; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Record when a client presents a different boot verifier than the
one we know about. Typically this is a sign the client has
rebooted, but sometimes it signals a conflicting client ID, which
the client's administrator will need to address.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |   11 ++++++++---
 fs/nfsd/trace.h     |   32 ++++++++++++++++++++++++++++++++
 2 files changed, 40 insertions(+), 3 deletions(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 4feadb683a2d..56ca79f55da4 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3193,6 +3193,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 			goto out_copy;
 		}
 		/* case 5, client reboot */
+		trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
 		conf = NULL;
 		goto out_new;
 	}
@@ -3988,9 +3989,13 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	if (unconf)
 		unhash_client_locked(unconf);
 	/* We need to handle only case 1: probable callback update */
-	if (conf && same_verf(&conf->cl_verifier, &clverifier)) {
-		copy_clid(new, conf);
-		gen_confirm(new, nn);
+	if (conf) {
+		if (same_verf(&conf->cl_verifier, &clverifier)) {
+			copy_clid(new, conf);
+			gen_confirm(new, nn);
+		} else
+			trace_nfsd_clid_verf_mismatch(conf, rqstp,
+						      &clverifier);
 	}
 	new->cl_minorversion = 0;
 	gen_callback(new, setclid, rqstp);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 80fd6ca6ae46..2c0392f30a86 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -592,6 +592,38 @@ TRACE_EVENT(nfsd_clid_cred_mismatch,
 	)
 )
 
+TRACE_EVENT(nfsd_clid_verf_mismatch,
+	TP_PROTO(
+		const struct nfs4_client *clp,
+		const struct svc_rqst *rqstp,
+		const nfs4_verifier *verf
+	),
+	TP_ARGS(clp, rqstp, verf),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__array(unsigned char, cl_verifier, NFS4_VERIFIER_SIZE)
+		__array(unsigned char, new_verifier, NFS4_VERIFIER_SIZE)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+	),
+	TP_fast_assign(
+		__entry->cl_boot = clp->cl_clientid.cl_boot;
+		__entry->cl_id = clp->cl_clientid.cl_id;
+		memcpy(__entry->cl_verifier, (void *)&clp->cl_verifier,
+		       NFS4_VERIFIER_SIZE);
+		memcpy(__entry->new_verifier, (void *)verf,
+		       NFS4_VERIFIER_SIZE);
+		memcpy(__entry->addr, &rqstp->rq_xprt->xpt_remote,
+			sizeof(struct sockaddr_in6));
+	),
+	TP_printk("client %08x:%08x verf=0x%s, updated=0x%s from addr=%pISpc",
+		__entry->cl_boot, __entry->cl_id,
+		__print_hex_str(__entry->cl_verifier, NFS4_VERIFIER_SIZE),
+		__print_hex_str(__entry->new_verifier, NFS4_VERIFIER_SIZE),
+		__entry->addr
+	)
+);
+
 TRACE_EVENT(nfsd_clid_inuse_err,
 	TP_PROTO(const struct nfs4_client *clp),
 	TP_ARGS(clp),



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 16/21] NFSD: Remove nfsd_clid_inuse_err
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (14 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 17/21] NFSD: Add nfsd_clid_confirmed tracepoint Chuck Lever
                   ` (5 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

This tracepoint has been replaced by nfsd_clid_cred_mismatch and
nfsd_clid_verf_mismatch.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/trace.h |   24 ------------------------
 1 file changed, 24 deletions(-)

diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 2c0392f30a86..bc495876e4ae 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -624,30 +624,6 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
 	)
 );
 
-TRACE_EVENT(nfsd_clid_inuse_err,
-	TP_PROTO(const struct nfs4_client *clp),
-	TP_ARGS(clp),
-	TP_STRUCT__entry(
-		__field(u32, cl_boot)
-		__field(u32, cl_id)
-		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
-		__field(unsigned int, namelen)
-		__dynamic_array(unsigned char, name, clp->cl_name.len)
-	),
-	TP_fast_assign(
-		__entry->cl_boot = clp->cl_clientid.cl_boot;
-		__entry->cl_id = clp->cl_clientid.cl_id;
-		memcpy(__entry->addr, &clp->cl_addr,
-			sizeof(struct sockaddr_in6));
-		__entry->namelen = clp->cl_name.len;
-		memcpy(__get_dynamic_array(name), clp->cl_name.data,
-			clp->cl_name.len);
-	),
-	TP_printk("nfs4_clientid %.*s already in use by %pISpc, client %08x:%08x",
-		__entry->namelen, __get_str(name), __entry->addr,
-		__entry->cl_boot, __entry->cl_id)
-)
-
 /*
  * from fs/nfsd/filecache.h
  */



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 17/21] NFSD: Add nfsd_clid_confirmed tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (15 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 16/21] NFSD: Remove nfsd_clid_inuse_err Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 18/21] NFSD: Add nfsd_clid_destroyed tracepoint Chuck Lever
                   ` (4 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

This replaces a dprintk call site in order to get greater visibility
on when client IDs are confirmed or re-used. Simple example:

            nfsd-995   [000]   126.622975: nfsd_compound:        xid=0x3a34e2b1 opcnt=1
            nfsd-995   [000]   126.623005: nfsd_cb_args:         addr=192.168.2.51:45901 client 60958e3b:9213ef0e prog=1073741824 ident=1
            nfsd-995   [000]   126.623007: nfsd_compound_status: op=1/1 OP_SETCLIENTID status=0
            nfsd-996   [001]   126.623142: nfsd_compound:        xid=0x3b34e2b1 opcnt=1
  >>>>      nfsd-996   [001]   126.623146: nfsd_clid_confirmed:  client 60958e3b:9213ef0e
            nfsd-996   [001]   126.623148: nfsd_cb_probe:        addr=192.168.2.51:45901 client 60958e3b:9213ef0e state=UNKNOWN
            nfsd-996   [001]   126.623154: nfsd_compound_status: op=1/1 OP_SETCLIENTID_CONFIRM status=0

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |   10 +++++-----
 fs/nfsd/trace.h     |    1 +
 2 files changed, 6 insertions(+), 5 deletions(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 56ca79f55da4..f40d948964f5 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -2818,14 +2818,14 @@ move_to_confirmed(struct nfs4_client *clp)
 
 	lockdep_assert_held(&nn->client_lock);
 
-	dprintk("NFSD: move_to_confirm nfs4_client %p\n", clp);
 	list_move(&clp->cl_idhash, &nn->conf_id_hashtbl[idhashval]);
 	rb_erase(&clp->cl_namenode, &nn->unconf_name_tree);
 	add_clp_to_name_tree(clp, &nn->conf_name_tree);
-	if (!test_and_set_bit(NFSD4_CLIENT_CONFIRMED, &clp->cl_flags) &&
-	    clp->cl_nfsd_dentry &&
-	    clp->cl_nfsd_info_dentry)
-		fsnotify_dentry(clp->cl_nfsd_info_dentry, FS_MODIFY);
+	if (!test_and_set_bit(NFSD4_CLIENT_CONFIRMED, &clp->cl_flags)) {
+		trace_nfsd_clid_confirmed(&clp->cl_clientid);
+		if (clp->cl_nfsd_dentry && clp->cl_nfsd_info_dentry)
+			fsnotify_dentry(clp->cl_nfsd_info_dentry, FS_MODIFY);
+	}
 	renew_client_locked(clp);
 }
 
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index bc495876e4ae..a39a7c9ac217 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -510,6 +510,7 @@ DEFINE_EVENT(nfsd_clientid_class, nfsd_clid_##name, \
 	TP_PROTO(const clientid_t *clid), \
 	TP_ARGS(clid))
 
+DEFINE_CLIENTID_EVENT(confirmed);
 DEFINE_CLIENTID_EVENT(expired);
 DEFINE_CLIENTID_EVENT(purged);
 DEFINE_CLIENTID_EVENT(renew);



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 18/21] NFSD: Add nfsd_clid_destroyed tracepoint
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (16 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 17/21] NFSD: Add nfsd_clid_confirmed tracepoint Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 19/21] NFSD: Add a couple more nfsd_clid_expired call sites Chuck Lever
                   ` (3 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Record client-requested termination of client IDs.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    1 +
 fs/nfsd/trace.h     |    1 +
 2 files changed, 2 insertions(+)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index f40d948964f5..52e03e9ab021 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3909,6 +3909,7 @@ nfsd4_destroy_clientid(struct svc_rqst *rqstp,
 		status = nfserr_wrong_cred;
 		goto out;
 	}
+	trace_nfsd_clid_destroyed(&clp->cl_clientid);
 	unhash_client_locked(clp);
 out:
 	spin_unlock(&nn->client_lock);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index a39a7c9ac217..9567840f8580 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -511,6 +511,7 @@ DEFINE_EVENT(nfsd_clientid_class, nfsd_clid_##name, \
 	TP_ARGS(clid))
 
 DEFINE_CLIENTID_EVENT(confirmed);
+DEFINE_CLIENTID_EVENT(destroyed);
 DEFINE_CLIENTID_EVENT(expired);
 DEFINE_CLIENTID_EVENT(purged);
 DEFINE_CLIENTID_EVENT(renew);



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 19/21] NFSD: Add a couple more nfsd_clid_expired call sites
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (17 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 18/21] NFSD: Add nfsd_clid_destroyed tracepoint Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 20/21] NFSD: Rename nfsd_clid_class Chuck Lever
                   ` (2 subsequent siblings)
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Improve observation of NFSv4 lease expiry.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    3 +++
 1 file changed, 3 insertions(+)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index 52e03e9ab021..a61601fe422a 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -2667,6 +2667,8 @@ static void force_expire_client(struct nfs4_client *clp)
 	struct nfsd_net *nn = net_generic(clp->net, nfsd_net_id);
 	bool already_expired;
 
+	trace_nfsd_clid_expired(&clp->cl_clientid);
+
 	spin_lock(&clp->cl_lock);
 	clp->cl_time = 0;
 	spin_unlock(&clp->cl_lock);
@@ -4076,6 +4078,7 @@ nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
 				goto out;
 			status = mark_client_expired_locked(old);
 			if (status) {
+				trace_nfsd_clid_expired(&old->cl_clientid);
 				old = NULL;
 				goto out;
 			}



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 20/21] NFSD: Rename nfsd_clid_class
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (18 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 19/21] NFSD: Add a couple more nfsd_clid_expired call sites Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 15:53 ` [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity Chuck Lever
  2021-05-10 17:24 ` [PATCH RFC 00/21] NFSD callback and lease management observability David Wysochanski
  21 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

Clean up in preparation for subsequent patches.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/trace.h |   10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 9567840f8580..523045c37749 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -537,7 +537,7 @@ DEFINE_EVENT(nfsd_net_class, nfsd_##name, \
 DEFINE_NET_EVENT(grace_start);
 DEFINE_NET_EVENT(grace_complete);
 
-DECLARE_EVENT_CLASS(nfsd_clid_class,
+DECLARE_EVENT_CLASS(nfsd_reclaim_class,
 	TP_PROTO(const struct nfsd_net *nn,
 		 unsigned int namelen,
 		 const unsigned char *namedata),
@@ -556,15 +556,15 @@ DECLARE_EVENT_CLASS(nfsd_clid_class,
 		__entry->boot_time, __entry->namelen, __get_str(name))
 )
 
-#define DEFINE_CLID_EVENT(name) \
-DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
+#define DEFINE_RECLAIM_EVENT(name) \
+DEFINE_EVENT(nfsd_reclaim_class, nfsd_clid_##name, \
 	TP_PROTO(const struct nfsd_net *nn, \
 		 unsigned int namelen, \
 		 const unsigned char *namedata), \
 	TP_ARGS(nn, namelen, namedata))
 
-DEFINE_CLID_EVENT(find);
-DEFINE_CLID_EVENT(reclaim);
+DEFINE_RECLAIM_EVENT(find);
+DEFINE_RECLAIM_EVENT(reclaim);
 
 TRACE_EVENT(nfsd_clid_cred_mismatch,
 	TP_PROTO(



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (19 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 20/21] NFSD: Rename nfsd_clid_class Chuck Lever
@ 2021-05-10 15:53 ` Chuck Lever
  2021-05-10 19:56   ` David Wysochanski
  2021-05-11 15:59   ` Chuck Lever III
  2021-05-10 17:24 ` [PATCH RFC 00/21] NFSD callback and lease management observability David Wysochanski
  21 siblings, 2 replies; 35+ messages in thread
From: Chuck Lever @ 2021-05-10 15:53 UTC (permalink / raw)
  To: dwysocha, bfields; +Cc: linux-nfs

We are especially interested in capturing clientID conflicts.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 fs/nfsd/nfs4state.c |    9 +++++++--
 fs/nfsd/trace.h     |   37 +++++++++++++++++++++++++++++++++++++
 2 files changed, 44 insertions(+), 2 deletions(-)

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index a61601fe422a..528cabffa1e9 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3180,6 +3180,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 			}
 			/* case 6 */
 			exid->flags |= EXCHGID4_FLAG_CONFIRMED_R;
+			trace_nfsd_clid_existing(conf);
 			goto out_copy;
 		}
 		if (!creds_match) { /* case 3 */
@@ -3188,15 +3189,18 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 				trace_nfsd_clid_cred_mismatch(conf, rqstp);
 				goto out;
 			}
+			trace_nfsd_clid_new(new);
 			goto out_new;
 		}
 		if (verfs_match) { /* case 2 */
 			conf->cl_exchange_flags |= EXCHGID4_FLAG_CONFIRMED_R;
+			trace_nfsd_clid_existing(conf);
 			goto out_copy;
 		}
 		/* case 5, client reboot */
 		trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
 		conf = NULL;
+		trace_nfsd_clid_new(new);
 		goto out_new;
 	}
 
@@ -3996,10 +4000,12 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 		if (same_verf(&conf->cl_verifier, &clverifier)) {
 			copy_clid(new, conf);
 			gen_confirm(new, nn);
+			trace_nfsd_clid_existing(new);
 		} else
 			trace_nfsd_clid_verf_mismatch(conf, rqstp,
 						      &clverifier);
-	}
+	} else
+		trace_nfsd_clid_new(new);
 	new->cl_minorversion = 0;
 	gen_callback(new, setclid, rqstp);
 	add_to_unconfirmed(new);
@@ -4017,7 +4023,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	return status;
 }
 
-
 __be32
 nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
 			struct nfsd4_compound_state *cstate,
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 523045c37749..6ddff13e3181 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -626,6 +626,43 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
 	)
 );
 
+DECLARE_EVENT_CLASS(nfsd_clid_class,
+	TP_PROTO(const struct nfs4_client *clp),
+	TP_ARGS(clp),
+	TP_STRUCT__entry(
+		__field(u32, cl_boot)
+		__field(u32, cl_id)
+		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
+		__field(unsigned long, flavor)
+		__array(unsigned char, verifier, NFS4_VERIFIER_SIZE)
+		__field(unsigned int, namelen)
+		__dynamic_array(unsigned char, name, clp->cl_name.len)
+	),
+	TP_fast_assign(
+		memcpy(__entry->addr, &clp->cl_addr,
+			sizeof(struct sockaddr_in6));
+		__entry->flavor = clp->cl_cred.cr_flavor;
+		memcpy(__entry->verifier, (void *)&clp->cl_verifier,
+		       NFS4_VERIFIER_SIZE);
+		__entry->namelen = clp->cl_name.len;
+		memcpy(__get_dynamic_array(name), clp->cl_name.data,
+			clp->cl_name.len);
+	),
+	TP_printk("addr=%pISpc name='%.*s' verifier=0x%s flavor=%s client=%08x:%08x\n",
+		__entry->addr, __entry->namelen, __get_str(name),
+		__print_hex_str(__entry->verifier, NFS4_VERIFIER_SIZE),
+		show_nfsd_authflavor(__entry->flavor),
+		__entry->cl_boot, __entry->cl_id)
+);
+
+#define DEFINE_CLID_EVENT(name) \
+DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
+	TP_PROTO(const struct nfs4_client *clp), \
+	TP_ARGS(clp))
+
+DEFINE_CLID_EVENT(new);
+DEFINE_CLID_EVENT(existing);
+
 /*
  * from fs/nfsd/filecache.h
  */



^ permalink raw reply related	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 00/21] NFSD callback and lease management observability
  2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
                   ` (20 preceding siblings ...)
  2021-05-10 15:53 ` [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity Chuck Lever
@ 2021-05-10 17:24 ` David Wysochanski
  21 siblings, 0 replies; 35+ messages in thread
From: David Wysochanski @ 2021-05-10 17:24 UTC (permalink / raw)
  To: Chuck Lever; +Cc: J. Bruce Fields, linux-nfs

On Mon, May 10, 2021 at 11:51 AM Chuck Lever <chuck.lever@oracle.com> wrote:
>
> Happy Monday.
>
> I've hacked together some improvements to the tracepoints that record
> server callback and lease management activity. I'm interested in
> review comments and testing. I'm sure I've missed your favorite edge
> case, so please let me know what it is!
>

I will take a look at these, especially with an eye towards some of
the recent discussions about duplicate client ids.
Building now (against 5.13-rc1).

Thanks Chuck!

> ---
>
> Chuck Lever (21):
>       NFSD: Constify @fh argument of knfsd_fh_hash()
>       NFSD: Capture every CB state transition
>       NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros
>       NFSD: Add cb_lost tracepoint
>       NFSD: Adjust cb_shutdown tracepoint
>       NFSD: Remove spurious cb_setup_err tracepoint
>       NFSD: Enhance the nfsd_cb_setup tracepoint
>       NFSD: Add an nfsd_cb_lm_notify tracepoint
>       NFSD: Add an nfsd_cb_offload tracepoint
>       NFSD: Replace the nfsd_deleg_break tracepoint
>       NFSD: Add an nfsd_cb_probe tracepoint
>       NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints
>       NFSD: Update nfsd_cb_args tracepoint
>       NFSD: Add nfsd_clid_cred_mismatch tracepoint
>       NFSD: Add nfsd_clid_verf_mismatch tracepoint
>       NFSD: Remove nfsd_clid_inuse_err
>       NFSD: Add nfsd_clid_confirmed tracepoint
>       NFSD: Add nfsd_clid_destroyed tracepoint
>       NFSD: Add a couple more nfsd_clid_expired call sites
>       NFSD: Rename nfsd_clid_class
>       NFSD: Add tracepoints to observe clientID activity
>
>
>  fs/nfsd/nfs4callback.c |  45 ++++----
>  fs/nfsd/nfs4proc.c     |   1 +
>  fs/nfsd/nfs4state.c    |  56 +++++++---
>  fs/nfsd/nfsfh.h        |   7 +-
>  fs/nfsd/trace.h        | 227 ++++++++++++++++++++++++++++++++++-------
>  5 files changed, 254 insertions(+), 82 deletions(-)
>
> --
> Chuck Lever
>


^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-10 15:53 ` [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity Chuck Lever
@ 2021-05-10 19:56   ` David Wysochanski
  2021-05-10 20:00     ` Chuck Lever III
  2021-05-11 15:59   ` Chuck Lever III
  1 sibling, 1 reply; 35+ messages in thread
From: David Wysochanski @ 2021-05-10 19:56 UTC (permalink / raw)
  To: Chuck Lever; +Cc: J. Bruce Fields, linux-nfs

On Mon, May 10, 2021 at 11:53 AM Chuck Lever <chuck.lever@oracle.com> wrote:
>
> We are especially interested in capturing clientID conflicts.
>
> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> ---
>  fs/nfsd/nfs4state.c |    9 +++++++--
>  fs/nfsd/trace.h     |   37 +++++++++++++++++++++++++++++++++++++
>  2 files changed, 44 insertions(+), 2 deletions(-)
>
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index a61601fe422a..528cabffa1e9 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -3180,6 +3180,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>                         }
>                         /* case 6 */
>                         exid->flags |= EXCHGID4_FLAG_CONFIRMED_R;
> +                       trace_nfsd_clid_existing(conf);
>                         goto out_copy;
>                 }
>                 if (!creds_match) { /* case 3 */
> @@ -3188,15 +3189,18 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>                                 trace_nfsd_clid_cred_mismatch(conf, rqstp);
>                                 goto out;
>                         }
> +                       trace_nfsd_clid_new(new);
>                         goto out_new;
>                 }
>                 if (verfs_match) { /* case 2 */
>                         conf->cl_exchange_flags |= EXCHGID4_FLAG_CONFIRMED_R;
> +                       trace_nfsd_clid_existing(conf);
>                         goto out_copy;
>                 }
>                 /* case 5, client reboot */
>                 trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
>                 conf = NULL;
> +               trace_nfsd_clid_new(new);
>                 goto out_new;
>         }
>
> @@ -3996,10 +4000,12 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>                 if (same_verf(&conf->cl_verifier, &clverifier)) {
>                         copy_clid(new, conf);
>                         gen_confirm(new, nn);
> +                       trace_nfsd_clid_existing(new);
>                 } else
>                         trace_nfsd_clid_verf_mismatch(conf, rqstp,
>                                                       &clverifier);
> -       }
> +       } else
> +               trace_nfsd_clid_new(new);
>         new->cl_minorversion = 0;
>         gen_callback(new, setclid, rqstp);
>         add_to_unconfirmed(new);
> @@ -4017,7 +4023,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>         return status;
>  }
>
> -
>  __be32
>  nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
>                         struct nfsd4_compound_state *cstate,
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 523045c37749..6ddff13e3181 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -626,6 +626,43 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
>         )
>  );
>
> +DECLARE_EVENT_CLASS(nfsd_clid_class,
> +       TP_PROTO(const struct nfs4_client *clp),
> +       TP_ARGS(clp),
> +       TP_STRUCT__entry(
> +               __field(u32, cl_boot)
> +               __field(u32, cl_id)
> +               __array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +               __field(unsigned long, flavor)
> +               __array(unsigned char, verifier, NFS4_VERIFIER_SIZE)
> +               __field(unsigned int, namelen)
> +               __dynamic_array(unsigned char, name, clp->cl_name.len)
> +       ),
> +       TP_fast_assign(
> +               memcpy(__entry->addr, &clp->cl_addr,
> +                       sizeof(struct sockaddr_in6));
> +               __entry->flavor = clp->cl_cred.cr_flavor;
> +               memcpy(__entry->verifier, (void *)&clp->cl_verifier,
> +                      NFS4_VERIFIER_SIZE);
> +               __entry->namelen = clp->cl_name.len;
> +               memcpy(__get_dynamic_array(name), clp->cl_name.data,
> +                       clp->cl_name.len);
> +       ),
> +       TP_printk("addr=%pISpc name='%.*s' verifier=0x%s flavor=%s client=%08x:%08x\n",
> +               __entry->addr, __entry->namelen, __get_str(name),
> +               __print_hex_str(__entry->verifier, NFS4_VERIFIER_SIZE),
> +               show_nfsd_authflavor(__entry->flavor),
> +               __entry->cl_boot, __entry->cl_id)
> +);
> +
> +#define DEFINE_CLID_EVENT(name) \
> +DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
> +       TP_PROTO(const struct nfs4_client *clp), \
> +       TP_ARGS(clp))
> +
> +DEFINE_CLID_EVENT(new);
> +DEFINE_CLID_EVENT(existing);
> +
>  /*
>   * from fs/nfsd/filecache.h
>   */
>
>

I just got this oops when testing duplicate hostnames and having
enabled these tracepoints with:
trace-cmd start -e nfsd:nfsd_clid*

[  408.119259] ------------[ cut here ]------------
[  408.136659] fmt: 'addr=%pISpc name='%.*s' verifier=0x%s flavor=%s
client=%08x:%08x
[  408.136659]
[  408.136659] ' current_buffer: '            nfsd-1117    [001] ....
 408.844043: nfsd_clid_new: addr=192.168.122.8:676 name=''
[  408.136831] WARNING: CPU: 4 PID: 15097 at kernel/trace/trace.c:3759
trace_check_vprintf+0x9f9/0x1040
[  408.149530] Modules linked in: nft_fib_inet nft_fib_ipv4
nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6
nft_reject nft_ct nft_chain_nat nf_tables ebtable_nat ebtable_broute
ip6table_nat ip6table_mangle ip6table_raw ip6table_security
iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
iptable_mangle iptable_raw iptable_security ip_set rfkill nfnetlink
ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter
cachefiles intel_rapl_msr intel_rapl_common joydev virtio_balloon nfsd
i2c_piix4 auth_rpcgss nfs_acl lockd grace sunrpc drm ip_tables xfs
libcrc32c crct10dif_pclmul crc32_pclmul crc32c_intel virtio_net
ata_generic ghash_clmulni_intel net_failover virtio_console serio_raw
pata_acpi virtio_blk failover qemu_fw_cfg
[  408.176536] CPU: 4 PID: 15097 Comm: trace-cmd Kdump: loaded Not
tainted 5.13.0-rc1-chuck-nfsd+ #12
[  408.180288] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
[  408.182731] RIP: 0010:trace_check_vprintf+0x9f9/0x1040
[  408.184912] Code: 00 00 49 8b 94 24 b0 20 00 00 48 8b 74 24 30 4c
89 4c 24 18 48 c7 c7 00 65 6c ba 44 89 44 24 10 4c 89 54 24 08 e8 e5
a2 bd 01 <0f> 0b 4c 8b 54 24 08 44 8b 44 24 10 4c 8b 4c 24 18 e9 c8 fc
ff ff
[  408.192521] RSP: 0018:ffff888115617a30 EFLAGS: 00010282
[  408.194732] RAX: 0000000000000000 RBX: 0000000000000013 RCX: 0000000000000000
[  408.197706] RDX: 0000000000000027 RSI: 0000000000000004 RDI: ffffed1022ac2f3c
[  408.200667] RBP: dffffc0000000000 R08: 0000000000000001 R09: ffff8881e3d20a0b
[  408.203621] R10: ffffed103c7a4141 R11: 0000000000000001 R12: ffff888110984000
[  408.206571] R13: ffffffffc0ef9b80 R14: ffff8881109850b0 R15: ffff8881109860b0
[  408.209537] FS:  00007fc70350b740(0000) GS:ffff8881e3d00000(0000)
knlGS:0000000000000000
[  408.212887] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  408.215297] CR2: 00005638a21aa9c8 CR3: 000000010c53a000 CR4: 00000000000406e0
[  408.218245] Call Trace:
[  408.219335]  trace_event_printf+0x9d/0xc0
[  408.221041]  ? trace_print_hex_dump_seq+0x120/0x120
[  408.223137]  trace_raw_output_nfsd_clid_class+0x175/0x1f0 [nfsd]
[  408.225936]  print_trace_line+0x75c/0x1430
[  408.227709]  ? tracing_buffers_read+0x820/0x820
[  408.229637]  ? _raw_spin_unlock_irqrestore+0xa/0x20
[  408.231710]  ? trace_find_next_entry_inc+0x10f/0x1b0
[  408.233815]  s_show+0xc1/0x3d0
[  408.235431]  seq_read_iter+0x93c/0xfe0
[  408.237042]  ? lru_cache_add+0x176/0x290
[  408.238722]  seq_read+0x311/0x4c0
[  408.246280]  ? seq_read_iter+0xfe0/0xfe0
[  408.247937]  ? vm_iomap_memory+0x1d0/0x1d0
[  408.249705]  ? inode_security+0x43/0xe0
[  408.251393]  vfs_read+0x111/0x400
[  408.252841]  ksys_read+0xdd/0x1a0
[  408.254279]  ? __ia32_sys_pwrite64+0x1b0/0x1b0
[  408.256138]  do_syscall_64+0x40/0x80
[  408.257670]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[  408.259767] RIP: 0033:0x7fc703600442


^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-10 19:56   ` David Wysochanski
@ 2021-05-10 20:00     ` Chuck Lever III
  0 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever III @ 2021-05-10 20:00 UTC (permalink / raw)
  To: David Wysochanski; +Cc: Bruce Fields, Linux NFS Mailing List

> [  408.223137]  trace_raw_output_nfsd_clid_class+0x175/0x1f0 [nfsd]


That's from the newest patch, so not surprising. I'll have a look.


> On May 10, 2021, at 3:56 PM, David Wysochanski <dwysocha@redhat.com> wrote:
> 
> On Mon, May 10, 2021 at 11:53 AM Chuck Lever <chuck.lever@oracle.com> wrote:
>> 
>> We are especially interested in capturing clientID conflicts.
>> 
>> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
>> ---
>> fs/nfsd/nfs4state.c |    9 +++++++--
>> fs/nfsd/trace.h     |   37 +++++++++++++++++++++++++++++++++++++
>> 2 files changed, 44 insertions(+), 2 deletions(-)
>> 
>> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
>> index a61601fe422a..528cabffa1e9 100644
>> --- a/fs/nfsd/nfs4state.c
>> +++ b/fs/nfsd/nfs4state.c
>> @@ -3180,6 +3180,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>>                        }
>>                        /* case 6 */
>>                        exid->flags |= EXCHGID4_FLAG_CONFIRMED_R;
>> +                       trace_nfsd_clid_existing(conf);
>>                        goto out_copy;
>>                }
>>                if (!creds_match) { /* case 3 */
>> @@ -3188,15 +3189,18 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>>                                trace_nfsd_clid_cred_mismatch(conf, rqstp);
>>                                goto out;
>>                        }
>> +                       trace_nfsd_clid_new(new);
>>                        goto out_new;
>>                }
>>                if (verfs_match) { /* case 2 */
>>                        conf->cl_exchange_flags |= EXCHGID4_FLAG_CONFIRMED_R;
>> +                       trace_nfsd_clid_existing(conf);
>>                        goto out_copy;
>>                }
>>                /* case 5, client reboot */
>>                trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
>>                conf = NULL;
>> +               trace_nfsd_clid_new(new);
>>                goto out_new;
>>        }
>> 
>> @@ -3996,10 +4000,12 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>>                if (same_verf(&conf->cl_verifier, &clverifier)) {
>>                        copy_clid(new, conf);
>>                        gen_confirm(new, nn);
>> +                       trace_nfsd_clid_existing(new);
>>                } else
>>                        trace_nfsd_clid_verf_mismatch(conf, rqstp,
>>                                                      &clverifier);
>> -       }
>> +       } else
>> +               trace_nfsd_clid_new(new);
>>        new->cl_minorversion = 0;
>>        gen_callback(new, setclid, rqstp);
>>        add_to_unconfirmed(new);
>> @@ -4017,7 +4023,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>>        return status;
>> }
>> 
>> -
>> __be32
>> nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
>>                        struct nfsd4_compound_state *cstate,
>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>> index 523045c37749..6ddff13e3181 100644
>> --- a/fs/nfsd/trace.h
>> +++ b/fs/nfsd/trace.h
>> @@ -626,6 +626,43 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
>>        )
>> );
>> 
>> +DECLARE_EVENT_CLASS(nfsd_clid_class,
>> +       TP_PROTO(const struct nfs4_client *clp),
>> +       TP_ARGS(clp),
>> +       TP_STRUCT__entry(
>> +               __field(u32, cl_boot)
>> +               __field(u32, cl_id)
>> +               __array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +               __field(unsigned long, flavor)
>> +               __array(unsigned char, verifier, NFS4_VERIFIER_SIZE)
>> +               __field(unsigned int, namelen)
>> +               __dynamic_array(unsigned char, name, clp->cl_name.len)
>> +       ),
>> +       TP_fast_assign(
>> +               memcpy(__entry->addr, &clp->cl_addr,
>> +                       sizeof(struct sockaddr_in6));
>> +               __entry->flavor = clp->cl_cred.cr_flavor;
>> +               memcpy(__entry->verifier, (void *)&clp->cl_verifier,
>> +                      NFS4_VERIFIER_SIZE);
>> +               __entry->namelen = clp->cl_name.len;
>> +               memcpy(__get_dynamic_array(name), clp->cl_name.data,
>> +                       clp->cl_name.len);
>> +       ),
>> +       TP_printk("addr=%pISpc name='%.*s' verifier=0x%s flavor=%s client=%08x:%08x\n",
>> +               __entry->addr, __entry->namelen, __get_str(name),
>> +               __print_hex_str(__entry->verifier, NFS4_VERIFIER_SIZE),
>> +               show_nfsd_authflavor(__entry->flavor),
>> +               __entry->cl_boot, __entry->cl_id)
>> +);
>> +
>> +#define DEFINE_CLID_EVENT(name) \
>> +DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
>> +       TP_PROTO(const struct nfs4_client *clp), \
>> +       TP_ARGS(clp))
>> +
>> +DEFINE_CLID_EVENT(new);
>> +DEFINE_CLID_EVENT(existing);
>> +
>> /*
>>  * from fs/nfsd/filecache.h
>>  */
>> 
>> 
> 
> I just got this oops when testing duplicate hostnames and having
> enabled these tracepoints with:
> trace-cmd start -e nfsd:nfsd_clid*
> 
> [  408.119259] ------------[ cut here ]------------
> [  408.136659] fmt: 'addr=%pISpc name='%.*s' verifier=0x%s flavor=%s
> client=%08x:%08x
> [  408.136659]
> [  408.136659] ' current_buffer: '            nfsd-1117    [001] ....
> 408.844043: nfsd_clid_new: addr=192.168.122.8:676 name=''
> [  408.136831] WARNING: CPU: 4 PID: 15097 at kernel/trace/trace.c:3759
> trace_check_vprintf+0x9f9/0x1040
> [  408.149530] Modules linked in: nft_fib_inet nft_fib_ipv4
> nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6
> nft_reject nft_ct nft_chain_nat nf_tables ebtable_nat ebtable_broute
> ip6table_nat ip6table_mangle ip6table_raw ip6table_security
> iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4
> iptable_mangle iptable_raw iptable_security ip_set rfkill nfnetlink
> ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter
> cachefiles intel_rapl_msr intel_rapl_common joydev virtio_balloon nfsd
> i2c_piix4 auth_rpcgss nfs_acl lockd grace sunrpc drm ip_tables xfs
> libcrc32c crct10dif_pclmul crc32_pclmul crc32c_intel virtio_net
> ata_generic ghash_clmulni_intel net_failover virtio_console serio_raw
> pata_acpi virtio_blk failover qemu_fw_cfg
> [  408.176536] CPU: 4 PID: 15097 Comm: trace-cmd Kdump: loaded Not
> tainted 5.13.0-rc1-chuck-nfsd+ #12
> [  408.180288] Hardware name: Red Hat KVM, BIOS 0.5.1 01/01/2011
> [  408.182731] RIP: 0010:trace_check_vprintf+0x9f9/0x1040
> [  408.184912] Code: 00 00 49 8b 94 24 b0 20 00 00 48 8b 74 24 30 4c
> 89 4c 24 18 48 c7 c7 00 65 6c ba 44 89 44 24 10 4c 89 54 24 08 e8 e5
> a2 bd 01 <0f> 0b 4c 8b 54 24 08 44 8b 44 24 10 4c 8b 4c 24 18 e9 c8 fc
> ff ff
> [  408.192521] RSP: 0018:ffff888115617a30 EFLAGS: 00010282
> [  408.194732] RAX: 0000000000000000 RBX: 0000000000000013 RCX: 0000000000000000
> [  408.197706] RDX: 0000000000000027 RSI: 0000000000000004 RDI: ffffed1022ac2f3c
> [  408.200667] RBP: dffffc0000000000 R08: 0000000000000001 R09: ffff8881e3d20a0b
> [  408.203621] R10: ffffed103c7a4141 R11: 0000000000000001 R12: ffff888110984000
> [  408.206571] R13: ffffffffc0ef9b80 R14: ffff8881109850b0 R15: ffff8881109860b0
> [  408.209537] FS:  00007fc70350b740(0000) GS:ffff8881e3d00000(0000)
> knlGS:0000000000000000
> [  408.212887] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  408.215297] CR2: 00005638a21aa9c8 CR3: 000000010c53a000 CR4: 00000000000406e0
> [  408.218245] Call Trace:
> [  408.219335]  trace_event_printf+0x9d/0xc0
> [  408.221041]  ? trace_print_hex_dump_seq+0x120/0x120
> [  408.223137]  trace_raw_output_nfsd_clid_class+0x175/0x1f0 [nfsd]
> [  408.225936]  print_trace_line+0x75c/0x1430
> [  408.227709]  ? tracing_buffers_read+0x820/0x820
> [  408.229637]  ? _raw_spin_unlock_irqrestore+0xa/0x20
> [  408.231710]  ? trace_find_next_entry_inc+0x10f/0x1b0
> [  408.233815]  s_show+0xc1/0x3d0
> [  408.235431]  seq_read_iter+0x93c/0xfe0
> [  408.237042]  ? lru_cache_add+0x176/0x290
> [  408.238722]  seq_read+0x311/0x4c0
> [  408.246280]  ? seq_read_iter+0xfe0/0xfe0
> [  408.247937]  ? vm_iomap_memory+0x1d0/0x1d0
> [  408.249705]  ? inode_security+0x43/0xe0
> [  408.251393]  vfs_read+0x111/0x400
> [  408.252841]  ksys_read+0xdd/0x1a0
> [  408.254279]  ? __ia32_sys_pwrite64+0x1b0/0x1b0
> [  408.256138]  do_syscall_64+0x40/0x80
> [  408.257670]  entry_SYSCALL_64_after_hwframe+0x44/0xae
> [  408.259767] RIP: 0033:0x7fc703600442
> 

--
Chuck Lever




^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint
  2021-05-10 15:52 ` [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint Chuck Lever
@ 2021-05-10 20:27   ` J. Bruce Fields
  2021-05-10 20:29     ` Chuck Lever III
  0 siblings, 1 reply; 35+ messages in thread
From: J. Bruce Fields @ 2021-05-10 20:27 UTC (permalink / raw)
  To: Chuck Lever; +Cc: dwysocha, linux-nfs

On Mon, May 10, 2021 at 11:52:14AM -0400, Chuck Lever wrote:
> This path is not really an error path,

What's the non-error case for this path?

On a quick look it seems like that'd mean a 4.1 client doesn't have a
connection available for the backchannel, which sounds bad.

But I'm probably overlooking something....

--b.

> so the tracepoint I added
> there is just noise.
> 
> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> ---
>  fs/nfsd/nfs4callback.c |    4 +---
>  1 file changed, 1 insertion(+), 3 deletions(-)
> 
> diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
> index ab1836381e22..15ba16c54793 100644
> --- a/fs/nfsd/nfs4callback.c
> +++ b/fs/nfsd/nfs4callback.c
> @@ -915,10 +915,8 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
>  		args.authflavor = clp->cl_cred.cr_flavor;
>  		clp->cl_cb_ident = conn->cb_ident;
>  	} else {
> -		if (!conn->cb_xprt) {
> -			trace_nfsd_cb_setup_err(clp, -EINVAL);
> +		if (!conn->cb_xprt)
>  			return -EINVAL;
> -		}
>  		clp->cl_cb_conn.cb_xprt = conn->cb_xprt;
>  		clp->cl_cb_session = ses;
>  		args.bc_xprt = conn->cb_xprt;
> 

^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint
  2021-05-10 20:27   ` J. Bruce Fields
@ 2021-05-10 20:29     ` Chuck Lever III
  2021-05-11 17:44       ` Bruce Fields
  0 siblings, 1 reply; 35+ messages in thread
From: Chuck Lever III @ 2021-05-10 20:29 UTC (permalink / raw)
  To: Bruce Fields; +Cc: David Wysochanski, Linux NFS Mailing List



> On May 10, 2021, at 4:27 PM, J. Bruce Fields <bfields@fieldses.org> wrote:
> 
> On Mon, May 10, 2021 at 11:52:14AM -0400, Chuck Lever wrote:
>> This path is not really an error path,
> 
> What's the non-error case for this path?

From what I can tell, it appears to be the default exit for when
there is a session and backchannel. Feel free to straighten me
out, but it just seemed to always fire for NFSv4.1 mounts.


> On a quick look it seems like that'd mean a 4.1 client doesn't have a
> connection available for the backchannel, which sounds bad.
> 
> But I'm probably overlooking something....
> 
> --b.
> 
>> so the tracepoint I added
>> there is just noise.
>> 
>> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
>> ---
>> fs/nfsd/nfs4callback.c |    4 +---
>> 1 file changed, 1 insertion(+), 3 deletions(-)
>> 
>> diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
>> index ab1836381e22..15ba16c54793 100644
>> --- a/fs/nfsd/nfs4callback.c
>> +++ b/fs/nfsd/nfs4callback.c
>> @@ -915,10 +915,8 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
>> 		args.authflavor = clp->cl_cred.cr_flavor;
>> 		clp->cl_cb_ident = conn->cb_ident;
>> 	} else {
>> -		if (!conn->cb_xprt) {
>> -			trace_nfsd_cb_setup_err(clp, -EINVAL);
>> +		if (!conn->cb_xprt)
>> 			return -EINVAL;
>> -		}
>> 		clp->cl_cb_conn.cb_xprt = conn->cb_xprt;
>> 		clp->cl_cb_session = ses;
>> 		args.bc_xprt = conn->cb_xprt;
>> 

--
Chuck Lever




^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint
  2021-05-10 15:53 ` [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint Chuck Lever
@ 2021-05-11 15:49   ` J. Bruce Fields
  0 siblings, 0 replies; 35+ messages in thread
From: J. Bruce Fields @ 2021-05-11 15:49 UTC (permalink / raw)
  To: Chuck Lever; +Cc: dwysocha, linux-nfs

On Mon, May 10, 2021 at 11:53:10AM -0400, Chuck Lever wrote:
> Record when a client presents a different boot verifier than the
> one we know about. Typically this is a sign the client has
> rebooted, but sometimes it signals a conflicting client ID, which
> the client's administrator will need to address.

Yes.  I suspect this is much more common that the cred mismatch case,
unfortunately.  Without kerberos, we just don't have much to go
on--we're not supposed to use IP address, and the auth_unix cred itself
probably doesn't vary much across clients.

(Patch looks fine, just commenting on that because it's a confusing
point.)

--b.

> 
> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> ---
>  fs/nfsd/nfs4state.c |   11 ++++++++---
>  fs/nfsd/trace.h     |   32 ++++++++++++++++++++++++++++++++
>  2 files changed, 40 insertions(+), 3 deletions(-)
> 
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index 4feadb683a2d..56ca79f55da4 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -3193,6 +3193,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>  			goto out_copy;
>  		}
>  		/* case 5, client reboot */
> +		trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
>  		conf = NULL;
>  		goto out_new;
>  	}
> @@ -3988,9 +3989,13 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
>  	if (unconf)
>  		unhash_client_locked(unconf);
>  	/* We need to handle only case 1: probable callback update */
> -	if (conf && same_verf(&conf->cl_verifier, &clverifier)) {
> -		copy_clid(new, conf);
> -		gen_confirm(new, nn);
> +	if (conf) {
> +		if (same_verf(&conf->cl_verifier, &clverifier)) {
> +			copy_clid(new, conf);
> +			gen_confirm(new, nn);
> +		} else
> +			trace_nfsd_clid_verf_mismatch(conf, rqstp,
> +						      &clverifier);
>  	}
>  	new->cl_minorversion = 0;
>  	gen_callback(new, setclid, rqstp);
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 80fd6ca6ae46..2c0392f30a86 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -592,6 +592,38 @@ TRACE_EVENT(nfsd_clid_cred_mismatch,
>  	)
>  )
>  
> +TRACE_EVENT(nfsd_clid_verf_mismatch,
> +	TP_PROTO(
> +		const struct nfs4_client *clp,
> +		const struct svc_rqst *rqstp,
> +		const nfs4_verifier *verf
> +	),
> +	TP_ARGS(clp, rqstp, verf),
> +	TP_STRUCT__entry(
> +		__field(u32, cl_boot)
> +		__field(u32, cl_id)
> +		__array(unsigned char, cl_verifier, NFS4_VERIFIER_SIZE)
> +		__array(unsigned char, new_verifier, NFS4_VERIFIER_SIZE)
> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +	),
> +	TP_fast_assign(
> +		__entry->cl_boot = clp->cl_clientid.cl_boot;
> +		__entry->cl_id = clp->cl_clientid.cl_id;
> +		memcpy(__entry->cl_verifier, (void *)&clp->cl_verifier,
> +		       NFS4_VERIFIER_SIZE);
> +		memcpy(__entry->new_verifier, (void *)verf,
> +		       NFS4_VERIFIER_SIZE);
> +		memcpy(__entry->addr, &rqstp->rq_xprt->xpt_remote,
> +			sizeof(struct sockaddr_in6));
> +	),
> +	TP_printk("client %08x:%08x verf=0x%s, updated=0x%s from addr=%pISpc",
> +		__entry->cl_boot, __entry->cl_id,
> +		__print_hex_str(__entry->cl_verifier, NFS4_VERIFIER_SIZE),
> +		__print_hex_str(__entry->new_verifier, NFS4_VERIFIER_SIZE),
> +		__entry->addr
> +	)
> +);
> +
>  TRACE_EVENT(nfsd_clid_inuse_err,
>  	TP_PROTO(const struct nfs4_client *clp),
>  	TP_ARGS(clp),
> 

^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-10 15:53 ` [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity Chuck Lever
  2021-05-10 19:56   ` David Wysochanski
@ 2021-05-11 15:59   ` Chuck Lever III
  2021-05-11 17:38     ` Bruce Fields
  1 sibling, 1 reply; 35+ messages in thread
From: Chuck Lever III @ 2021-05-11 15:59 UTC (permalink / raw)
  To: Bruce Fields; +Cc: Linux NFS Mailing List, David Wysochanski

As Dave reported yesterday, this patch is unfinished and is probably
junk. But any thoughts on how the tracepoints should be organized
in this code would help.

So I was thinking we probably want a tracepoint to fire for each
case that is handled in this code (and in nfsd4_exchangeid).
However, this comment in nfsd4_setclientid:

   /* Cases below refer to rfc 3530 section 14.2.33: */

Is confusing.

- RFC 3530 is superceded by RFC 7530, and the section numbers have changed.

- The cases in this section in both RFCs aren't numbered, they are
bullet points.


> On May 10, 2021, at 11:53 AM, Chuck Lever <chuck.lever@oracle.com> wrote:
> 
> We are especially interested in capturing clientID conflicts.
> 
> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> ---
> fs/nfsd/nfs4state.c |    9 +++++++--
> fs/nfsd/trace.h     |   37 +++++++++++++++++++++++++++++++++++++
> 2 files changed, 44 insertions(+), 2 deletions(-)
> 
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index a61601fe422a..528cabffa1e9 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -3180,6 +3180,7 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 			}
> 			/* case 6 */
> 			exid->flags |= EXCHGID4_FLAG_CONFIRMED_R;
> +			trace_nfsd_clid_existing(conf);
> 			goto out_copy;
> 		}
> 		if (!creds_match) { /* case 3 */
> @@ -3188,15 +3189,18 @@ nfsd4_exchange_id(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 				trace_nfsd_clid_cred_mismatch(conf, rqstp);
> 				goto out;
> 			}
> +			trace_nfsd_clid_new(new);
> 			goto out_new;
> 		}
> 		if (verfs_match) { /* case 2 */
> 			conf->cl_exchange_flags |= EXCHGID4_FLAG_CONFIRMED_R;
> +			trace_nfsd_clid_existing(conf);
> 			goto out_copy;
> 		}
> 		/* case 5, client reboot */
> 		trace_nfsd_clid_verf_mismatch(conf, rqstp, &verf);
> 		conf = NULL;
> +		trace_nfsd_clid_new(new);
> 		goto out_new;
> 	}
> 
> @@ -3996,10 +4000,12 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 		if (same_verf(&conf->cl_verifier, &clverifier)) {
> 			copy_clid(new, conf);
> 			gen_confirm(new, nn);
> +			trace_nfsd_clid_existing(new);
> 		} else
> 			trace_nfsd_clid_verf_mismatch(conf, rqstp,
> 						      &clverifier);
> -	}
> +	} else
> +		trace_nfsd_clid_new(new);
> 	new->cl_minorversion = 0;
> 	gen_callback(new, setclid, rqstp);
> 	add_to_unconfirmed(new);
> @@ -4017,7 +4023,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 	return status;
> }
> 
> -
> __be32
> nfsd4_setclientid_confirm(struct svc_rqst *rqstp,
> 			struct nfsd4_compound_state *cstate,
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 523045c37749..6ddff13e3181 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -626,6 +626,43 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
> 	)
> );
> 
> +DECLARE_EVENT_CLASS(nfsd_clid_class,
> +	TP_PROTO(const struct nfs4_client *clp),
> +	TP_ARGS(clp),
> +	TP_STRUCT__entry(
> +		__field(u32, cl_boot)
> +		__field(u32, cl_id)
> +		__array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +		__field(unsigned long, flavor)
> +		__array(unsigned char, verifier, NFS4_VERIFIER_SIZE)
> +		__field(unsigned int, namelen)
> +		__dynamic_array(unsigned char, name, clp->cl_name.len)
> +	),
> +	TP_fast_assign(
> +		memcpy(__entry->addr, &clp->cl_addr,
> +			sizeof(struct sockaddr_in6));
> +		__entry->flavor = clp->cl_cred.cr_flavor;
> +		memcpy(__entry->verifier, (void *)&clp->cl_verifier,
> +		       NFS4_VERIFIER_SIZE);
> +		__entry->namelen = clp->cl_name.len;
> +		memcpy(__get_dynamic_array(name), clp->cl_name.data,
> +			clp->cl_name.len);
> +	),
> +	TP_printk("addr=%pISpc name='%.*s' verifier=0x%s flavor=%s client=%08x:%08x\n",
> +		__entry->addr, __entry->namelen, __get_str(name),
> +		__print_hex_str(__entry->verifier, NFS4_VERIFIER_SIZE),
> +		show_nfsd_authflavor(__entry->flavor),
> +		__entry->cl_boot, __entry->cl_id)
> +);
> +
> +#define DEFINE_CLID_EVENT(name) \
> +DEFINE_EVENT(nfsd_clid_class, nfsd_clid_##name, \
> +	TP_PROTO(const struct nfs4_client *clp), \
> +	TP_ARGS(clp))
> +
> +DEFINE_CLID_EVENT(new);
> +DEFINE_CLID_EVENT(existing);
> +
> /*
>  * from fs/nfsd/filecache.h
>  */
> 
> 

--
Chuck Lever




^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-11 15:59   ` Chuck Lever III
@ 2021-05-11 17:38     ` Bruce Fields
  2021-05-11 17:40       ` Chuck Lever III
  0 siblings, 1 reply; 35+ messages in thread
From: Bruce Fields @ 2021-05-11 17:38 UTC (permalink / raw)
  To: Chuck Lever III; +Cc: Linux NFS Mailing List, David Wysochanski

On Tue, May 11, 2021 at 03:59:00PM +0000, Chuck Lever III wrote:
> As Dave reported yesterday, this patch is unfinished and is probably
> junk. But any thoughts on how the tracepoints should be organized
> in this code would help.
> 
> So I was thinking we probably want a tracepoint to fire for each
> case that is handled in this code (and in nfsd4_exchangeid).
> However, this comment in nfsd4_setclientid:
> 
>    /* Cases below refer to rfc 3530 section 14.2.33: */
> 
> Is confusing.
> 
> - RFC 3530 is superceded by RFC 7530, and the section numbers have changed.
> 
> - The cases in this section in both RFCs aren't numbered, they are
> bullet points.

Honestly I think those particular comments should just go.  The code
doesn't even follow those bullet points very closely any more.

--b.

diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
index f47f72bc871f..2aa5d15b08ed 100644
--- a/fs/nfsd/nfs4state.c
+++ b/fs/nfsd/nfs4state.c
@@ -3954,11 +3954,9 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	new = create_client(clname, rqstp, &clverifier);
 	if (new == NULL)
 		return nfserr_jukebox;
-	/* Cases below refer to rfc 3530 section 14.2.33: */
 	spin_lock(&nn->client_lock);
 	conf = find_confirmed_client_by_name(&clname, nn);
 	if (conf && client_has_state(conf)) {
-		/* case 0: */
 		status = nfserr_clid_inuse;
 		if (clp_used_exchangeid(conf))
 			goto out;
@@ -3970,7 +3968,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
 	unconf = find_unconfirmed_client_by_name(&clname, nn);
 	if (unconf)
 		unhash_client_locked(unconf);
-	/* We need to handle only case 1: probable callback update */
 	if (conf && same_verf(&conf->cl_verifier, &clverifier)) {
 		copy_clid(new, conf);
 		gen_confirm(new, nn);

^ permalink raw reply related	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-11 17:38     ` Bruce Fields
@ 2021-05-11 17:40       ` Chuck Lever III
  2021-05-11 17:43         ` Bruce Fields
  0 siblings, 1 reply; 35+ messages in thread
From: Chuck Lever III @ 2021-05-11 17:40 UTC (permalink / raw)
  To: Bruce Fields; +Cc: Linux NFS Mailing List, David Wysochanski



> On May 11, 2021, at 1:38 PM, Bruce Fields <bfields@fieldses.org> wrote:
> 
> On Tue, May 11, 2021 at 03:59:00PM +0000, Chuck Lever III wrote:
>> As Dave reported yesterday, this patch is unfinished and is probably
>> junk. But any thoughts on how the tracepoints should be organized
>> in this code would help.
>> 
>> So I was thinking we probably want a tracepoint to fire for each
>> case that is handled in this code (and in nfsd4_exchangeid).
>> However, this comment in nfsd4_setclientid:
>> 
>>   /* Cases below refer to rfc 3530 section 14.2.33: */
>> 
>> Is confusing.
>> 
>> - RFC 3530 is superceded by RFC 7530, and the section numbers have changed.
>> 
>> - The cases in this section in both RFCs aren't numbered, they are
>> bullet points.
> 
> Honestly I think those particular comments should just go.  The code
> doesn't even follow those bullet points very closely any more.

OK, I'll squash this in, and include similar changes to
nfsd4_setclientid_confirm().


> --b.
> 
> diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> index f47f72bc871f..2aa5d15b08ed 100644
> --- a/fs/nfsd/nfs4state.c
> +++ b/fs/nfsd/nfs4state.c
> @@ -3954,11 +3954,9 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 	new = create_client(clname, rqstp, &clverifier);
> 	if (new == NULL)
> 		return nfserr_jukebox;
> -	/* Cases below refer to rfc 3530 section 14.2.33: */
> 	spin_lock(&nn->client_lock);
> 	conf = find_confirmed_client_by_name(&clname, nn);
> 	if (conf && client_has_state(conf)) {
> -		/* case 0: */
> 		status = nfserr_clid_inuse;
> 		if (clp_used_exchangeid(conf))
> 			goto out;
> @@ -3970,7 +3968,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> 	unconf = find_unconfirmed_client_by_name(&clname, nn);
> 	if (unconf)
> 		unhash_client_locked(unconf);
> -	/* We need to handle only case 1: probable callback update */
> 	if (conf && same_verf(&conf->cl_verifier, &clverifier)) {
> 		copy_clid(new, conf);
> 		gen_confirm(new, nn);

--
Chuck Lever




^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity
  2021-05-11 17:40       ` Chuck Lever III
@ 2021-05-11 17:43         ` Bruce Fields
  0 siblings, 0 replies; 35+ messages in thread
From: Bruce Fields @ 2021-05-11 17:43 UTC (permalink / raw)
  To: Chuck Lever III; +Cc: Linux NFS Mailing List, David Wysochanski

On Tue, May 11, 2021 at 05:40:20PM +0000, Chuck Lever III wrote:
> 
> 
> > On May 11, 2021, at 1:38 PM, Bruce Fields <bfields@fieldses.org> wrote:
> > 
> > On Tue, May 11, 2021 at 03:59:00PM +0000, Chuck Lever III wrote:
> >> As Dave reported yesterday, this patch is unfinished and is probably
> >> junk. But any thoughts on how the tracepoints should be organized
> >> in this code would help.
> >> 
> >> So I was thinking we probably want a tracepoint to fire for each
> >> case that is handled in this code (and in nfsd4_exchangeid).
> >> However, this comment in nfsd4_setclientid:
> >> 
> >>   /* Cases below refer to rfc 3530 section 14.2.33: */
> >> 
> >> Is confusing.
> >> 
> >> - RFC 3530 is superceded by RFC 7530, and the section numbers have changed.
> >> 
> >> - The cases in this section in both RFCs aren't numbered, they are
> >> bullet points.
> > 
> > Honestly I think those particular comments should just go.  The code
> > doesn't even follow those bullet points very closely any more.
> 
> OK, I'll squash this in, and include similar changes to
> nfsd4_setclientid_confirm().

The setclientid_confirm cases are a little more complicated and I think
the code there may map more closely to the RFC bullet points.

But I'm not particularly attached to them, feel free to use your
judgement for those....

--b.

> 
> 
> > --b.
> > 
> > diff --git a/fs/nfsd/nfs4state.c b/fs/nfsd/nfs4state.c
> > index f47f72bc871f..2aa5d15b08ed 100644
> > --- a/fs/nfsd/nfs4state.c
> > +++ b/fs/nfsd/nfs4state.c
> > @@ -3954,11 +3954,9 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> > 	new = create_client(clname, rqstp, &clverifier);
> > 	if (new == NULL)
> > 		return nfserr_jukebox;
> > -	/* Cases below refer to rfc 3530 section 14.2.33: */
> > 	spin_lock(&nn->client_lock);
> > 	conf = find_confirmed_client_by_name(&clname, nn);
> > 	if (conf && client_has_state(conf)) {
> > -		/* case 0: */
> > 		status = nfserr_clid_inuse;
> > 		if (clp_used_exchangeid(conf))
> > 			goto out;
> > @@ -3970,7 +3968,6 @@ nfsd4_setclientid(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> > 	unconf = find_unconfirmed_client_by_name(&clname, nn);
> > 	if (unconf)
> > 		unhash_client_locked(unconf);
> > -	/* We need to handle only case 1: probable callback update */
> > 	if (conf && same_verf(&conf->cl_verifier, &clverifier)) {
> > 		copy_clid(new, conf);
> > 		gen_confirm(new, nn);
> 
> --
> Chuck Lever
> 
> 

^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint
  2021-05-10 20:29     ` Chuck Lever III
@ 2021-05-11 17:44       ` Bruce Fields
  0 siblings, 0 replies; 35+ messages in thread
From: Bruce Fields @ 2021-05-11 17:44 UTC (permalink / raw)
  To: Chuck Lever III; +Cc: David Wysochanski, Linux NFS Mailing List

On Mon, May 10, 2021 at 08:29:32PM +0000, Chuck Lever III wrote:
> 
> 
> > On May 10, 2021, at 4:27 PM, J. Bruce Fields <bfields@fieldses.org> wrote:
> > 
> > On Mon, May 10, 2021 at 11:52:14AM -0400, Chuck Lever wrote:
> >> This path is not really an error path,
> > 
> > What's the non-error case for this path?
> 
> >From what I can tell, it appears to be the default exit for when
> there is a session and backchannel. Feel free to straighten me
> out, but it just seemed to always fire for NFSv4.1 mounts.

I'd be curious to know why.  I'll see if I can find some time to
experiment.

--b.

> > On a quick look it seems like that'd mean a 4.1 client doesn't have a
> > connection available for the backchannel, which sounds bad.
> > 
> > But I'm probably overlooking something....
> > 
> > --b.
> > 
> >> so the tracepoint I added
> >> there is just noise.
> >> 
> >> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> >> ---
> >> fs/nfsd/nfs4callback.c |    4 +---
> >> 1 file changed, 1 insertion(+), 3 deletions(-)
> >> 
> >> diff --git a/fs/nfsd/nfs4callback.c b/fs/nfsd/nfs4callback.c
> >> index ab1836381e22..15ba16c54793 100644
> >> --- a/fs/nfsd/nfs4callback.c
> >> +++ b/fs/nfsd/nfs4callback.c
> >> @@ -915,10 +915,8 @@ static int setup_callback_client(struct nfs4_client *clp, struct nfs4_cb_conn *c
> >> 		args.authflavor = clp->cl_cred.cr_flavor;
> >> 		clp->cl_cb_ident = conn->cb_ident;
> >> 	} else {
> >> -		if (!conn->cb_xprt) {
> >> -			trace_nfsd_cb_setup_err(clp, -EINVAL);
> >> +		if (!conn->cb_xprt)
> >> 			return -EINVAL;
> >> -		}
> >> 		clp->cl_cb_conn.cb_xprt = conn->cb_xprt;
> >> 		clp->cl_cb_session = ses;
> >> 		args.bc_xprt = conn->cb_xprt;
> >> 
> 
> --
> Chuck Lever
> 
> 

^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint
  2021-05-10 15:52 ` [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint Chuck Lever
@ 2021-05-14 18:22   ` Olga Kornievskaia
  2021-05-14 19:11     ` Chuck Lever III
  0 siblings, 1 reply; 35+ messages in thread
From: Olga Kornievskaia @ 2021-05-14 18:22 UTC (permalink / raw)
  To: Chuck Lever; +Cc: Dave Wysochanski, J. Bruce Fields, linux-nfs

Hi Chuck,

On Mon, May 10, 2021 at 12:05 PM Chuck Lever <chuck.lever@oracle.com> wrote:
>
> Record the arguments of CB_OFFLOAD callbacks so we can better
> observe asynchronous copy-offload behavior. For example:
>
>             nfsd-995   [008]  7721.934222: nfsd_cb_offload:      addr=192.168.2.51:0 client 6092a47c:35a43fc1 fh_hash=0x8739113a

I like the idea but can we include copy->nfserr if there is one and/or
if not then size copied?

> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> Cc: Olga Kornievskaia <kolga@netapp.com>
> Cc: Dai Ngo <Dai.Ngo@oracle.com>
> ---
>  fs/nfsd/nfs4proc.c |    1 +
>  fs/nfsd/trace.h    |   30 ++++++++++++++++++++++++++++++
>  2 files changed, 31 insertions(+)
>
> diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
> index daf43b980d4b..7a13f6c848c6 100644
> --- a/fs/nfsd/nfs4proc.c
> +++ b/fs/nfsd/nfs4proc.c
> @@ -1497,6 +1497,7 @@ static int nfsd4_do_async_copy(void *data)
>         memcpy(&cb_copy->fh, &copy->fh, sizeof(copy->fh));
>         nfsd4_init_cb(&cb_copy->cp_cb, cb_copy->cp_clp,
>                         &nfsd4_cb_offload_ops, NFSPROC4_CLNT_CB_OFFLOAD);
> +       trace_nfsd_cb_offload(copy->cp_clp, &copy->cp_res.cb_stateid, &copy->fh);
>         nfsd4_run_cb(&cb_copy->cp_cb);
>  out:
>         if (!copy->cp_intra)
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index 1dce41b3bd4d..15cacbdac411 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -1004,6 +1004,36 @@ TRACE_EVENT(nfsd_cb_notify_lock,
>                 __entry->fh_hash)
>  );
>
> +TRACE_EVENT(nfsd_cb_offload,
> +       TP_PROTO(
> +               const struct nfs4_client *clp,
> +               const stateid_t *stp,
> +               const struct knfsd_fh *fh
> +       ),
> +       TP_ARGS(clp, stp, fh),
> +       TP_STRUCT__entry(
> +               __field(u32, cl_boot)
> +               __field(u32, cl_id)
> +               __field(u32, si_id)
> +               __field(u32, si_generation)
> +               __field(u32, fh_hash)
> +               __array(unsigned char, addr, sizeof(struct sockaddr_in6))
> +       ),
> +       TP_fast_assign(
> +               __entry->cl_boot = stp->si_opaque.so_clid.cl_boot;
> +               __entry->cl_id = stp->si_opaque.so_clid.cl_id;
> +               __entry->si_id = stp->si_opaque.so_id;
> +               __entry->si_generation = stp->si_generation;
> +               __entry->fh_hash = knfsd_fh_hash(fh);
> +               memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
> +                       sizeof(struct sockaddr_in6));
> +       ),
> +       TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x fh_hash=0x%08x",
> +               __entry->addr, __entry->cl_boot, __entry->cl_id,
> +               __entry->si_id, __entry->si_generation,
> +               __entry->fh_hash)
> +);
> +
>  #endif /* _NFSD_TRACE_H */
>
>  #undef TRACE_INCLUDE_PATH
>
>

^ permalink raw reply	[flat|nested] 35+ messages in thread

* Re: [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint
  2021-05-14 18:22   ` Olga Kornievskaia
@ 2021-05-14 19:11     ` Chuck Lever III
  0 siblings, 0 replies; 35+ messages in thread
From: Chuck Lever III @ 2021-05-14 19:11 UTC (permalink / raw)
  To: Olga Kornievskaia; +Cc: Dave Wysochanski, Bruce Fields, Linux NFS Mailing List



> On May 14, 2021, at 2:22 PM, Olga Kornievskaia <aglo@umich.edu> wrote:
> 
> Hi Chuck,
> 
> On Mon, May 10, 2021 at 12:05 PM Chuck Lever <chuck.lever@oracle.com> wrote:
>> 
>> Record the arguments of CB_OFFLOAD callbacks so we can better
>> observe asynchronous copy-offload behavior. For example:
>> 
>>            nfsd-995   [008]  7721.934222: nfsd_cb_offload:      addr=192.168.2.51:0 client 6092a47c:35a43fc1 fh_hash=0x8739113a
> 
> I like the idea but can we include copy->nfserr if there is one and/or
> if not then size copied?

Yes. How about recording both copy->nfserr _and_ copy->cp_count ?

Unfortunately struct nfsd4_copy is defined in a header that
cannot be included everywhere, so I have to pass all of these
in as separate arguments. Should be OK, this isn't a
performance-critical path.


>> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
>> Cc: Olga Kornievskaia <kolga@netapp.com>
>> Cc: Dai Ngo <Dai.Ngo@oracle.com>
>> ---
>> fs/nfsd/nfs4proc.c |    1 +
>> fs/nfsd/trace.h    |   30 ++++++++++++++++++++++++++++++
>> 2 files changed, 31 insertions(+)
>> 
>> diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
>> index daf43b980d4b..7a13f6c848c6 100644
>> --- a/fs/nfsd/nfs4proc.c
>> +++ b/fs/nfsd/nfs4proc.c
>> @@ -1497,6 +1497,7 @@ static int nfsd4_do_async_copy(void *data)
>>        memcpy(&cb_copy->fh, &copy->fh, sizeof(copy->fh));
>>        nfsd4_init_cb(&cb_copy->cp_cb, cb_copy->cp_clp,
>>                        &nfsd4_cb_offload_ops, NFSPROC4_CLNT_CB_OFFLOAD);
>> +       trace_nfsd_cb_offload(copy->cp_clp, &copy->cp_res.cb_stateid, &copy->fh);
>>        nfsd4_run_cb(&cb_copy->cp_cb);
>> out:
>>        if (!copy->cp_intra)
>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>> index 1dce41b3bd4d..15cacbdac411 100644
>> --- a/fs/nfsd/trace.h
>> +++ b/fs/nfsd/trace.h
>> @@ -1004,6 +1004,36 @@ TRACE_EVENT(nfsd_cb_notify_lock,
>>                __entry->fh_hash)
>> );
>> 
>> +TRACE_EVENT(nfsd_cb_offload,
>> +       TP_PROTO(
>> +               const struct nfs4_client *clp,
>> +               const stateid_t *stp,
>> +               const struct knfsd_fh *fh
>> +       ),
>> +       TP_ARGS(clp, stp, fh),
>> +       TP_STRUCT__entry(
>> +               __field(u32, cl_boot)
>> +               __field(u32, cl_id)
>> +               __field(u32, si_id)
>> +               __field(u32, si_generation)
>> +               __field(u32, fh_hash)
>> +               __array(unsigned char, addr, sizeof(struct sockaddr_in6))
>> +       ),
>> +       TP_fast_assign(
>> +               __entry->cl_boot = stp->si_opaque.so_clid.cl_boot;
>> +               __entry->cl_id = stp->si_opaque.so_clid.cl_id;
>> +               __entry->si_id = stp->si_opaque.so_id;
>> +               __entry->si_generation = stp->si_generation;
>> +               __entry->fh_hash = knfsd_fh_hash(fh);
>> +               memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
>> +                       sizeof(struct sockaddr_in6));
>> +       ),
>> +       TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x fh_hash=0x%08x",
>> +               __entry->addr, __entry->cl_boot, __entry->cl_id,
>> +               __entry->si_id, __entry->si_generation,
>> +               __entry->fh_hash)
>> +);
>> +
>> #endif /* _NFSD_TRACE_H */
>> 
>> #undef TRACE_INCLUDE_PATH
>> 
>> 

--
Chuck Lever




^ permalink raw reply	[flat|nested] 35+ messages in thread

end of thread, other threads:[~2021-05-14 19:11 UTC | newest]

Thread overview: 35+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-05-10 15:51 [PATCH RFC 00/21] NFSD callback and lease management observability Chuck Lever
2021-05-10 15:51 ` [PATCH RFC 01/21] NFSD: Constify @fh argument of knfsd_fh_hash() Chuck Lever
2021-05-10 15:51 ` [PATCH RFC 02/21] NFSD: Capture every CB state transition Chuck Lever
2021-05-10 15:51 ` [PATCH RFC 03/21] NFSD: Drop TRACE_DEFINE_ENUM for NFSD4_CB_<state> macros Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 04/21] NFSD: Add cb_lost tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 05/21] NFSD: Adjust cb_shutdown tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 06/21] NFSD: Remove spurious cb_setup_err tracepoint Chuck Lever
2021-05-10 20:27   ` J. Bruce Fields
2021-05-10 20:29     ` Chuck Lever III
2021-05-11 17:44       ` Bruce Fields
2021-05-10 15:52 ` [PATCH RFC 07/21] NFSD: Enhance the nfsd_cb_setup tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 08/21] NFSD: Add an nfsd_cb_lm_notify tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 09/21] NFSD: Add an nfsd_cb_offload tracepoint Chuck Lever
2021-05-14 18:22   ` Olga Kornievskaia
2021-05-14 19:11     ` Chuck Lever III
2021-05-10 15:52 ` [PATCH RFC 10/21] NFSD: Replace the nfsd_deleg_break tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 11/21] NFSD: Add an nfsd_cb_probe tracepoint Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 12/21] NFSD: Remove the nfsd_cb_work and nfsd_cb_done tracepoints Chuck Lever
2021-05-10 15:52 ` [PATCH RFC 13/21] NFSD: Update nfsd_cb_args tracepoint Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 14/21] NFSD: Add nfsd_clid_cred_mismatch tracepoint Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 15/21] NFSD: Add nfsd_clid_verf_mismatch tracepoint Chuck Lever
2021-05-11 15:49   ` J. Bruce Fields
2021-05-10 15:53 ` [PATCH RFC 16/21] NFSD: Remove nfsd_clid_inuse_err Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 17/21] NFSD: Add nfsd_clid_confirmed tracepoint Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 18/21] NFSD: Add nfsd_clid_destroyed tracepoint Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 19/21] NFSD: Add a couple more nfsd_clid_expired call sites Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 20/21] NFSD: Rename nfsd_clid_class Chuck Lever
2021-05-10 15:53 ` [PATCH RFC 21/21] NFSD: Add tracepoints to observe clientID activity Chuck Lever
2021-05-10 19:56   ` David Wysochanski
2021-05-10 20:00     ` Chuck Lever III
2021-05-11 15:59   ` Chuck Lever III
2021-05-11 17:38     ` Bruce Fields
2021-05-11 17:40       ` Chuck Lever III
2021-05-11 17:43         ` Bruce Fields
2021-05-10 17:24 ` [PATCH RFC 00/21] NFSD callback and lease management observability David Wysochanski

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).