summaryrefslogtreecommitdiffstats
path: root/include/trace
diff options
context:
space:
mode:
authorLinus Torvalds <torvalds@linux-foundation.org>2019-03-12 22:50:42 +0100
committerLinus Torvalds <torvalds@linux-foundation.org>2019-03-12 22:50:42 +0100
commit1fbf3e48123d701584bc75ccac67ef2fe412ac4c (patch)
treecaca042e8d753d4147219820db8497a766b873bd /include/trace
parentMerge tag 'ovl-update-5.1' of git://git.kernel.org/pub/scm/linux/kernel/git/m... (diff)
parentSUNRPC: Take the transport send lock before binding+connecting (diff)
downloadlinux-1fbf3e48123d701584bc75ccac67ef2fe412ac4c.tar.xz
linux-1fbf3e48123d701584bc75ccac67ef2fe412ac4c.zip
Merge tag 'nfs-for-5.1-1' of git://git.linux-nfs.org/projects/trondmy/linux-nfs
Pull NFS client updates from Trond Myklebust: "Highlights include: Stable fixes: - Fixes for NFS I/O request leakages - Fix error handling paths in the NFS I/O recoalescing code - Reinitialise NFSv4.1 sequence results before retransmitting a request - Fix a soft lockup in the delegation recovery code - Bulk destroy of layouts needs to be safe w.r.t. umount - Prevent thundering herd issues when the SUNRPC socket is not connected - Respect RPC call timeouts when retrying transmission Features: - Convert rpc auth layer to use xdr_streams - Config option to disable insecure RPCSEC_GSS crypto types - Reduce size of RPC receive buffers - Readdirplus optimization by cache mechanism - Convert SUNRPC socket send code to use iov_iter() - SUNRPC micro-optimisations to avoid indirect calls - Add support for the pNFS LAYOUTERROR operation and use it with the pNFS/flexfiles driver - Add trace events to report non-zero NFS status codes - Various removals of unnecessary dprintks Bugfixes and cleanups: - Fix a number of sparse warnings and documentation format warnings - Fix nfs_parse_devname to not modify it's argument - Fix potential corruption of page being written through pNFS/blocks - fix xfstest generic/099 failures on nfsv3 - Avoid NFSv4.1 "false retries" when RPC calls are interrupted - Abort I/O early if the pNFS/flexfiles layout segment was invalidated - Avoid unnecessary pNFS/flexfiles layout invalidations" * tag 'nfs-for-5.1-1' of git://git.linux-nfs.org/projects/trondmy/linux-nfs: (90 commits) SUNRPC: Take the transport send lock before binding+connecting SUNRPC: Micro-optimise when the task is known not to be sleeping SUNRPC: Check whether the task was transmitted before rebind/reconnect SUNRPC: Remove redundant calls to RPC_IS_QUEUED() SUNRPC: Clean up SUNRPC: Respect RPC call timeouts when retrying transmission SUNRPC: Fix up RPC back channel transmission SUNRPC: Prevent thundering herd when the socket is not connected SUNRPC: Allow dynamic allocation of back channel slots NFSv4.1: Bump the default callback session slot count to 16 SUNRPC: Convert remaining GFP_NOIO, and GFP_NOWAIT sites in sunrpc NFS/flexfiles: Clean up mirror DS initialisation NFS/flexfiles: Remove dead code in ff_layout_mirror_valid() NFS/flexfile: Simplify nfs4_ff_layout_select_ds_stateid() NFS/flexfile: Simplify nfs4_ff_layout_ds_version() NFS/flexfiles: Simplify ff_layout_get_ds_cred() NFS/flexfiles: Simplify nfs4_ff_find_or_create_ds_client() NFS/flexfiles: Simplify nfs4_ff_layout_select_ds_fh() NFS/flexfiles: Speed up read failover when DSes are down NFS/flexfiles: Don't invalidate DS deviceids for being unresponsive ...
Diffstat (limited to 'include/trace')
-rw-r--r--include/trace/events/rpcgss.h361
-rw-r--r--include/trace/events/rpcrdma.h12
-rw-r--r--include/trace/events/sunrpc.h361
3 files changed, 725 insertions, 9 deletions
diff --git a/include/trace/events/rpcgss.h b/include/trace/events/rpcgss.h
new file mode 100644
index 000000000000..d1f7fe1b6fe4
--- /dev/null
+++ b/include/trace/events/rpcgss.h
@@ -0,0 +1,361 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+/*
+ * Copyright (c) 2018 Oracle. All rights reserved.
+ *
+ * Trace point definitions for the "rpcgss" subsystem.
+ */
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM rpcgss
+
+#if !defined(_TRACE_RPCRDMA_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_RPCGSS_H
+
+#include <linux/tracepoint.h>
+
+/**
+ ** GSS-API related trace events
+ **/
+
+TRACE_DEFINE_ENUM(GSS_S_BAD_MECH);
+TRACE_DEFINE_ENUM(GSS_S_BAD_NAME);
+TRACE_DEFINE_ENUM(GSS_S_BAD_NAMETYPE);
+TRACE_DEFINE_ENUM(GSS_S_BAD_BINDINGS);
+TRACE_DEFINE_ENUM(GSS_S_BAD_STATUS);
+TRACE_DEFINE_ENUM(GSS_S_BAD_SIG);
+TRACE_DEFINE_ENUM(GSS_S_NO_CRED);
+TRACE_DEFINE_ENUM(GSS_S_NO_CONTEXT);
+TRACE_DEFINE_ENUM(GSS_S_DEFECTIVE_TOKEN);
+TRACE_DEFINE_ENUM(GSS_S_DEFECTIVE_CREDENTIAL);
+TRACE_DEFINE_ENUM(GSS_S_CREDENTIALS_EXPIRED);
+TRACE_DEFINE_ENUM(GSS_S_CONTEXT_EXPIRED);
+TRACE_DEFINE_ENUM(GSS_S_FAILURE);
+TRACE_DEFINE_ENUM(GSS_S_BAD_QOP);
+TRACE_DEFINE_ENUM(GSS_S_UNAUTHORIZED);
+TRACE_DEFINE_ENUM(GSS_S_UNAVAILABLE);
+TRACE_DEFINE_ENUM(GSS_S_DUPLICATE_ELEMENT);
+TRACE_DEFINE_ENUM(GSS_S_NAME_NOT_MN);
+TRACE_DEFINE_ENUM(GSS_S_CONTINUE_NEEDED);
+TRACE_DEFINE_ENUM(GSS_S_DUPLICATE_TOKEN);
+TRACE_DEFINE_ENUM(GSS_S_OLD_TOKEN);
+TRACE_DEFINE_ENUM(GSS_S_UNSEQ_TOKEN);
+TRACE_DEFINE_ENUM(GSS_S_GAP_TOKEN);
+
+#define show_gss_status(x) \
+ __print_flags(x, "|", \
+ { GSS_S_BAD_MECH, "GSS_S_BAD_MECH" }, \
+ { GSS_S_BAD_NAME, "GSS_S_BAD_NAME" }, \
+ { GSS_S_BAD_NAMETYPE, "GSS_S_BAD_NAMETYPE" }, \
+ { GSS_S_BAD_BINDINGS, "GSS_S_BAD_BINDINGS" }, \
+ { GSS_S_BAD_STATUS, "GSS_S_BAD_STATUS" }, \
+ { GSS_S_BAD_SIG, "GSS_S_BAD_SIG" }, \
+ { GSS_S_NO_CRED, "GSS_S_NO_CRED" }, \
+ { GSS_S_NO_CONTEXT, "GSS_S_NO_CONTEXT" }, \
+ { GSS_S_DEFECTIVE_TOKEN, "GSS_S_DEFECTIVE_TOKEN" }, \
+ { GSS_S_DEFECTIVE_CREDENTIAL, "GSS_S_DEFECTIVE_CREDENTIAL" }, \
+ { GSS_S_CREDENTIALS_EXPIRED, "GSS_S_CREDENTIALS_EXPIRED" }, \
+ { GSS_S_CONTEXT_EXPIRED, "GSS_S_CONTEXT_EXPIRED" }, \
+ { GSS_S_FAILURE, "GSS_S_FAILURE" }, \
+ { GSS_S_BAD_QOP, "GSS_S_BAD_QOP" }, \
+ { GSS_S_UNAUTHORIZED, "GSS_S_UNAUTHORIZED" }, \
+ { GSS_S_UNAVAILABLE, "GSS_S_UNAVAILABLE" }, \
+ { GSS_S_DUPLICATE_ELEMENT, "GSS_S_DUPLICATE_ELEMENT" }, \
+ { GSS_S_NAME_NOT_MN, "GSS_S_NAME_NOT_MN" }, \
+ { GSS_S_CONTINUE_NEEDED, "GSS_S_CONTINUE_NEEDED" }, \
+ { GSS_S_DUPLICATE_TOKEN, "GSS_S_DUPLICATE_TOKEN" }, \
+ { GSS_S_OLD_TOKEN, "GSS_S_OLD_TOKEN" }, \
+ { GSS_S_UNSEQ_TOKEN, "GSS_S_UNSEQ_TOKEN" }, \
+ { GSS_S_GAP_TOKEN, "GSS_S_GAP_TOKEN" })
+
+
+DECLARE_EVENT_CLASS(rpcgss_gssapi_event,
+ TP_PROTO(
+ const struct rpc_task *task,
+ u32 maj_stat
+ ),
+
+ TP_ARGS(task, maj_stat),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, maj_stat)
+
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->maj_stat = maj_stat;
+ ),
+
+ TP_printk("task:%u@%u maj_stat=%s",
+ __entry->task_id, __entry->client_id,
+ __entry->maj_stat == 0 ?
+ "GSS_S_COMPLETE" : show_gss_status(__entry->maj_stat))
+);
+
+#define DEFINE_GSSAPI_EVENT(name) \
+ DEFINE_EVENT(rpcgss_gssapi_event, rpcgss_##name, \
+ TP_PROTO( \
+ const struct rpc_task *task, \
+ u32 maj_stat \
+ ), \
+ TP_ARGS(task, maj_stat))
+
+TRACE_EVENT(rpcgss_import_ctx,
+ TP_PROTO(
+ int status
+ ),
+
+ TP_ARGS(status),
+
+ TP_STRUCT__entry(
+ __field(int, status)
+ ),
+
+ TP_fast_assign(
+ __entry->status = status;
+ ),
+
+ TP_printk("status=%d", __entry->status)
+);
+
+DEFINE_GSSAPI_EVENT(get_mic);
+DEFINE_GSSAPI_EVENT(verify_mic);
+DEFINE_GSSAPI_EVENT(wrap);
+DEFINE_GSSAPI_EVENT(unwrap);
+
+
+/**
+ ** GSS auth unwrap failures
+ **/
+
+TRACE_EVENT(rpcgss_unwrap_failed,
+ TP_PROTO(
+ const struct rpc_task *task
+ ),
+
+ TP_ARGS(task),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ ),
+
+ TP_printk("task:%u@%u", __entry->task_id, __entry->client_id)
+);
+
+TRACE_EVENT(rpcgss_bad_seqno,
+ TP_PROTO(
+ const struct rpc_task *task,
+ u32 expected,
+ u32 received
+ ),
+
+ TP_ARGS(task, expected, received),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, expected)
+ __field(u32, received)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->expected = expected;
+ __entry->received = received;
+ ),
+
+ TP_printk("task:%u@%u expected seqno %u, received seqno %u",
+ __entry->task_id, __entry->client_id,
+ __entry->expected, __entry->received)
+);
+
+TRACE_EVENT(rpcgss_seqno,
+ TP_PROTO(
+ const struct rpc_task *task
+ ),
+
+ TP_ARGS(task),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, xid)
+ __field(u32, seqno)
+ ),
+
+ TP_fast_assign(
+ const struct rpc_rqst *rqst = task->tk_rqstp;
+
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
+ __entry->seqno = rqst->rq_seqno;
+ ),
+
+ TP_printk("task:%u@%u xid=0x%08x seqno=%u",
+ __entry->task_id, __entry->client_id,
+ __entry->xid, __entry->seqno)
+);
+
+TRACE_EVENT(rpcgss_need_reencode,
+ TP_PROTO(
+ const struct rpc_task *task,
+ u32 seq_xmit,
+ bool ret
+ ),
+
+ TP_ARGS(task, seq_xmit, ret),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, xid)
+ __field(u32, seq_xmit)
+ __field(u32, seqno)
+ __field(bool, ret)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
+ __entry->seq_xmit = seq_xmit;
+ __entry->seqno = task->tk_rqstp->rq_seqno;
+ __entry->ret = ret;
+ ),
+
+ TP_printk("task:%u@%u 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")
+);
+
+/**
+ ** gssd upcall related trace events
+ **/
+
+TRACE_EVENT(rpcgss_upcall_msg,
+ TP_PROTO(
+ const char *buf
+ ),
+
+ TP_ARGS(buf),
+
+ TP_STRUCT__entry(
+ __string(msg, buf)
+ ),
+
+ TP_fast_assign(
+ __assign_str(msg, buf)
+ ),
+
+ TP_printk("msg='%s'", __get_str(msg))
+);
+
+TRACE_EVENT(rpcgss_upcall_result,
+ TP_PROTO(
+ u32 uid,
+ int result
+ ),
+
+ TP_ARGS(uid, result),
+
+ TP_STRUCT__entry(
+ __field(u32, uid)
+ __field(int, result)
+
+ ),
+
+ TP_fast_assign(
+ __entry->uid = uid;
+ __entry->result = result;
+ ),
+
+ TP_printk("for uid %u, result=%d", __entry->uid, __entry->result)
+);
+
+TRACE_EVENT(rpcgss_context,
+ TP_PROTO(
+ unsigned long expiry,
+ unsigned long now,
+ unsigned int timeout,
+ unsigned int len,
+ const u8 *data
+ ),
+
+ TP_ARGS(expiry, now, timeout, len, data),
+
+ TP_STRUCT__entry(
+ __field(unsigned long, expiry)
+ __field(unsigned long, now)
+ __field(unsigned int, timeout)
+ __field(int, len)
+ __string(acceptor, data)
+ ),
+
+ TP_fast_assign(
+ __entry->expiry = expiry;
+ __entry->now = now;
+ __entry->timeout = timeout;
+ __entry->len = len;
+ strncpy(__get_str(acceptor), data, len);
+ ),
+
+ TP_printk("gc_expiry=%lu now=%lu timeout=%u acceptor=%.*s",
+ __entry->expiry, __entry->now, __entry->timeout,
+ __entry->len, __get_str(acceptor))
+);
+
+
+/**
+ ** Miscellaneous events
+ */
+
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5I);
+TRACE_DEFINE_ENUM(RPC_AUTH_GSS_KRB5P);
+
+#define show_pseudoflavor(x) \
+ __print_symbolic(x, \
+ { RPC_AUTH_GSS_KRB5, "RPC_AUTH_GSS_KRB5" }, \
+ { RPC_AUTH_GSS_KRB5I, "RPC_AUTH_GSS_KRB5I" }, \
+ { RPC_AUTH_GSS_KRB5P, "RPC_AUTH_GSS_KRB5P" })
+
+
+TRACE_EVENT(rpcgss_createauth,
+ TP_PROTO(
+ unsigned int flavor,
+ int error
+ ),
+
+ TP_ARGS(flavor, error),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, flavor)
+ __field(int, error)
+
+ ),
+
+ TP_fast_assign(
+ __entry->flavor = flavor;
+ __entry->error = error;
+ ),
+
+ TP_printk("flavor=%s error=%d",
+ show_pseudoflavor(__entry->flavor), __entry->error)
+);
+
+
+#endif /* _TRACE_RPCGSS_H */
+
+#include <trace/define_trace.h>
diff --git a/include/trace/events/rpcrdma.h b/include/trace/events/rpcrdma.h
index 399b1aedc927..962975b4313f 100644
--- a/include/trace/events/rpcrdma.h
+++ b/include/trace/events/rpcrdma.h
@@ -521,12 +521,18 @@ TRACE_EVENT(xprtrdma_post_send,
TP_STRUCT__entry(
__field(const void *, req)
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
__field(int, num_sge)
__field(int, signaled)
__field(int, status)
),
TP_fast_assign(
+ const struct rpc_rqst *rqst = &req->rl_slot;
+
+ __entry->task_id = rqst->rq_task->tk_pid;
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
__entry->req = req;
__entry->num_sge = req->rl_sendctx->sc_wr.num_sge;
__entry->signaled = req->rl_sendctx->sc_wr.send_flags &
@@ -534,9 +540,11 @@ TRACE_EVENT(xprtrdma_post_send,
__entry->status = status;
),
- TP_printk("req=%p, %d SGEs%s, status=%d",
+ TP_printk("task:%u@%u req=%p (%d SGE%s) %sstatus=%d",
+ __entry->task_id, __entry->client_id,
__entry->req, __entry->num_sge,
- (__entry->signaled ? ", signaled" : ""),
+ (__entry->num_sge == 1 ? "" : "s"),
+ (__entry->signaled ? "signaled " : ""),
__entry->status
)
);
diff --git a/include/trace/events/sunrpc.h b/include/trace/events/sunrpc.h
index 0d5d0d91f861..8451f30c6a0f 100644
--- a/include/trace/events/sunrpc.h
+++ b/include/trace/events/sunrpc.h
@@ -77,6 +77,50 @@ TRACE_EVENT(rpc_request,
)
);
+TRACE_DEFINE_ENUM(RPC_TASK_ASYNC);
+TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER);
+TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN);
+TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS);
+TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC);
+TRACE_DEFINE_ENUM(RPC_TASK_KILLED);
+TRACE_DEFINE_ENUM(RPC_TASK_SOFT);
+TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
+TRACE_DEFINE_ENUM(RPC_TASK_SENT);
+TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
+TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
+TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT);
+
+#define rpc_show_task_flags(flags) \
+ __print_flags(flags, "|", \
+ { RPC_TASK_ASYNC, "ASYNC" }, \
+ { RPC_TASK_SWAPPER, "SWAPPER" }, \
+ { RPC_CALL_MAJORSEEN, "MAJORSEEN" }, \
+ { RPC_TASK_ROOTCREDS, "ROOTCREDS" }, \
+ { RPC_TASK_DYNAMIC, "DYNAMIC" }, \
+ { RPC_TASK_KILLED, "KILLED" }, \
+ { RPC_TASK_SOFT, "SOFT" }, \
+ { RPC_TASK_SOFTCONN, "SOFTCONN" }, \
+ { RPC_TASK_SENT, "SENT" }, \
+ { RPC_TASK_TIMEOUT, "TIMEOUT" }, \
+ { RPC_TASK_NOCONNECT, "NOCONNECT" }, \
+ { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" })
+
+TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
+TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
+TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
+TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
+TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
+TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
+
+#define rpc_show_runstate(flags) \
+ __print_flags(flags, "|", \
+ { (1UL << RPC_TASK_RUNNING), "RUNNING" }, \
+ { (1UL << RPC_TASK_QUEUED), "QUEUED" }, \
+ { (1UL << RPC_TASK_ACTIVE), "ACTIVE" }, \
+ { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" }, \
+ { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" }, \
+ { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" })
+
DECLARE_EVENT_CLASS(rpc_task_running,
TP_PROTO(const struct rpc_task *task, const void *action),
@@ -102,10 +146,10 @@ DECLARE_EVENT_CLASS(rpc_task_running,
__entry->flags = task->tk_flags;
),
- TP_printk("task:%u@%d flags=%4.4x state=%4.4lx status=%d action=%pf",
+ TP_printk("task:%u@%d flags=%s runstate=%s status=%d action=%pf",
__entry->task_id, __entry->client_id,
- __entry->flags,
- __entry->runstate,
+ rpc_show_task_flags(__entry->flags),
+ rpc_show_runstate(__entry->runstate),
__entry->status,
__entry->action
)
@@ -149,10 +193,10 @@ DECLARE_EVENT_CLASS(rpc_task_queued,
__assign_str(q_name, rpc_qname(q));
),
- TP_printk("task:%u@%d flags=%4.4x state=%4.4lx status=%d timeout=%lu queue=%s",
+ TP_printk("task:%u@%d flags=%s runstate=%s status=%d timeout=%lu queue=%s",
__entry->task_id, __entry->client_id,
- __entry->flags,
- __entry->runstate,
+ rpc_show_task_flags(__entry->flags),
+ rpc_show_runstate(__entry->runstate),
__entry->status,
__entry->timeout,
__get_str(q_name)
@@ -169,6 +213,87 @@ DECLARE_EVENT_CLASS(rpc_task_queued,
DEFINE_RPC_QUEUED_EVENT(sleep);
DEFINE_RPC_QUEUED_EVENT(wakeup);
+DECLARE_EVENT_CLASS(rpc_failure,
+
+ TP_PROTO(const struct rpc_task *task),
+
+ TP_ARGS(task),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ ),
+
+ TP_printk("task:%u@%u",
+ __entry->task_id, __entry->client_id)
+);
+
+#define DEFINE_RPC_FAILURE(name) \
+ DEFINE_EVENT(rpc_failure, rpc_bad_##name, \
+ TP_PROTO( \
+ const struct rpc_task *task \
+ ), \
+ TP_ARGS(task))
+
+DEFINE_RPC_FAILURE(callhdr);
+DEFINE_RPC_FAILURE(verifier);
+
+DECLARE_EVENT_CLASS(rpc_reply_event,
+
+ TP_PROTO(
+ const struct rpc_task *task
+ ),
+
+ TP_ARGS(task),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, xid)
+ __string(progname, task->tk_client->cl_program->name)
+ __field(u32, version)
+ __string(procname, rpc_proc_name(task))
+ __string(servername, task->tk_xprt->servername)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
+ __assign_str(progname, task->tk_client->cl_program->name)
+ __entry->version = task->tk_client->cl_vers;
+ __assign_str(procname, rpc_proc_name(task))
+ __assign_str(servername, task->tk_xprt->servername)
+ ),
+
+ TP_printk("task:%u@%d server=%s xid=0x%08x %sv%d %s",
+ __entry->task_id, __entry->client_id, __get_str(servername),
+ __entry->xid, __get_str(progname), __entry->version,
+ __get_str(procname))
+)
+
+#define DEFINE_RPC_REPLY_EVENT(name) \
+ DEFINE_EVENT(rpc_reply_event, rpc__##name, \
+ TP_PROTO( \
+ const struct rpc_task *task \
+ ), \
+ TP_ARGS(task))
+
+DEFINE_RPC_REPLY_EVENT(prog_unavail);
+DEFINE_RPC_REPLY_EVENT(prog_mismatch);
+DEFINE_RPC_REPLY_EVENT(proc_unavail);
+DEFINE_RPC_REPLY_EVENT(garbage_args);
+DEFINE_RPC_REPLY_EVENT(unparsable);
+DEFINE_RPC_REPLY_EVENT(mismatch);
+DEFINE_RPC_REPLY_EVENT(stale_creds);
+DEFINE_RPC_REPLY_EVENT(bad_creds);
+DEFINE_RPC_REPLY_EVENT(auth_tooweak);
+
TRACE_EVENT(rpc_stats_latency,
TP_PROTO(
@@ -210,6 +335,169 @@ TRACE_EVENT(rpc_stats_latency,
__entry->backlog, __entry->rtt, __entry->execute)
);
+TRACE_EVENT(rpc_xdr_overflow,
+ TP_PROTO(
+ const struct xdr_stream *xdr,
+ size_t requested
+ ),
+
+ TP_ARGS(xdr, requested),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(int, version)
+ __field(size_t, requested)
+ __field(const void *, end)
+ __field(const void *, p)
+ __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, len)
+ __string(progname,
+ xdr->rqst->rq_task->tk_client->cl_program->name)
+ __string(procedure,
+ xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
+ ),
+
+ TP_fast_assign(
+ if (xdr->rqst) {
+ const struct rpc_task *task = xdr->rqst->rq_task;
+
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __assign_str(progname,
+ task->tk_client->cl_program->name)
+ __entry->version = task->tk_client->cl_vers;
+ __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
+ } else {
+ __entry->task_id = 0;
+ __entry->client_id = 0;
+ __assign_str(progname, "unknown")
+ __entry->version = 0;
+ __assign_str(procedure, "unknown")
+ }
+ __entry->requested = requested;
+ __entry->end = xdr->end;
+ __entry->p = xdr->p;
+ __entry->head_base = xdr->buf->head[0].iov_base,
+ __entry->head_len = xdr->buf->head[0].iov_len,
+ __entry->page_len = xdr->buf->page_len,
+ __entry->tail_base = xdr->buf->tail[0].iov_base,
+ __entry->tail_len = xdr->buf->tail[0].iov_len,
+ __entry->len = xdr->buf->len;
+ ),
+
+ TP_printk(
+ "task:%u@%u %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
+ __entry->task_id, __entry->client_id,
+ __get_str(progname), __entry->version, __get_str(procedure),
+ __entry->requested, __entry->p, __entry->end,
+ __entry->head_base, __entry->head_len,
+ __entry->page_len,
+ __entry->tail_base, __entry->tail_len,
+ __entry->len
+ )
+);
+
+TRACE_EVENT(rpc_xdr_alignment,
+ TP_PROTO(
+ const struct xdr_stream *xdr,
+ size_t offset,
+ unsigned int copied
+ ),
+
+ TP_ARGS(xdr, offset, copied),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(int, version)
+ __field(size_t, offset)
+ __field(unsigned int, copied)
+ __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, len)
+ __string(progname,
+ xdr->rqst->rq_task->tk_client->cl_program->name)
+ __string(procedure,
+ xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
+ ),
+
+ TP_fast_assign(
+ const struct rpc_task *task = xdr->rqst->rq_task;
+
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __assign_str(progname,
+ task->tk_client->cl_program->name)
+ __entry->version = task->tk_client->cl_vers;
+ __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
+
+ __entry->offset = offset;
+ __entry->copied = copied;
+ __entry->head_base = xdr->buf->head[0].iov_base,
+ __entry->head_len = xdr->buf->head[0].iov_len,
+ __entry->page_len = xdr->buf->page_len,
+ __entry->tail_base = xdr->buf->tail[0].iov_base,
+ __entry->tail_len = xdr->buf->tail[0].iov_len,
+ __entry->len = xdr->buf->len;
+ ),
+
+ TP_printk(
+ "task:%u@%u %sv%d %s offset=%zu copied=%u xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
+ __entry->task_id, __entry->client_id,
+ __get_str(progname), __entry->version, __get_str(procedure),
+ __entry->offset, __entry->copied,
+ __entry->head_base, __entry->head_len,
+ __entry->page_len,
+ __entry->tail_base, __entry->tail_len,
+ __entry->len
+ )
+);
+
+TRACE_EVENT(rpc_reply_pages,
+ TP_PROTO(
+ const struct rpc_rqst *req
+ ),
+
+ TP_ARGS(req),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __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)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = req->rq_task->tk_pid;
+ __entry->client_id = req->rq_task->tk_client->cl_clid;
+
+ __entry->head_base = req->rq_rcv_buf.head[0].iov_base;
+ __entry->head_len = req->rq_rcv_buf.head[0].iov_len;
+ __entry->page_len = req->rq_rcv_buf.page_len;
+ __entry->tail_base = req->rq_rcv_buf.tail[0].iov_base;
+ __entry->tail_len = req->rq_rcv_buf.tail[0].iov_len;
+ ),
+
+ TP_printk(
+ "task:%u@%u xdr=[%p,%zu]/%u/[%p,%zu]\n",
+ __entry->task_id, __entry->client_id,
+ __entry->head_base, __entry->head_len,
+ __entry->page_len,
+ __entry->tail_base, __entry->tail_len
+ )
+);
+
/*
* First define the enums in the below macros to be exported to userspace
* via TRACE_DEFINE_ENUM().
@@ -404,9 +692,68 @@ DECLARE_EVENT_CLASS(rpc_xprt_event,
DEFINE_RPC_XPRT_EVENT(timer);
DEFINE_RPC_XPRT_EVENT(lookup_rqst);
-DEFINE_RPC_XPRT_EVENT(transmit);
DEFINE_RPC_XPRT_EVENT(complete_rqst);
+TRACE_EVENT(xprt_transmit,
+ TP_PROTO(
+ const struct rpc_rqst *rqst,
+ int status
+ ),
+
+ TP_ARGS(rqst, status),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, xid)
+ __field(u32, seqno)
+ __field(int, status)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = rqst->rq_task->tk_pid;
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
+ __entry->seqno = rqst->rq_seqno;
+ __entry->status = status;
+ ),
+
+ TP_printk(
+ "task:%u@%u xid=0x%08x seqno=%u status=%d",
+ __entry->task_id, __entry->client_id, __entry->xid,
+ __entry->seqno, __entry->status)
+);
+
+TRACE_EVENT(xprt_enq_xmit,
+ TP_PROTO(
+ const struct rpc_task *task,
+ int stage
+ ),
+
+ TP_ARGS(task, stage),
+
+ TP_STRUCT__entry(
+ __field(unsigned int, task_id)
+ __field(unsigned int, client_id)
+ __field(u32, xid)
+ __field(u32, seqno)
+ __field(int, stage)
+ ),
+
+ TP_fast_assign(
+ __entry->task_id = task->tk_pid;
+ __entry->client_id = task->tk_client->cl_clid;
+ __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
+ __entry->seqno = task->tk_rqstp->rq_seqno;
+ __entry->stage = stage;
+ ),
+
+ TP_printk(
+ "task:%u@%u xid=0x%08x seqno=%u stage=%d",
+ __entry->task_id, __entry->client_id, __entry->xid,
+ __entry->seqno, __entry->stage)
+);
+
TRACE_EVENT(xprt_ping,
TP_PROTO(const struct rpc_xprt *xprt, int status),