Received-SPF: pass (google.com: best guess record for domain of linux-nfs-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Message-ID: <3a2a3b9de724757b3b580536f2ea1947752faeb1.camel@gmail.com>
Subject: Re: [PATCH v1 10/11] xprtrdma: Extract sockaddr from struct
 rdma_cm_id
From:   Anna Schumaker <schumaker.anna@gmail.com>
To:     Chuck Lever <chuck.lever@oracle.com>
Cc:     linux-rdma@vger.kernel.org,
        Linux NFS Mailing List <linux-nfs@vger.kernel.org>
Date:   Mon, 24 Feb 2020 11:23:16 -0500
In-Reply-To: <3099D78C-CBA7-43ED-86A1-4C757C7B9F93@oracle.com>
References: <20200221214906.2072.32572.stgit@manet.1015granger.net>
         <20200221220100.2072.45609.stgit@manet.1015granger.net>
         <57e16538f7a711d7671056d19abc38a09afc451d.camel@gmail.com>
         <3099D78C-CBA7-43ED-86A1-4C757C7B9F93@oracle.com>
Content-Type: text/plain; charset="UTF-8"
User-Agent: Evolution 3.34.4 
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Sender: linux-nfs-owner@vger.kernel.org
Precedence: bulk

On Mon, 2020-02-24 at 08:18 -0800, Chuck Lever wrote:
> > On Feb 24, 2020, at 8:15 AM, Anna Schumaker <schumaker.anna@gmail.com>
> > wrote:
> > 
> > Hi Chuck,
> > 
> > On Fri, 2020-02-21 at 17:01 -0500, Chuck Lever wrote:
> > > rpcrdma_cm_event_handler() is always passed an @id pointer that is
> > > valid. However, in a subsequent patch, we won't be able to extract
> > > an r_xprt in every case. So instead of using the r_xprt's
> > > presentation address strings, extract them from struct rdma_cm_id.
> > > 
> > > Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
> > > ---
> > > include/trace/events/rpcrdma.h |   78 +++++++++++++++++++++++++++---------
> > > -
> > > ---
> > > net/sunrpc/xprtrdma/verbs.c    |   33 +++++++----------
> > > 2 files changed, 67 insertions(+), 44 deletions(-)
> > > 
> > > diff --git a/include/trace/events/rpcrdma.h
> > > b/include/trace/events/rpcrdma.h
> > > index bebc45f7c570..a6d3a2122e9b 100644
> > > --- a/include/trace/events/rpcrdma.h
> > > +++ b/include/trace/events/rpcrdma.h
> > > @@ -373,47 +373,74 @@
> > > 
> > > TRACE_EVENT(xprtrdma_inline_thresh,
> > > 	TP_PROTO(
> > > -		const struct rpcrdma_xprt *r_xprt
> > > +		const struct rpcrdma_ep *ep
> > > 	),
> > > 
> > > -	TP_ARGS(r_xprt),
> > > +	TP_ARGS(ep),
> > > 
> > > 	TP_STRUCT__entry(
> > > -		__field(const void *, r_xprt)
> > > 		__field(unsigned int, inline_send)
> > > 		__field(unsigned int, inline_recv)
> > > 		__field(unsigned int, max_send)
> > > 		__field(unsigned int, max_recv)
> > > -		__string(addr, rpcrdma_addrstr(r_xprt))
> > > -		__string(port, rpcrdma_portstr(r_xprt))
> > > +		__array(unsigned char, srcaddr, sizeof(struct sockaddr_in6))
> > > +		__array(unsigned char, dstaddr, sizeof(struct sockaddr_in6))
> > > 	),
> > > 
> > > 	TP_fast_assign(
> > > -		const struct rpcrdma_ep *ep = &r_xprt->rx_ep;
> > > +		const struct rdma_cm_id *id = ep->re_id;
> > > 
> > > -		__entry->r_xprt = r_xprt;
> > > 		__entry->inline_send = ep->re_inline_send;
> > > 		__entry->inline_recv = ep->re_inline_recv;
> > > 		__entry->max_send = ep->re_max_inline_send;
> > > 		__entry->max_recv = ep->re_max_inline_recv;
> > > -		__assign_str(addr, rpcrdma_addrstr(r_xprt));
> > > -		__assign_str(port, rpcrdma_portstr(r_xprt));
> > > +		memcpy(__entry->srcaddr, &id->route.addr.src_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > +		memcpy(__entry->dstaddr, &id->route.addr.dst_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > 	),
> > > 
> > > -	TP_printk("peer=[%s]:%s r_xprt=%p neg send/recv=%u/%u, calc
> > > send/recv=%u/%u",
> > > -		__get_str(addr), __get_str(port), __entry->r_xprt,
> > > +	TP_printk("%pISpc -> %pISpc neg send/recv=%u/%u, calc send/recv=%u/%u",
> > > +		__entry->srcaddr, __entry->dstaddr,
> > > 		__entry->inline_send, __entry->inline_recv,
> > > 		__entry->max_send, __entry->max_recv
> > > 	)
> > > );
> > > 
> > > +TRACE_EVENT(xprtrdma_remove,
> > > +	TP_PROTO(
> > > +		const struct rpcrdma_ep *ep
> > > +	),
> > > +
> > > +	TP_ARGS(ep),
> > > +
> > > +	TP_STRUCT__entry(
> > > +		__array(unsigned char, srcaddr, sizeof(struct sockaddr_in6))
> > > +		__array(unsigned char, dstaddr, sizeof(struct sockaddr_in6))
> > > +		__string(name, ep->re_id->device->name)
> > > +	),
> > > +
> > > +	TP_fast_assign(
> > > +		const struct rdma_cm_id *id = ep->re_id;
> > > +
> > > +		memcpy(__entry->srcaddr, &id->route.addr.src_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > +		memcpy(__entry->dstaddr, &id->route.addr.dst_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > +		__assign_str(name, id->device->name);
> > > +	),
> > > +
> > > +	TP_printk("%pISpc -> %pISpc device=%s",
> > > +		__entry->srcaddr, __entry->dstaddr, __get_str(name)
> > > +	)
> > > +);
> > > +
> > > DEFINE_CONN_EVENT(connect);
> > > DEFINE_CONN_EVENT(disconnect);
> > > DEFINE_CONN_EVENT(flush_dct);
> > > 
> > > DEFINE_RXPRT_EVENT(xprtrdma_create);
> > > DEFINE_RXPRT_EVENT(xprtrdma_op_destroy);
> > > -DEFINE_RXPRT_EVENT(xprtrdma_remove);
> > > DEFINE_RXPRT_EVENT(xprtrdma_op_inject_dsc);
> > > DEFINE_RXPRT_EVENT(xprtrdma_op_close);
> > > DEFINE_RXPRT_EVENT(xprtrdma_op_setport);
> > > @@ -480,32 +507,33 @@
> > > 
> > > TRACE_EVENT(xprtrdma_qp_event,
> > > 	TP_PROTO(
> > > -		const struct rpcrdma_xprt *r_xprt,
> > > +		const struct rpcrdma_ep *ep,
> > > 		const struct ib_event *event
> > > 	),
> > > 
> > > -	TP_ARGS(r_xprt, event),
> > > +	TP_ARGS(ep, event),
> > > 
> > > 	TP_STRUCT__entry(
> > > -		__field(const void *, r_xprt)
> > > -		__field(unsigned int, event)
> > > +		__field(unsigned long, event)
> > > 		__string(name, event->device->name)
> > > -		__string(addr, rpcrdma_addrstr(r_xprt))
> > > -		__string(port, rpcrdma_portstr(r_xprt))
> > > +		__array(unsigned char, srcaddr, sizeof(struct sockaddr_in6))
> > > +		__array(unsigned char, dstaddr, sizeof(struct sockaddr_in6))
> > > 	),
> > > 
> > > 	TP_fast_assign(
> > > -		__entry->r_xprt = r_xprt;
> > > +		const struct rdma_cm_id *id = ep->re_id;
> > > +
> > > 		__entry->event = event->event;
> > > 		__assign_str(name, event->device->name);
> > > -		__assign_str(addr, rpcrdma_addrstr(r_xprt));
> > > -		__assign_str(port, rpcrdma_portstr(r_xprt));
> > > +		memcpy(__entry->srcaddr, &id->route.addr.src_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > +		memcpy(__entry->dstaddr, &id->route.addr.dst_addr,
> > > +		       sizeof(struct sockaddr_in6));
> > > 	),
> > > 
> > > -	TP_printk("peer=[%s]:%s r_xprt=%p: dev %s: %s (%u)",
> > > -		__get_str(addr), __get_str(port), __entry->r_xprt,
> > > -		__get_str(name), rdma_show_ib_event(__entry->event),
> > > -		__entry->event
> > > +	TP_printk("%pISpc -> %pISpc device=%s %s (%lu)",
> > > +		__entry->srcaddr, __entry->dstaddr, __get_str(name),
> > > +		rdma_show_ib_event(__entry->event), __entry->event
> > > 	)
> > > );
> > > 
> > > diff --git a/net/sunrpc/xprtrdma/verbs.c b/net/sunrpc/xprtrdma/verbs.c
> > > index 10826982ddf8..5cb308fb4f0f 100644
> > > --- a/net/sunrpc/xprtrdma/verbs.c
> > > +++ b/net/sunrpc/xprtrdma/verbs.c
> > > @@ -116,16 +116,14 @@ static void rpcrdma_xprt_drain(struct rpcrdma_xprt
> > > *r_xprt)
> > >  * @context: ep that owns QP where event occurred
> > >  *
> > >  * Called from the RDMA provider (device driver) possibly in an interrupt
> > > - * context.
> > > + * context. The QP is always destroyed before the ID, so the ID will be
> > > + * reliably available when this handler is invoked.
> > >  */
> > > -static void
> > > -rpcrdma_qp_event_handler(struct ib_event *event, void *context)
> > > +static void rpcrdma_qp_event_handler(struct ib_event *event, void
> > > *context)
> > > {
> > > 	struct rpcrdma_ep *ep = context;
> > > -	struct rpcrdma_xprt *r_xprt = container_of(ep, struct rpcrdma_xprt,
> > > -						rx_ep);
> > > 
> > > -	trace_xprtrdma_qp_event(r_xprt, event);
> > > +	trace_xprtrdma_qp_event(ep, event);
> > > }
> > > 
> > > /**
> > > @@ -202,11 +200,10 @@ static void rpcrdma_wc_receive(struct ib_cq *cq,
> > > struct
> > > ib_wc *wc)
> > > 	rpcrdma_rep_destroy(rep);
> > > }
> > > 
> > > -static void rpcrdma_update_cm_private(struct rpcrdma_xprt *r_xprt,
> > > +static void rpcrdma_update_cm_private(struct rpcrdma_ep *ep,
> > > 				      struct rdma_conn_param *param)
> > > {
> > > 	const struct rpcrdma_connect_private *pmsg = param->private_data;
> > > -	struct rpcrdma_ep *ep = &r_xprt->rx_ep;
> > > 	unsigned int rsize, wsize;
> > > 
> > > 	/* Default settings for RPC-over-RDMA Version One */
> > > @@ -241,6 +238,7 @@ static void rpcrdma_update_cm_private(struct
> > > rpcrdma_xprt
> > > *r_xprt,
> > > static int
> > > rpcrdma_cm_event_handler(struct rdma_cm_id *id, struct rdma_cm_event
> > > *event)
> > > {
> > > +	struct sockaddr *sap = (struct sockaddr *)&id->route.addr.dst_addr;
> > 
> > Is there an clean way to put this inside the CONFIG_SUNRPC_DEBUG lines
> > below?
> > I'm getting an "unused variable 'sap'" warning when CONFIG_SUNRPC_DEBUG=n.
> 
> Looking at the RDMA_CM_EVENT_DEVICE_REMOVAL arm, seems like
> those are not really debugging messages. What if I deleted
> the "#if IS_ENABLED(CONFIG_SUNRPC_DEBUG)" wrapper?

That works for me!

> 
> 
> > Thanks,
> > Anna
> > 
> > > 	struct rpcrdma_xprt *r_xprt = id->context;
> > > 	struct rpcrdma_ep *ep = &r_xprt->rx_ep;
> > > 	struct rpc_xprt *xprt = &r_xprt->rx_xprt;
> > > @@ -264,23 +262,22 @@ static void rpcrdma_update_cm_private(struct
> > > rpcrdma_xprt *r_xprt,
> > > 		return 0;
> > > 	case RDMA_CM_EVENT_DEVICE_REMOVAL:
> > > #if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
> > > -		pr_info("rpcrdma: removing device %s for %s:%s\n",
> > > -			ep->re_id->device->name,
> > > -			rpcrdma_addrstr(r_xprt), rpcrdma_portstr(r_xprt));
> > > +		pr_info("rpcrdma: removing device %s for %pISpc\n",
> > > +			ep->re_id->device->name, sap);
> > > #endif
> > > 		init_completion(&ep->re_remove_done);
> > > 		ep->re_connect_status = -ENODEV;
> > > 		xprt_force_disconnect(xprt);
> > > 		wait_for_completion(&ep->re_remove_done);
> > > -		trace_xprtrdma_remove(r_xprt);
> > > +		trace_xprtrdma_remove(ep);
> > > 
> > > 		/* Return 1 to ensure the core destroys the id. */
> > > 		return 1;
> > > 	case RDMA_CM_EVENT_ESTABLISHED:
> > > 		++xprt->connect_cookie;
> > > 		ep->re_connect_status = 1;
> > > -		rpcrdma_update_cm_private(r_xprt, &event->param.conn);
> > > -		trace_xprtrdma_inline_thresh(r_xprt);
> > > +		rpcrdma_update_cm_private(ep, &event->param.conn);
> > > +		trace_xprtrdma_inline_thresh(ep);
> > > 		wake_up_all(&ep->re_connect_wait);
> > > 		break;
> > > 	case RDMA_CM_EVENT_CONNECT_ERROR:
> > > @@ -290,9 +287,8 @@ static void rpcrdma_update_cm_private(struct
> > > rpcrdma_xprt
> > > *r_xprt,
> > > 		ep->re_connect_status = -ENETUNREACH;
> > > 		goto disconnected;
> > > 	case RDMA_CM_EVENT_REJECTED:
> > > -		dprintk("rpcrdma: connection to %s:%s rejected: %s\n",
> > > -			rpcrdma_addrstr(r_xprt), rpcrdma_portstr(r_xprt),
> > > -			rdma_reject_msg(id, event->status));
> > > +		dprintk("rpcrdma: connection to %pISpc rejected: %s\n",
> > > +			sap, rdma_reject_msg(id, event->status));
> > > 		ep->re_connect_status = -ECONNREFUSED;
> > > 		if (event->status == IB_CM_REJ_STALE_CONN)
> > > 			ep->re_connect_status = -EAGAIN;
> > > @@ -307,8 +303,7 @@ static void rpcrdma_update_cm_private(struct
> > > rpcrdma_xprt
> > > *r_xprt,
> > > 		break;
> > > 	}
> > > 
> > > -	dprintk("RPC:       %s: %s:%s on %s/frwr: %s\n", __func__,
> > > -		rpcrdma_addrstr(r_xprt), rpcrdma_portstr(r_xprt),
> > > +	dprintk("RPC:       %s: %pISpc on %s/frwr: %s\n", __func__, sap,
> > > 		ep->re_id->device->name, rdma_event_msg(event->event));
> > > 	return 0;
> > > }
> 
> --
> Chuck Lever
> 
> 
>