Re: [PATCH 07/15] sunrpc: Save remote presentation address in svc_xprt for trace events

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




> On Mar 14, 2018, at 4:35 PM, J. Bruce Fields <bfields@xxxxxxxxxxxx> wrote:
> 
> On Tue, Mar 13, 2018 at 11:44:16AM -0400, Chuck Lever wrote:
>> TP_printk defines a format string that is passed to user space for
>> converting raw trace event records to something human-readable.
>> 
>> My user space's printf (Oracle Linux 7), however, does not have a
>> %pI format specifier. The result is that what is supposed to be an
>> IP address in the output of "trace-cmd report" is just a string that
>> says the field couldn't be displayed.
>> 
>> To fix this, adopt the same approach as the client: maintain a pre-
>> formated presentation address for occasions when %pI is not
>> available.
>> 
>> The location of the trace_svc_send trace point is adjusted so that
>> rqst->rq_xprt is not NULL when the trace event is recorded.
> 
> So presumably the problem could also be fixed in userspace; why is it
> better to do it here?

"User space" means the C library's printf() implementation. You'd have
to address this by adding %pI to every possible C library used by Linux
distributions.

Also, as mentioned above, we've already used this approach successfully
in several other similar places.


> --b.
> 
>> 
>> Signed-off-by: Chuck Lever <chuck.lever@xxxxxxxxxx>
>> ---
>> include/linux/sunrpc/svc_xprt.h          |    4 +
>> include/trace/events/sunrpc.h            |   89 +++++++++++-------------------
>> net/sunrpc/svc_xprt.c                    |    3 +
>> net/sunrpc/svcsock.c                     |    1 
>> net/sunrpc/xprtrdma/svc_rdma_transport.c |    4 +
>> 5 files changed, 43 insertions(+), 58 deletions(-)
>> 
>> diff --git a/include/linux/sunrpc/svc_xprt.h b/include/linux/sunrpc/svc_xprt.h
>> index 19475ac..c3d7206 100644
>> --- a/include/linux/sunrpc/svc_xprt.h
>> +++ b/include/linux/sunrpc/svc_xprt.h
>> @@ -83,6 +83,7 @@ struct svc_xprt {
>> 	size_t			xpt_locallen;	/* length of address */
>> 	struct sockaddr_storage	xpt_remote;	/* remote peer's address */
>> 	size_t			xpt_remotelen;	/* length of address */
>> +	char			xpt_remotebuf[INET6_ADDRSTRLEN + 10];
>> 	struct rpc_wait_queue	xpt_bc_pending;	/* backchannel wait queue */
>> 	struct list_head	xpt_users;	/* callbacks on free */
>> 
>> @@ -152,7 +153,10 @@ static inline void svc_xprt_set_remote(struct svc_xprt *xprt,
>> {
>> 	memcpy(&xprt->xpt_remote, sa, salen);
>> 	xprt->xpt_remotelen = salen;
>> +	snprintf(xprt->xpt_remotebuf, sizeof(xprt->xpt_remotebuf) - 1,
>> +		 "%pISpc", sa);
>> }
>> +
>> static inline unsigned short svc_addr_port(const struct sockaddr *sa)
>> {
>> 	const struct sockaddr_in *sin = (const struct sockaddr_in *)sa;
>> diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
>> index 5849bfb..1ec8c4c 100644
>> --- a/include/trace/events/sunrpc.h
>> +++ b/include/trace/events/sunrpc.h
>> @@ -493,20 +493,18 @@
>> 		__field(u32, xid)
>> 		__field(int, len)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, rqst->rq_addrlen)
>> +		__string(addr, rqst->rq_xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xid = be32_to_cpu(rqst->rq_xid);
>> 		__entry->len = len;
>> 		__entry->flags = rqst->rq_flags;
>> -		memcpy(__get_dynamic_array(addr),
>> -			&rqst->rq_addr, rqst->rq_addrlen);
>> +		__assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("addr=%pIScp xid=0x%08x len=%d flags=%s",
>> -			(struct sockaddr *)__get_dynamic_array(addr),
>> -			__entry->xid, __entry->len,
>> +	TP_printk("addr=%s xid=0x%08x len=%d flags=%s",
>> +			__get_str(addr), __entry->xid, __entry->len,
>> 			show_rqstp_flags(__entry->flags))
>> );
>> 
>> @@ -519,20 +517,18 @@
>> 	TP_STRUCT__entry(
>> 		__field(u32, xid)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, rqst->rq_addrlen)
>> +		__string(addr, rqst->rq_xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xid = be32_to_cpu(rqst->rq_xid);
>> 		__entry->flags = rqst->rq_flags;
>> -		memcpy(__get_dynamic_array(addr),
>> -			&rqst->rq_addr, rqst->rq_addrlen);
>> +		__assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("addr=%pIScp rq_xid=0x%08x flags=%s",
>> -		(struct sockaddr *)__get_dynamic_array(addr),
>> -		__entry->xid,
>> -		show_rqstp_flags(__entry->flags))
>> +	TP_printk("addr=%s xid=0x%08x flags=%s",
>> +			__get_str(addr), __entry->xid,
>> +			show_rqstp_flags(__entry->flags))
>> );
>> 
>> DEFINE_EVENT(svc_rqst_event, svc_defer,
>> @@ -553,21 +549,19 @@
>> 		__field(u32, xid)
>> 		__field(int, status)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, rqst->rq_addrlen)
>> +		__string(addr, rqst->rq_xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xid = be32_to_cpu(rqst->rq_xid);
>> 		__entry->status = status;
>> 		__entry->flags = rqst->rq_flags;
>> -		memcpy(__get_dynamic_array(addr),
>> -			&rqst->rq_addr, rqst->rq_addrlen);
>> +		__assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("addr=%pIScp rq_xid=0x%08x status=%d flags=%s",
>> -		(struct sockaddr *)__get_dynamic_array(addr),
>> -		__entry->xid,
>> -		__entry->status, show_rqstp_flags(__entry->flags))
>> +	TP_printk("addr=%s xid=0x%08x status=%d flags=%s",
>> +		  __get_str(addr), __entry->xid,
>> +		  __entry->status, show_rqstp_flags(__entry->flags))
>> );
>> 
>> DEFINE_EVENT(svc_rqst_status, svc_process,
>> @@ -604,26 +598,19 @@
>> 		__field(struct svc_xprt *, xprt)
>> 		__field(int, pid)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, xprt != NULL ?
>> -			xprt->xpt_remotelen : 0)
>> +		__string(addr, xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xprt = xprt;
>> 		__entry->pid = rqst? rqst->rq_task->pid : 0;
>> -		if (xprt) {
>> -			memcpy(__get_dynamic_array(addr),
>> -				&xprt->xpt_remote,
>> -				xprt->xpt_remotelen);
>> -			__entry->flags = xprt->xpt_flags;
>> -		} else
>> -			__entry->flags = 0;
>> +		__entry->flags = xprt->xpt_flags;
>> +		__assign_str(addr, xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("xprt=0x%p addr=%pIScp pid=%d flags=%s", __entry->xprt,
>> -		__get_dynamic_array_len(addr) != 0 ?
>> -			(struct sockaddr *)__get_dynamic_array(addr) : NULL,
>> -		__entry->pid, show_svc_xprt_flags(__entry->flags))
>> +	TP_printk("xprt=%p addr=%s pid=%d flags=%s",
>> +			__entry->xprt, __get_str(addr),
>> +			__entry->pid, show_svc_xprt_flags(__entry->flags))
>> );
>> 
>> DECLARE_EVENT_CLASS(svc_xprt_event,
>> @@ -634,19 +621,18 @@
>> 	TP_STRUCT__entry(
>> 		__field(struct svc_xprt *, xprt)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, xprt->xpt_remotelen)
>> +		__string(addr, xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xprt = xprt;
>> 		__entry->flags = xprt->xpt_flags;
>> -		memcpy(__get_dynamic_array(addr),
>> -		       &xprt->xpt_remote, xprt->xpt_remotelen);
>> +		__assign_str(addr, xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("xprt=0x%p addr=%pIScp flags=%s", __entry->xprt,
>> -		(struct sockaddr *)__get_dynamic_array(addr),
>> -		show_svc_xprt_flags(__entry->flags))
>> +	TP_printk("xprt=%p addr=%s flags=%s",
>> +			__entry->xprt, __get_str(addr),
>> +			show_svc_xprt_flags(__entry->flags))
>> );
>> 
>> DEFINE_EVENT(svc_xprt_event, svc_xprt_dequeue,
>> @@ -682,25 +668,18 @@
>> 		__field(struct svc_xprt *, xprt)
>> 		__field(int, len)
>> 		__field(unsigned long, flags)
>> -		__dynamic_array(unsigned char, addr, xprt != NULL ?
>> -			xprt->xpt_remotelen : 0)
>> +		__string(addr, xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xprt = xprt;
>> 		__entry->len = len;
>> -		if (xprt) {
>> -			memcpy(__get_dynamic_array(addr),
>> -					&xprt->xpt_remote,
>> -					xprt->xpt_remotelen);
>> -			__entry->flags = xprt->xpt_flags;
>> -		} else
>> -			__entry->flags = 0;
>> +		__entry->flags = xprt->xpt_flags;
>> +		__assign_str(addr, xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("xprt=0x%p addr=%pIScp len=%d flags=%s", __entry->xprt,
>> -		__get_dynamic_array_len(addr) != 0 ?
>> -			(struct sockaddr *)__get_dynamic_array(addr) : NULL,
>> +	TP_printk("xprt=%p addr=%s len=%d flags=%s",
>> +		__entry->xprt, __get_str(addr),
>> 		__entry->len, show_svc_xprt_flags(__entry->flags))
>> );
>> 
>> @@ -712,18 +691,16 @@
>> 
>> 	TP_STRUCT__entry(
>> 		__field(u32, xid)
>> -		__dynamic_array(unsigned char, addr, dr->addrlen)
>> +		__string(addr, dr->xprt->xpt_remotebuf)
>> 	),
>> 
>> 	TP_fast_assign(
>> 		__entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
>> 						       (dr->xprt_hlen>>2)));
>> -		memcpy(__get_dynamic_array(addr), &dr->addr, dr->addrlen);
>> +		__assign_str(addr, dr->xprt->xpt_remotebuf);
>> 	),
>> 
>> -	TP_printk("addr=%pIScp xid=0x%08x",
>> -		(struct sockaddr *)__get_dynamic_array(addr),
>> -		__entry->xid)
>> +	TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
>> );
>> 
>> DEFINE_EVENT(svc_deferred_event, svc_drop_deferred,
>> diff --git a/net/sunrpc/svc_xprt.c b/net/sunrpc/svc_xprt.c
>> index 47384d0..f745754 100644
>> --- a/net/sunrpc/svc_xprt.c
>> +++ b/net/sunrpc/svc_xprt.c
>> @@ -173,6 +173,7 @@ void svc_xprt_init(struct net *net, struct svc_xprt_class *xcl,
>> 	set_bit(XPT_BUSY, &xprt->xpt_flags);
>> 	rpc_init_wait_queue(&xprt->xpt_bc_pending, "xpt_bc_pending");
>> 	xprt->xpt_net = get_net(net);
>> +	strcpy(xprt->xpt_remotebuf, "uninitialized");
>> }
>> EXPORT_SYMBOL_GPL(svc_xprt_init);
>> 
>> @@ -894,12 +895,12 @@ int svc_send(struct svc_rqst *rqstp)
>> 		len = xprt->xpt_ops->xpo_sendto(rqstp);
>> 	mutex_unlock(&xprt->xpt_mutex);
>> 	rpc_wake_up(&xprt->xpt_bc_pending);
>> +	trace_svc_send(rqstp, len);
>> 	svc_xprt_release(rqstp);
>> 
>> 	if (len == -ECONNREFUSED || len == -ENOTCONN || len == -EAGAIN)
>> 		len = 0;
>> out:
>> -	trace_svc_send(rqstp, len);
>> 	return len;
>> }
>> 
>> diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c
>> index 9b67035..4ca1d92 100644
>> --- a/net/sunrpc/svcsock.c
>> +++ b/net/sunrpc/svcsock.c
>> @@ -1310,6 +1310,7 @@ static void svc_tcp_init(struct svc_sock *svsk, struct svc_serv *serv)
>> 	set_bit(XPT_CONG_CTRL, &svsk->sk_xprt.xpt_flags);
>> 	if (sk->sk_state == TCP_LISTEN) {
>> 		dprintk("setting up TCP socket for listening\n");
>> +		strcpy(svsk->sk_xprt.xpt_remotebuf, "listener");
>> 		set_bit(XPT_LISTENER, &svsk->sk_xprt.xpt_flags);
>> 		sk->sk_data_ready = svc_tcp_listen_data_ready;
>> 		set_bit(XPT_CONN, &svsk->sk_xprt.xpt_flags);
>> diff --git a/net/sunrpc/xprtrdma/svc_rdma_transport.c b/net/sunrpc/xprtrdma/svc_rdma_transport.c
>> index b083ac8..ca211dc 100644
>> --- a/net/sunrpc/xprtrdma/svc_rdma_transport.c
>> +++ b/net/sunrpc/xprtrdma/svc_rdma_transport.c
>> @@ -401,8 +401,10 @@ static struct svcxprt_rdma *rdma_create_xprt(struct svc_serv *serv,
>> 	 */
>> 	set_bit(XPT_CONG_CTRL, &cma_xprt->sc_xprt.xpt_flags);
>> 
>> -	if (listener)
>> +	if (listener) {
>> +		strcpy(cma_xprt->sc_xprt.xpt_remotebuf, "listener");
>> 		set_bit(XPT_LISTENER, &cma_xprt->sc_xprt.xpt_flags);
>> +	}
>> 
>> 	return cma_xprt;
>> }

--
Chuck Lever



--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html




[Index of Archives]     [Linux Filesystem Development]     [Linux USB Development]     [Linux Media Development]     [Video for Linux]     [Linux NILFS]     [Linux Audio Users]     [Yosemite Info]     [Linux SCSI]

  Powered by Linux