SUNRPC: Tracepoints should display tk_pid and cl_clid as a fixed-size field

For certain special cases, RPC-related tracepoints record a -1 as
the task ID or the client ID. It's ugly for a trace event to display
4 billion in these cases.

To help keep SUNRPC tracepoints consistent, create a macro that
defines the print format specifiers for tk_pid and cl_clid. At some
point in the future we might try tk_pid with a wider range of values
than 0..64K so this makes it easier to make that change.

RPC tracepoints now look like this:

<...>-1276  [009]   149.720358: rpc_clnt_new:         client=00000005 peer=[192.168.2.55]:20049 program=nfs server=klimt.ib

<...>-1342  [004]   149.921234: rpc_xdr_recvfrom:     task:0000001a@00000005 head=[0xff1242d9ab6dc01c,144] page=0 tail=[(nil),0] len=144
<...>-1342  [004]   149.921235: xprt_release_cong:    task:0000001a@00000005 snd_task:ffffffff cong=256 cwnd=16384
<...>-1342  [004]   149.921235: xprt_put_cong:        task:0000001a@00000005 snd_task:ffffffff cong=0 cwnd=16384

Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Trond Myklebust <trond.myklebust@hammerspace.com>
This commit is contained in:
Chuck Lever
2021-10-16 18:02:24 -04:00
committed by Trond Myklebust
parent 7a3d524c4c
commit b4776a341e
6 changed files with 108 additions and 59 deletions

View File

@@ -13,6 +13,8 @@
#include <linux/tracepoint.h>
#include <trace/events/sunrpc_base.h>
/**
** GSS-API related trace events
**/
@@ -99,7 +101,7 @@ DECLARE_EVENT_CLASS(rpcgss_gssapi_event,
__entry->maj_stat = maj_stat;
),
TP_printk("task:%u@%u maj_stat=%s",
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " maj_stat=%s",
__entry->task_id, __entry->client_id,
__entry->maj_stat == 0 ?
"GSS_S_COMPLETE" : show_gss_status(__entry->maj_stat))
@@ -332,7 +334,8 @@ TRACE_EVENT(rpcgss_unwrap_failed,
__entry->client_id = task->tk_client->cl_clid;
),
TP_printk("task:%u@%u", __entry->task_id, __entry->client_id)
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER,
__entry->task_id, __entry->client_id)
);
TRACE_EVENT(rpcgss_bad_seqno,
@@ -358,7 +361,8 @@ TRACE_EVENT(rpcgss_bad_seqno,
__entry->received = received;
),
TP_printk("task:%u@%u expected seqno %u, received seqno %u",
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER
" expected seqno %u, received seqno %u",
__entry->task_id, __entry->client_id,
__entry->expected, __entry->received)
);
@@ -386,7 +390,7 @@ TRACE_EVENT(rpcgss_seqno,
__entry->seqno = rqst->rq_seqno;
),
TP_printk("task:%u@%u xid=0x%08x seqno=%u",
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " xid=0x%08x seqno=%u",
__entry->task_id, __entry->client_id,
__entry->xid, __entry->seqno)
);
@@ -418,7 +422,8 @@ TRACE_EVENT(rpcgss_need_reencode,
__entry->ret = ret;
),
TP_printk("task:%u@%u xid=0x%08x rq_seqno=%u seq_xmit=%u reencode %sneeded",
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER
" xid=0x%08x rq_seqno=%u seq_xmit=%u reencode %sneeded",
__entry->task_id, __entry->client_id,
__entry->xid, __entry->seqno, __entry->seq_xmit,
__entry->ret ? "" : "un")
@@ -452,7 +457,8 @@ TRACE_EVENT(rpcgss_update_slack,
__entry->verfsize = auth->au_verfsize;
),
TP_printk("task:%u@%u xid=0x%08x auth=%p rslack=%u ralign=%u verfsize=%u\n",
TP_printk(SUNRPC_TRACE_TASK_SPECIFIER
" xid=0x%08x auth=%p rslack=%u ralign=%u verfsize=%u\n",
__entry->task_id, __entry->client_id, __entry->xid,
__entry->auth, __entry->rslack, __entry->ralign,
__entry->verfsize)