diff mbox series

[v2,03/15] SUNRPC: Replace dprintk() call site in xs_data_ready

Message ID 165452704802.1496.15626296214203899256.stgit@oracle-102.nfsv4.dev (mailing list archive)
State New, archived
Headers show
Series RPC-with-TLS client side | expand

Commit Message

Chuck Lever June 6, 2022, 2:50 p.m. UTC 
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
---
 include/trace/events/sunrpc.h |   20 ++++++++++++++++++++
 net/sunrpc/xprtsock.c         |    6 ++++--
 2 files changed, 24 insertions(+), 2 deletions(-)

Comments

Jeff Layton July 6, 2022, 5:19 p.m. UTC | #1 
On Mon, 2022-06-06 at 10:50 -0400, Chuck Lever wrote:
> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> ---
>  include/trace/events/sunrpc.h |   20 ++++++++++++++++++++
>  net/sunrpc/xprtsock.c         |    6 ++++--
>  2 files changed, 24 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
> index 3995c58a1c51..a66aa1f59ed8 100644
> --- a/include/trace/events/sunrpc.h
> +++ b/include/trace/events/sunrpc.h
> @@ -1266,6 +1266,26 @@ TRACE_EVENT(xprt_reserve,
>  	)
>  );
>  
> +TRACE_EVENT(xs_data_ready,
> +	TP_PROTO(
> +		const struct rpc_xprt *xprt
> +	),
> +
> +	TP_ARGS(xprt),
> +
> +	TP_STRUCT__entry(
> +		__string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
> +		__string(port, xprt->address_strings[RPC_DISPLAY_PORT])
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
> +		__assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
> +	),
> 
> 

This tracepoint is likely to fire rather often when it's enabled. Would
it be more efficient to store the addr and port as binary data instead?

> +
> +	TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port))
> +);
> +
>  TRACE_EVENT(xs_stream_read_data,
>  	TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
>  
> diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
> index 650102a9c86a..73fab802996d 100644
> --- a/net/sunrpc/xprtsock.c
> +++ b/net/sunrpc/xprtsock.c
> @@ -1378,7 +1378,7 @@ static void xs_udp_data_receive_workfn(struct work_struct *work)
>  }
>  
>  /**
> - * xs_data_ready - "data ready" callback for UDP sockets
> + * xs_data_ready - "data ready" callback for sockets
>   * @sk: socket with data to read
>   *
>   */
> @@ -1386,11 +1386,13 @@ static void xs_data_ready(struct sock *sk)
>  {
>  	struct rpc_xprt *xprt;
>  
> -	dprintk("RPC:       xs_data_ready...\n");
>  	xprt = xprt_from_sock(sk);
>  	if (xprt != NULL) {
>  		struct sock_xprt *transport = container_of(xprt,
>  				struct sock_xprt, xprt);
> +
> +		trace_xs_data_ready(xprt);
> +
>  		transport->old_data_ready(sk);
>  		/* Any data means we had a useful conversation, so
>  		 * then we don't need to delay the next reconnect
> 
> 

That dprintk was pretty worthless anyway. So the change seems fine to
me.
Chuck Lever July 6, 2022, 6:10 p.m. UTC | #2 
> On Jul 6, 2022, at 1:19 PM, Jeff Layton <jlayton@kernel.org> wrote:
> 
> On Mon, 2022-06-06 at 10:50 -0400, Chuck Lever wrote:
>> Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
>> ---
>> include/trace/events/sunrpc.h | 20 ++++++++++++++++++++
>> net/sunrpc/xprtsock.c | 6 ++++--
>> 2 files changed, 24 insertions(+), 2 deletions(-)
>> 
>> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
>> index 3995c58a1c51..a66aa1f59ed8 100644
>> --- a/include/trace/events/sunrpc.h
>> +++ b/include/trace/events/sunrpc.h
>> @@ -1266,6 +1266,26 @@ TRACE_EVENT(xprt_reserve,
>> 	)
>> );
>> 
>> +TRACE_EVENT(xs_data_ready,
>> +	TP_PROTO(
>> +		const struct rpc_xprt *xprt
>> +	),
>> +
>> +	TP_ARGS(xprt),
>> +
>> +	TP_STRUCT__entry(
>> +		__string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
>> +		__string(port, xprt->address_strings[RPC_DISPLAY_PORT])
>> +	),
>> +
>> +	TP_fast_assign(
>> +		__assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
>> +		__assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
>> +	),
>> 
>> 
> 
> This tracepoint is likely to fire rather often when it's enabled. Would
> it be more efficient to store the addr and port as binary data instead?

Yes, and it can use get_sockaddr() and friends for that. But those
patches were in flight when I wrote this one.


>> +
>> +	TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port))
>> +);
>> +
>> TRACE_EVENT(xs_stream_read_data,
>> 	TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
>> 
>> diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
>> index 650102a9c86a..73fab802996d 100644
>> --- a/net/sunrpc/xprtsock.c
>> +++ b/net/sunrpc/xprtsock.c
>> @@ -1378,7 +1378,7 @@ static void xs_udp_data_receive_workfn(struct work_struct *work)
>> }
>> 
>> /**
>> - * xs_data_ready - "data ready" callback for UDP sockets
>> + * xs_data_ready - "data ready" callback for sockets
>> * @sk: socket with data to read
>> *
>> */
>> @@ -1386,11 +1386,13 @@ static void xs_data_ready(struct sock *sk)
>> {
>> 	struct rpc_xprt *xprt;
>> 
>> -	dprintk("RPC: xs_data_ready...\n");
>> 	xprt = xprt_from_sock(sk);
>> 	if (xprt != NULL) {
>> 		struct sock_xprt *transport = container_of(xprt,
>> 				struct sock_xprt, xprt);
>> +
>> +		trace_xs_data_ready(xprt);
>> +
>> 		transport->old_data_ready(sk);
>> 		/* Any data means we had a useful conversation, so
>> 		 * then we don't need to delay the next reconnect
>> 
>> 
> 
> That dprintk was pretty worthless anyway. So the change seems fine to
> me.
> 
> 
> -- 
> Jeff Layton <jlayton@kernel.org>

--
Chuck Lever
diff mbox series

Patch

diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 3995c58a1c51..a66aa1f59ed8 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -1266,6 +1266,26 @@  TRACE_EVENT(xprt_reserve,
 	)
 );
 
+TRACE_EVENT(xs_data_ready,
+	TP_PROTO(
+		const struct rpc_xprt *xprt
+	),
+
+	TP_ARGS(xprt),
+
+	TP_STRUCT__entry(
+		__string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
+		__string(port, xprt->address_strings[RPC_DISPLAY_PORT])
+	),
+
+	TP_fast_assign(
+		__assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
+		__assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
+	),
+
+	TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port))
+);
+
 TRACE_EVENT(xs_stream_read_data,
 	TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
 
diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 650102a9c86a..73fab802996d 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -1378,7 +1378,7 @@  static void xs_udp_data_receive_workfn(struct work_struct *work)
 }
 
 /**
- * xs_data_ready - "data ready" callback for UDP sockets
+ * xs_data_ready - "data ready" callback for sockets
  * @sk: socket with data to read
  *
  */
@@ -1386,11 +1386,13 @@  static void xs_data_ready(struct sock *sk)
 {
 	struct rpc_xprt *xprt;
 
-	dprintk("RPC:       xs_data_ready...\n");
 	xprt = xprt_from_sock(sk);
 	if (xprt != NULL) {
 		struct sock_xprt *transport = container_of(xprt,
 				struct sock_xprt, xprt);
+
+		trace_xs_data_ready(xprt);
+
 		transport->old_data_ready(sk);
 		/* Any data means we had a useful conversation, so
 		 * then we don't need to delay the next reconnect