SUNRPC: Move the svc_xdr_recvfrom tracepoint again

Commit 156708adf2 ("SUNRPC: Move the svc_xdr_recvfrom()
tracepoint") tried to capture the correct XID in the trace record,
but this line in svc_recv:

	rqstp->rq_xid = svc_getu32(&rqstp->rq_arg.head[0]);

alters the size of rq_arg.head[0].iov_len. The tracepoint records
the correct XID but an incorrect value for the length of the
xdr_buf's head.

To keep the trace callsites simple, I've created two trace classes.
One assumes the xdr_buf contains a full RPC message, and the XID
can be extracted from it. The other assumes the contents of the
xdr_buf are arbitrary, and the xid will be provided by the caller.

Currently there is only one user of each class, but I expect we will
need a few more tracepoints using each class as time goes on.

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
This commit is contained in:
Chuck Lever 2021-01-03 14:39:27 -05:00
parent 51b2ee7d00
commit 5f39d2713b
2 changed files with 56 additions and 9 deletions

View file

@ -1424,13 +1424,13 @@ TRACE_EVENT(rpcb_unregister,
)
);
DECLARE_EVENT_CLASS(svc_xdr_buf_class,
/* Record an xdr_buf containing a fully-formed RPC message */
DECLARE_EVENT_CLASS(svc_xdr_msg_class,
TP_PROTO(
const struct svc_rqst *rqst,
const struct xdr_buf *xdr
),
TP_ARGS(rqst, xdr),
TP_ARGS(xdr),
TP_STRUCT__entry(
__field(u32, xid)
@ -1443,7 +1443,55 @@ DECLARE_EVENT_CLASS(svc_xdr_buf_class,
),
TP_fast_assign(
__entry->xid = be32_to_cpu(rqst->rq_xid);
__be32 *p = (__be32 *)xdr->head[0].iov_base;
__entry->xid = be32_to_cpu(*p);
__entry->head_base = p;
__entry->head_len = xdr->head[0].iov_len;
__entry->tail_base = xdr->tail[0].iov_base;
__entry->tail_len = xdr->tail[0].iov_len;
__entry->page_len = xdr->page_len;
__entry->msg_len = xdr->len;
),
TP_printk("xid=0x%08x head=[%p,%zu] page=%u tail=[%p,%zu] len=%u",
__entry->xid,
__entry->head_base, __entry->head_len, __entry->page_len,
__entry->tail_base, __entry->tail_len, __entry->msg_len
)
);
#define DEFINE_SVCXDRMSG_EVENT(name) \
DEFINE_EVENT(svc_xdr_msg_class, \
svc_xdr_##name, \
TP_PROTO( \
const struct xdr_buf *xdr \
), \
TP_ARGS(xdr))
DEFINE_SVCXDRMSG_EVENT(recvfrom);
/* Record an xdr_buf containing arbitrary data, tagged with an XID */
DECLARE_EVENT_CLASS(svc_xdr_buf_class,
TP_PROTO(
__be32 xid,
const struct xdr_buf *xdr
),
TP_ARGS(xid, xdr),
TP_STRUCT__entry(
__field(u32, xid)
__field(const void *, head_base)
__field(size_t, head_len)
__field(const void *, tail_base)
__field(size_t, tail_len)
__field(unsigned int, page_len)
__field(unsigned int, msg_len)
),
TP_fast_assign(
__entry->xid = be32_to_cpu(xid);
__entry->head_base = xdr->head[0].iov_base;
__entry->head_len = xdr->head[0].iov_len;
__entry->tail_base = xdr->tail[0].iov_base;
@ -1463,12 +1511,11 @@ DECLARE_EVENT_CLASS(svc_xdr_buf_class,
DEFINE_EVENT(svc_xdr_buf_class, \
svc_xdr_##name, \
TP_PROTO( \
const struct svc_rqst *rqst, \
__be32 xid, \
const struct xdr_buf *xdr \
), \
TP_ARGS(rqst, xdr))
TP_ARGS(xid, xdr))
DEFINE_SVCXDRBUF_EVENT(recvfrom);
DEFINE_SVCXDRBUF_EVENT(sendto);
/*

View file

@ -857,6 +857,7 @@ int svc_recv(struct svc_rqst *rqstp, long timeout)
err = -EAGAIN;
if (len <= 0)
goto out_release;
trace_svc_xdr_recvfrom(&rqstp->rq_arg);
clear_bit(XPT_OLD, &xprt->xpt_flags);
@ -866,7 +867,6 @@ int svc_recv(struct svc_rqst *rqstp, long timeout)
if (serv->sv_stats)
serv->sv_stats->netcnt++;
trace_svc_xdr_recvfrom(rqstp, &rqstp->rq_arg);
return len;
out_release:
rqstp->rq_res.len = 0;
@ -904,7 +904,7 @@ int svc_send(struct svc_rqst *rqstp)
xb->len = xb->head[0].iov_len +
xb->page_len +
xb->tail[0].iov_len;
trace_svc_xdr_sendto(rqstp, xb);
trace_svc_xdr_sendto(rqstp->rq_xid, xb);
trace_svc_stats_latency(rqstp);
len = xprt->xpt_ops->xpo_sendto(rqstp);