1 /* SPDX-License-Identifier: GPL-2.0 */
3 #define TRACE_SYSTEM sunrpc
5 #if !defined(_TRACE_SUNRPC_H) || defined(TRACE_HEADER_MULTI_READ)
6 #define _TRACE_SUNRPC_H
8 #include <linux/sunrpc/sched.h>
9 #include <linux/sunrpc/clnt.h>
10 #include <linux/sunrpc/svc.h>
11 #include <linux/sunrpc/xprtsock.h>
12 #include <linux/sunrpc/svc_xprt.h>
13 #include <net/tcp_states.h>
14 #include <linux/net.h>
15 #include <linux/tracepoint.h>
17 TRACE_DEFINE_ENUM(RPC_AUTH_OK);
18 TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED);
19 TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED);
20 TRACE_DEFINE_ENUM(RPC_AUTH_BADVERF);
21 TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDVERF);
22 TRACE_DEFINE_ENUM(RPC_AUTH_TOOWEAK);
23 TRACE_DEFINE_ENUM(RPCSEC_GSS_CREDPROBLEM);
24 TRACE_DEFINE_ENUM(RPCSEC_GSS_CTXPROBLEM);
26 #define rpc_show_auth_stat(status) \
27 __print_symbolic(status, \
28 { RPC_AUTH_OK, "AUTH_OK" }, \
29 { RPC_AUTH_BADCRED, "BADCRED" }, \
30 { RPC_AUTH_REJECTEDCRED, "REJECTEDCRED" }, \
31 { RPC_AUTH_BADVERF, "BADVERF" }, \
32 { RPC_AUTH_REJECTEDVERF, "REJECTEDVERF" }, \
33 { RPC_AUTH_TOOWEAK, "TOOWEAK" }, \
34 { RPCSEC_GSS_CREDPROBLEM, "GSS_CREDPROBLEM" }, \
35 { RPCSEC_GSS_CTXPROBLEM, "GSS_CTXPROBLEM" }) \
37 DECLARE_EVENT_CLASS(rpc_task_status,
39 TP_PROTO(const struct rpc_task *task),
44 __field(unsigned int, task_id)
45 __field(unsigned int, client_id)
50 __entry->task_id = task->tk_pid;
51 __entry->client_id = task->tk_client->cl_clid;
52 __entry->status = task->tk_status;
55 TP_printk("task:%u@%u status=%d",
56 __entry->task_id, __entry->client_id,
59 #define DEFINE_RPC_STATUS_EVENT(name) \
60 DEFINE_EVENT(rpc_task_status, rpc_##name##_status, \
62 const struct rpc_task *task \
66 DEFINE_RPC_STATUS_EVENT(call);
67 DEFINE_RPC_STATUS_EVENT(bind);
68 DEFINE_RPC_STATUS_EVENT(connect);
70 TRACE_EVENT(rpc_request,
71 TP_PROTO(const struct rpc_task *task),
76 __field(unsigned int, task_id)
77 __field(unsigned int, client_id)
80 __string(progname, task->tk_client->cl_program->name)
81 __string(procname, rpc_proc_name(task))
85 __entry->task_id = task->tk_pid;
86 __entry->client_id = task->tk_client->cl_clid;
87 __entry->version = task->tk_client->cl_vers;
88 __entry->async = RPC_IS_ASYNC(task);
89 __assign_str(progname, task->tk_client->cl_program->name)
90 __assign_str(procname, rpc_proc_name(task))
93 TP_printk("task:%u@%u %sv%d %s (%ssync)",
94 __entry->task_id, __entry->client_id,
95 __get_str(progname), __entry->version,
96 __get_str(procname), __entry->async ? "a": ""
100 TRACE_DEFINE_ENUM(RPC_TASK_ASYNC);
101 TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER);
102 TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN);
103 TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS);
104 TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC);
105 TRACE_DEFINE_ENUM(RPC_TASK_SOFT);
106 TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
107 TRACE_DEFINE_ENUM(RPC_TASK_SENT);
108 TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
109 TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
110 TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT);
112 #define rpc_show_task_flags(flags) \
113 __print_flags(flags, "|", \
114 { RPC_TASK_ASYNC, "ASYNC" }, \
115 { RPC_TASK_SWAPPER, "SWAPPER" }, \
116 { RPC_CALL_MAJORSEEN, "MAJORSEEN" }, \
117 { RPC_TASK_ROOTCREDS, "ROOTCREDS" }, \
118 { RPC_TASK_DYNAMIC, "DYNAMIC" }, \
119 { RPC_TASK_SOFT, "SOFT" }, \
120 { RPC_TASK_SOFTCONN, "SOFTCONN" }, \
121 { RPC_TASK_SENT, "SENT" }, \
122 { RPC_TASK_TIMEOUT, "TIMEOUT" }, \
123 { RPC_TASK_NOCONNECT, "NOCONNECT" }, \
124 { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" })
126 TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
127 TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
128 TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
129 TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
130 TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
131 TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
132 TRACE_DEFINE_ENUM(RPC_TASK_SIGNALLED);
134 #define rpc_show_runstate(flags) \
135 __print_flags(flags, "|", \
136 { (1UL << RPC_TASK_RUNNING), "RUNNING" }, \
137 { (1UL << RPC_TASK_QUEUED), "QUEUED" }, \
138 { (1UL << RPC_TASK_ACTIVE), "ACTIVE" }, \
139 { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" }, \
140 { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" }, \
141 { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" }, \
142 { (1UL << RPC_TASK_SIGNALLED), "SIGNALLED" })
144 DECLARE_EVENT_CLASS(rpc_task_running,
146 TP_PROTO(const struct rpc_task *task, const void *action),
148 TP_ARGS(task, action),
151 __field(unsigned int, task_id)
152 __field(unsigned int, client_id)
153 __field(const void *, action)
154 __field(unsigned long, runstate)
156 __field(unsigned short, flags)
160 __entry->client_id = task->tk_client ?
161 task->tk_client->cl_clid : -1;
162 __entry->task_id = task->tk_pid;
163 __entry->action = action;
164 __entry->runstate = task->tk_runstate;
165 __entry->status = task->tk_status;
166 __entry->flags = task->tk_flags;
169 TP_printk("task:%u@%d flags=%s runstate=%s status=%d action=%ps",
170 __entry->task_id, __entry->client_id,
171 rpc_show_task_flags(__entry->flags),
172 rpc_show_runstate(__entry->runstate),
177 #define DEFINE_RPC_RUNNING_EVENT(name) \
178 DEFINE_EVENT(rpc_task_running, rpc_task_##name, \
180 const struct rpc_task *task, \
183 TP_ARGS(task, action))
185 DEFINE_RPC_RUNNING_EVENT(begin);
186 DEFINE_RPC_RUNNING_EVENT(run_action);
187 DEFINE_RPC_RUNNING_EVENT(complete);
188 DEFINE_RPC_RUNNING_EVENT(end);
190 DECLARE_EVENT_CLASS(rpc_task_queued,
192 TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q),
197 __field(unsigned int, task_id)
198 __field(unsigned int, client_id)
199 __field(unsigned long, timeout)
200 __field(unsigned long, runstate)
202 __field(unsigned short, flags)
203 __string(q_name, rpc_qname(q))
207 __entry->client_id = task->tk_client ?
208 task->tk_client->cl_clid : -1;
209 __entry->task_id = task->tk_pid;
210 __entry->timeout = rpc_task_timeout(task);
211 __entry->runstate = task->tk_runstate;
212 __entry->status = task->tk_status;
213 __entry->flags = task->tk_flags;
214 __assign_str(q_name, rpc_qname(q));
217 TP_printk("task:%u@%d flags=%s runstate=%s status=%d timeout=%lu queue=%s",
218 __entry->task_id, __entry->client_id,
219 rpc_show_task_flags(__entry->flags),
220 rpc_show_runstate(__entry->runstate),
226 #define DEFINE_RPC_QUEUED_EVENT(name) \
227 DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \
229 const struct rpc_task *task, \
230 const struct rpc_wait_queue *q \
234 DEFINE_RPC_QUEUED_EVENT(sleep);
235 DEFINE_RPC_QUEUED_EVENT(wakeup);
237 DECLARE_EVENT_CLASS(rpc_failure,
239 TP_PROTO(const struct rpc_task *task),
244 __field(unsigned int, task_id)
245 __field(unsigned int, client_id)
249 __entry->task_id = task->tk_pid;
250 __entry->client_id = task->tk_client->cl_clid;
253 TP_printk("task:%u@%u",
254 __entry->task_id, __entry->client_id)
257 #define DEFINE_RPC_FAILURE(name) \
258 DEFINE_EVENT(rpc_failure, rpc_bad_##name, \
260 const struct rpc_task *task \
264 DEFINE_RPC_FAILURE(callhdr);
265 DEFINE_RPC_FAILURE(verifier);
267 DECLARE_EVENT_CLASS(rpc_reply_event,
270 const struct rpc_task *task
276 __field(unsigned int, task_id)
277 __field(unsigned int, client_id)
279 __string(progname, task->tk_client->cl_program->name)
280 __field(u32, version)
281 __string(procname, rpc_proc_name(task))
282 __string(servername, task->tk_xprt->servername)
286 __entry->task_id = task->tk_pid;
287 __entry->client_id = task->tk_client->cl_clid;
288 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
289 __assign_str(progname, task->tk_client->cl_program->name)
290 __entry->version = task->tk_client->cl_vers;
291 __assign_str(procname, rpc_proc_name(task))
292 __assign_str(servername, task->tk_xprt->servername)
295 TP_printk("task:%u@%d server=%s xid=0x%08x %sv%d %s",
296 __entry->task_id, __entry->client_id, __get_str(servername),
297 __entry->xid, __get_str(progname), __entry->version,
301 #define DEFINE_RPC_REPLY_EVENT(name) \
302 DEFINE_EVENT(rpc_reply_event, rpc__##name, \
304 const struct rpc_task *task \
308 DEFINE_RPC_REPLY_EVENT(prog_unavail);
309 DEFINE_RPC_REPLY_EVENT(prog_mismatch);
310 DEFINE_RPC_REPLY_EVENT(proc_unavail);
311 DEFINE_RPC_REPLY_EVENT(garbage_args);
312 DEFINE_RPC_REPLY_EVENT(unparsable);
313 DEFINE_RPC_REPLY_EVENT(mismatch);
314 DEFINE_RPC_REPLY_EVENT(stale_creds);
315 DEFINE_RPC_REPLY_EVENT(bad_creds);
316 DEFINE_RPC_REPLY_EVENT(auth_tooweak);
318 TRACE_EVENT(rpc_stats_latency,
321 const struct rpc_task *task,
327 TP_ARGS(task, backlog, rtt, execute),
330 __field(unsigned int, task_id)
331 __field(unsigned int, client_id)
333 __field(int, version)
334 __string(progname, task->tk_client->cl_program->name)
335 __string(procname, rpc_proc_name(task))
336 __field(unsigned long, backlog)
337 __field(unsigned long, rtt)
338 __field(unsigned long, execute)
342 __entry->client_id = task->tk_client->cl_clid;
343 __entry->task_id = task->tk_pid;
344 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
345 __entry->version = task->tk_client->cl_vers;
346 __assign_str(progname, task->tk_client->cl_program->name)
347 __assign_str(procname, rpc_proc_name(task))
348 __entry->backlog = ktime_to_us(backlog);
349 __entry->rtt = ktime_to_us(rtt);
350 __entry->execute = ktime_to_us(execute);
353 TP_printk("task:%u@%d xid=0x%08x %sv%d %s backlog=%lu rtt=%lu execute=%lu",
354 __entry->task_id, __entry->client_id, __entry->xid,
355 __get_str(progname), __entry->version, __get_str(procname),
356 __entry->backlog, __entry->rtt, __entry->execute)
359 TRACE_EVENT(rpc_xdr_overflow,
361 const struct xdr_stream *xdr,
365 TP_ARGS(xdr, requested),
368 __field(unsigned int, task_id)
369 __field(unsigned int, client_id)
370 __field(int, version)
371 __field(size_t, requested)
372 __field(const void *, end)
373 __field(const void *, p)
374 __field(const void *, head_base)
375 __field(size_t, head_len)
376 __field(const void *, tail_base)
377 __field(size_t, tail_len)
378 __field(unsigned int, page_len)
379 __field(unsigned int, len)
381 xdr->rqst->rq_task->tk_client->cl_program->name)
383 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
388 const struct rpc_task *task = xdr->rqst->rq_task;
390 __entry->task_id = task->tk_pid;
391 __entry->client_id = task->tk_client->cl_clid;
392 __assign_str(progname,
393 task->tk_client->cl_program->name)
394 __entry->version = task->tk_client->cl_vers;
395 __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
397 __entry->task_id = 0;
398 __entry->client_id = 0;
399 __assign_str(progname, "unknown")
400 __entry->version = 0;
401 __assign_str(procedure, "unknown")
403 __entry->requested = requested;
404 __entry->end = xdr->end;
406 __entry->head_base = xdr->buf->head[0].iov_base,
407 __entry->head_len = xdr->buf->head[0].iov_len,
408 __entry->page_len = xdr->buf->page_len,
409 __entry->tail_base = xdr->buf->tail[0].iov_base,
410 __entry->tail_len = xdr->buf->tail[0].iov_len,
411 __entry->len = xdr->buf->len;
415 "task:%u@%u %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
416 __entry->task_id, __entry->client_id,
417 __get_str(progname), __entry->version, __get_str(procedure),
418 __entry->requested, __entry->p, __entry->end,
419 __entry->head_base, __entry->head_len,
421 __entry->tail_base, __entry->tail_len,
426 TRACE_EVENT(rpc_xdr_alignment,
428 const struct xdr_stream *xdr,
433 TP_ARGS(xdr, offset, copied),
436 __field(unsigned int, task_id)
437 __field(unsigned int, client_id)
438 __field(int, version)
439 __field(size_t, offset)
440 __field(unsigned int, copied)
441 __field(const void *, head_base)
442 __field(size_t, head_len)
443 __field(const void *, tail_base)
444 __field(size_t, tail_len)
445 __field(unsigned int, page_len)
446 __field(unsigned int, len)
448 xdr->rqst->rq_task->tk_client->cl_program->name)
450 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
454 const struct rpc_task *task = xdr->rqst->rq_task;
456 __entry->task_id = task->tk_pid;
457 __entry->client_id = task->tk_client->cl_clid;
458 __assign_str(progname,
459 task->tk_client->cl_program->name)
460 __entry->version = task->tk_client->cl_vers;
461 __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
463 __entry->offset = offset;
464 __entry->copied = copied;
465 __entry->head_base = xdr->buf->head[0].iov_base,
466 __entry->head_len = xdr->buf->head[0].iov_len,
467 __entry->page_len = xdr->buf->page_len,
468 __entry->tail_base = xdr->buf->tail[0].iov_base,
469 __entry->tail_len = xdr->buf->tail[0].iov_len,
470 __entry->len = xdr->buf->len;
474 "task:%u@%u %sv%d %s offset=%zu copied=%u xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
475 __entry->task_id, __entry->client_id,
476 __get_str(progname), __entry->version, __get_str(procedure),
477 __entry->offset, __entry->copied,
478 __entry->head_base, __entry->head_len,
480 __entry->tail_base, __entry->tail_len,
485 TRACE_EVENT(rpc_reply_pages,
487 const struct rpc_rqst *req
493 __field(unsigned int, task_id)
494 __field(unsigned int, client_id)
495 __field(const void *, head_base)
496 __field(size_t, head_len)
497 __field(const void *, tail_base)
498 __field(size_t, tail_len)
499 __field(unsigned int, page_len)
503 __entry->task_id = req->rq_task->tk_pid;
504 __entry->client_id = req->rq_task->tk_client->cl_clid;
506 __entry->head_base = req->rq_rcv_buf.head[0].iov_base;
507 __entry->head_len = req->rq_rcv_buf.head[0].iov_len;
508 __entry->page_len = req->rq_rcv_buf.page_len;
509 __entry->tail_base = req->rq_rcv_buf.tail[0].iov_base;
510 __entry->tail_len = req->rq_rcv_buf.tail[0].iov_len;
514 "task:%u@%u xdr=[%p,%zu]/%u/[%p,%zu]\n",
515 __entry->task_id, __entry->client_id,
516 __entry->head_base, __entry->head_len,
518 __entry->tail_base, __entry->tail_len
523 * First define the enums in the below macros to be exported to userspace
524 * via TRACE_DEFINE_ENUM().
528 #define EM(a, b) TRACE_DEFINE_ENUM(a);
529 #define EMe(a, b) TRACE_DEFINE_ENUM(a);
531 #define RPC_SHOW_SOCKET \
532 EM( SS_FREE, "FREE" ) \
533 EM( SS_UNCONNECTED, "UNCONNECTED" ) \
534 EM( SS_CONNECTING, "CONNECTING," ) \
535 EM( SS_CONNECTED, "CONNECTED," ) \
536 EMe(SS_DISCONNECTING, "DISCONNECTING" )
538 #define rpc_show_socket_state(state) \
539 __print_symbolic(state, RPC_SHOW_SOCKET)
543 #define RPC_SHOW_SOCK \
544 EM( TCP_ESTABLISHED, "ESTABLISHED" ) \
545 EM( TCP_SYN_SENT, "SYN_SENT" ) \
546 EM( TCP_SYN_RECV, "SYN_RECV" ) \
547 EM( TCP_FIN_WAIT1, "FIN_WAIT1" ) \
548 EM( TCP_FIN_WAIT2, "FIN_WAIT2" ) \
549 EM( TCP_TIME_WAIT, "TIME_WAIT" ) \
550 EM( TCP_CLOSE, "CLOSE" ) \
551 EM( TCP_CLOSE_WAIT, "CLOSE_WAIT" ) \
552 EM( TCP_LAST_ACK, "LAST_ACK" ) \
553 EM( TCP_LISTEN, "LISTEN" ) \
554 EMe( TCP_CLOSING, "CLOSING" )
556 #define rpc_show_sock_state(state) \
557 __print_symbolic(state, RPC_SHOW_SOCK)
562 * Now redefine the EM() and EMe() macros to map the enums to the strings
563 * that will be printed in the output.
567 #define EM(a, b) {a, b},
568 #define EMe(a, b) {a, b}
570 DECLARE_EVENT_CLASS(xs_socket_event,
573 struct rpc_xprt *xprt,
574 struct socket *socket
577 TP_ARGS(xprt, socket),
580 __field(unsigned int, socket_state)
581 __field(unsigned int, sock_state)
582 __field(unsigned long long, ino)
584 xprt->address_strings[RPC_DISPLAY_ADDR])
586 xprt->address_strings[RPC_DISPLAY_PORT])
590 struct inode *inode = SOCK_INODE(socket);
591 __entry->socket_state = socket->state;
592 __entry->sock_state = socket->sk->sk_state;
593 __entry->ino = (unsigned long long)inode->i_ino;
594 __assign_str(dstaddr,
595 xprt->address_strings[RPC_DISPLAY_ADDR]);
596 __assign_str(dstport,
597 xprt->address_strings[RPC_DISPLAY_PORT]);
601 "socket:[%llu] dstaddr=%s/%s "
602 "state=%u (%s) sk_state=%u (%s)",
603 __entry->ino, __get_str(dstaddr), __get_str(dstport),
604 __entry->socket_state,
605 rpc_show_socket_state(__entry->socket_state),
607 rpc_show_sock_state(__entry->sock_state)
610 #define DEFINE_RPC_SOCKET_EVENT(name) \
611 DEFINE_EVENT(xs_socket_event, name, \
613 struct rpc_xprt *xprt, \
614 struct socket *socket \
616 TP_ARGS(xprt, socket))
618 DECLARE_EVENT_CLASS(xs_socket_event_done,
621 struct rpc_xprt *xprt,
622 struct socket *socket,
626 TP_ARGS(xprt, socket, error),
630 __field(unsigned int, socket_state)
631 __field(unsigned int, sock_state)
632 __field(unsigned long long, ino)
634 xprt->address_strings[RPC_DISPLAY_ADDR])
636 xprt->address_strings[RPC_DISPLAY_PORT])
640 struct inode *inode = SOCK_INODE(socket);
641 __entry->socket_state = socket->state;
642 __entry->sock_state = socket->sk->sk_state;
643 __entry->ino = (unsigned long long)inode->i_ino;
644 __entry->error = error;
645 __assign_str(dstaddr,
646 xprt->address_strings[RPC_DISPLAY_ADDR]);
647 __assign_str(dstport,
648 xprt->address_strings[RPC_DISPLAY_PORT]);
652 "error=%d socket:[%llu] dstaddr=%s/%s "
653 "state=%u (%s) sk_state=%u (%s)",
655 __entry->ino, __get_str(dstaddr), __get_str(dstport),
656 __entry->socket_state,
657 rpc_show_socket_state(__entry->socket_state),
659 rpc_show_sock_state(__entry->sock_state)
662 #define DEFINE_RPC_SOCKET_EVENT_DONE(name) \
663 DEFINE_EVENT(xs_socket_event_done, name, \
665 struct rpc_xprt *xprt, \
666 struct socket *socket, \
669 TP_ARGS(xprt, socket, error))
671 DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change);
672 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect);
673 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error);
674 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
675 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
676 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
678 DECLARE_EVENT_CLASS(rpc_xprt_event,
680 const struct rpc_xprt *xprt,
685 TP_ARGS(xprt, xid, status),
690 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
691 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
695 __entry->xid = be32_to_cpu(xid);
696 __entry->status = status;
697 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
698 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
701 TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr),
702 __get_str(port), __entry->xid,
705 #define DEFINE_RPC_XPRT_EVENT(name) \
706 DEFINE_EVENT(rpc_xprt_event, xprt_##name, \
708 const struct rpc_xprt *xprt, \
712 TP_ARGS(xprt, xid, status))
714 DEFINE_RPC_XPRT_EVENT(timer);
715 DEFINE_RPC_XPRT_EVENT(lookup_rqst);
716 DEFINE_RPC_XPRT_EVENT(complete_rqst);
718 TRACE_EVENT(xprt_transmit,
720 const struct rpc_rqst *rqst,
724 TP_ARGS(rqst, status),
727 __field(unsigned int, task_id)
728 __field(unsigned int, client_id)
735 __entry->task_id = rqst->rq_task->tk_pid;
736 __entry->client_id = rqst->rq_task->tk_client ?
737 rqst->rq_task->tk_client->cl_clid : -1;
738 __entry->xid = be32_to_cpu(rqst->rq_xid);
739 __entry->seqno = rqst->rq_seqno;
740 __entry->status = status;
744 "task:%u@%u xid=0x%08x seqno=%u status=%d",
745 __entry->task_id, __entry->client_id, __entry->xid,
746 __entry->seqno, __entry->status)
749 TRACE_EVENT(xprt_enq_xmit,
751 const struct rpc_task *task,
755 TP_ARGS(task, stage),
758 __field(unsigned int, task_id)
759 __field(unsigned int, client_id)
766 __entry->task_id = task->tk_pid;
767 __entry->client_id = task->tk_client ?
768 task->tk_client->cl_clid : -1;
769 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
770 __entry->seqno = task->tk_rqstp->rq_seqno;
771 __entry->stage = stage;
775 "task:%u@%u xid=0x%08x seqno=%u stage=%d",
776 __entry->task_id, __entry->client_id, __entry->xid,
777 __entry->seqno, __entry->stage)
780 TRACE_EVENT(xprt_ping,
781 TP_PROTO(const struct rpc_xprt *xprt, int status),
783 TP_ARGS(xprt, status),
787 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
788 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
792 __entry->status = status;
793 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
794 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
797 TP_printk("peer=[%s]:%s status=%d",
798 __get_str(addr), __get_str(port), __entry->status)
801 DECLARE_EVENT_CLASS(xprt_writelock_event,
803 const struct rpc_xprt *xprt, const struct rpc_task *task
809 __field(unsigned int, task_id)
810 __field(unsigned int, client_id)
811 __field(unsigned int, snd_task_id)
816 __entry->task_id = task->tk_pid;
817 __entry->client_id = task->tk_client ?
818 task->tk_client->cl_clid : -1;
820 __entry->task_id = -1;
821 __entry->client_id = -1;
823 __entry->snd_task_id = xprt->snd_task ?
824 xprt->snd_task->tk_pid : -1;
827 TP_printk("task:%u@%u snd_task:%u",
828 __entry->task_id, __entry->client_id,
829 __entry->snd_task_id)
832 #define DEFINE_WRITELOCK_EVENT(name) \
833 DEFINE_EVENT(xprt_writelock_event, xprt_##name, \
835 const struct rpc_xprt *xprt, \
836 const struct rpc_task *task \
840 DEFINE_WRITELOCK_EVENT(reserve_xprt);
841 DEFINE_WRITELOCK_EVENT(release_xprt);
843 DECLARE_EVENT_CLASS(xprt_cong_event,
845 const struct rpc_xprt *xprt, const struct rpc_task *task
851 __field(unsigned int, task_id)
852 __field(unsigned int, client_id)
853 __field(unsigned int, snd_task_id)
854 __field(unsigned long, cong)
855 __field(unsigned long, cwnd)
861 __entry->task_id = task->tk_pid;
862 __entry->client_id = task->tk_client ?
863 task->tk_client->cl_clid : -1;
865 __entry->task_id = -1;
866 __entry->client_id = -1;
868 __entry->snd_task_id = xprt->snd_task ?
869 xprt->snd_task->tk_pid : -1;
870 __entry->cong = xprt->cong;
871 __entry->cwnd = xprt->cwnd;
872 __entry->wait = test_bit(XPRT_CWND_WAIT, &xprt->state);
875 TP_printk("task:%u@%u snd_task:%u cong=%lu cwnd=%lu%s",
876 __entry->task_id, __entry->client_id,
877 __entry->snd_task_id, __entry->cong, __entry->cwnd,
878 __entry->wait ? " (wait)" : "")
881 #define DEFINE_CONG_EVENT(name) \
882 DEFINE_EVENT(xprt_cong_event, xprt_##name, \
884 const struct rpc_xprt *xprt, \
885 const struct rpc_task *task \
889 DEFINE_CONG_EVENT(reserve_cong);
890 DEFINE_CONG_EVENT(release_cong);
891 DEFINE_CONG_EVENT(get_cong);
892 DEFINE_CONG_EVENT(put_cong);
894 TRACE_EVENT(xs_stream_read_data,
895 TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
897 TP_ARGS(xprt, err, total),
900 __field(ssize_t, err)
901 __field(size_t, total)
902 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] :
904 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] :
910 __entry->total = total;
911 __assign_str(addr, xprt ?
912 xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)");
913 __assign_str(port, xprt ?
914 xprt->address_strings[RPC_DISPLAY_PORT] : "(null)");
917 TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr),
918 __get_str(port), __entry->err, __entry->total)
921 TRACE_EVENT(xs_stream_read_request,
922 TP_PROTO(struct sock_xprt *xs),
927 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR])
928 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT])
930 __field(unsigned long, copied)
931 __field(unsigned int, reclen)
932 __field(unsigned int, offset)
936 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]);
937 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]);
938 __entry->xid = be32_to_cpu(xs->recv.xid);
939 __entry->copied = xs->recv.copied;
940 __entry->reclen = xs->recv.len;
941 __entry->offset = xs->recv.offset;
944 TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u",
945 __get_str(addr), __get_str(port), __entry->xid,
946 __entry->copied, __entry->reclen, __entry->offset)
949 #define show_rqstp_flags(flags) \
950 __print_flags(flags, "|", \
951 { (1UL << RQ_SECURE), "RQ_SECURE"}, \
952 { (1UL << RQ_LOCAL), "RQ_LOCAL"}, \
953 { (1UL << RQ_USEDEFERRAL), "RQ_USEDEFERRAL"}, \
954 { (1UL << RQ_DROPME), "RQ_DROPME"}, \
955 { (1UL << RQ_SPLICE_OK), "RQ_SPLICE_OK"}, \
956 { (1UL << RQ_VICTIM), "RQ_VICTIM"}, \
957 { (1UL << RQ_BUSY), "RQ_BUSY"})
959 TRACE_EVENT(svc_recv,
960 TP_PROTO(struct svc_rqst *rqst, int len),
967 __field(unsigned long, flags)
968 __string(addr, rqst->rq_xprt->xpt_remotebuf)
972 __entry->xid = be32_to_cpu(rqst->rq_xid);
974 __entry->flags = rqst->rq_flags;
975 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
978 TP_printk("addr=%s xid=0x%08x len=%d flags=%s",
979 __get_str(addr), __entry->xid, __entry->len,
980 show_rqstp_flags(__entry->flags))
983 #define svc_show_status(status) \
984 __print_symbolic(status, \
985 { SVC_GARBAGE, "SVC_GARBAGE" }, \
986 { SVC_SYSERR, "SVC_SYSERR" }, \
987 { SVC_VALID, "SVC_VALID" }, \
988 { SVC_NEGATIVE, "SVC_NEGATIVE" }, \
989 { SVC_OK, "SVC_OK" }, \
990 { SVC_DROP, "SVC_DROP" }, \
991 { SVC_CLOSE, "SVC_CLOSE" }, \
992 { SVC_DENIED, "SVC_DENIED" }, \
993 { SVC_PENDING, "SVC_PENDING" }, \
994 { SVC_COMPLETE, "SVC_COMPLETE" })
996 TRACE_EVENT(svc_authenticate,
997 TP_PROTO(const struct svc_rqst *rqst, int auth_res, __be32 auth_stat),
999 TP_ARGS(rqst, auth_res, auth_stat),
1003 __field(unsigned long, svc_status)
1004 __field(unsigned long, auth_stat)
1008 __entry->xid = be32_to_cpu(rqst->rq_xid);
1009 __entry->svc_status = auth_res;
1010 __entry->auth_stat = be32_to_cpu(auth_stat);
1013 TP_printk("xid=0x%08x auth_res=%s auth_stat=%s",
1014 __entry->xid, svc_show_status(__entry->svc_status),
1015 rpc_show_auth_stat(__entry->auth_stat))
1018 TRACE_EVENT(svc_process,
1019 TP_PROTO(const struct svc_rqst *rqst, const char *name),
1021 TP_ARGS(rqst, name),
1027 __string(service, name)
1028 __string(addr, rqst->rq_xprt ?
1029 rqst->rq_xprt->xpt_remotebuf : "(null)")
1033 __entry->xid = be32_to_cpu(rqst->rq_xid);
1034 __entry->vers = rqst->rq_vers;
1035 __entry->proc = rqst->rq_proc;
1036 __assign_str(service, name);
1037 __assign_str(addr, rqst->rq_xprt ?
1038 rqst->rq_xprt->xpt_remotebuf : "(null)");
1041 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%u",
1042 __get_str(addr), __entry->xid,
1043 __get_str(service), __entry->vers, __entry->proc)
1046 DECLARE_EVENT_CLASS(svc_rqst_event,
1049 const struct svc_rqst *rqst
1056 __field(unsigned long, flags)
1057 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1061 __entry->xid = be32_to_cpu(rqst->rq_xid);
1062 __entry->flags = rqst->rq_flags;
1063 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1066 TP_printk("addr=%s xid=0x%08x flags=%s",
1067 __get_str(addr), __entry->xid,
1068 show_rqstp_flags(__entry->flags))
1070 #define DEFINE_SVC_RQST_EVENT(name) \
1071 DEFINE_EVENT(svc_rqst_event, svc_##name, \
1073 const struct svc_rqst *rqst \
1077 DEFINE_SVC_RQST_EVENT(defer);
1078 DEFINE_SVC_RQST_EVENT(drop);
1080 DECLARE_EVENT_CLASS(svc_rqst_status,
1082 TP_PROTO(struct svc_rqst *rqst, int status),
1084 TP_ARGS(rqst, status),
1088 __field(int, status)
1089 __field(unsigned long, flags)
1090 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1094 __entry->xid = be32_to_cpu(rqst->rq_xid);
1095 __entry->status = status;
1096 __entry->flags = rqst->rq_flags;
1097 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1100 TP_printk("addr=%s xid=0x%08x status=%d flags=%s",
1101 __get_str(addr), __entry->xid,
1102 __entry->status, show_rqstp_flags(__entry->flags))
1105 DEFINE_EVENT(svc_rqst_status, svc_send,
1106 TP_PROTO(struct svc_rqst *rqst, int status),
1107 TP_ARGS(rqst, status));
1109 #define show_svc_xprt_flags(flags) \
1110 __print_flags(flags, "|", \
1111 { (1UL << XPT_BUSY), "XPT_BUSY"}, \
1112 { (1UL << XPT_CONN), "XPT_CONN"}, \
1113 { (1UL << XPT_CLOSE), "XPT_CLOSE"}, \
1114 { (1UL << XPT_DATA), "XPT_DATA"}, \
1115 { (1UL << XPT_TEMP), "XPT_TEMP"}, \
1116 { (1UL << XPT_DEAD), "XPT_DEAD"}, \
1117 { (1UL << XPT_CHNGBUF), "XPT_CHNGBUF"}, \
1118 { (1UL << XPT_DEFERRED), "XPT_DEFERRED"}, \
1119 { (1UL << XPT_OLD), "XPT_OLD"}, \
1120 { (1UL << XPT_LISTENER), "XPT_LISTENER"}, \
1121 { (1UL << XPT_CACHE_AUTH), "XPT_CACHE_AUTH"}, \
1122 { (1UL << XPT_LOCAL), "XPT_LOCAL"}, \
1123 { (1UL << XPT_KILL_TEMP), "XPT_KILL_TEMP"}, \
1124 { (1UL << XPT_CONG_CTRL), "XPT_CONG_CTRL"})
1126 TRACE_EVENT(svc_xprt_do_enqueue,
1127 TP_PROTO(struct svc_xprt *xprt, struct svc_rqst *rqst),
1129 TP_ARGS(xprt, rqst),
1132 __field(struct svc_xprt *, xprt)
1134 __field(unsigned long, flags)
1135 __string(addr, xprt->xpt_remotebuf)
1139 __entry->xprt = xprt;
1140 __entry->pid = rqst? rqst->rq_task->pid : 0;
1141 __entry->flags = xprt->xpt_flags;
1142 __assign_str(addr, xprt->xpt_remotebuf);
1145 TP_printk("xprt=%p addr=%s pid=%d flags=%s",
1146 __entry->xprt, __get_str(addr),
1147 __entry->pid, show_svc_xprt_flags(__entry->flags))
1150 DECLARE_EVENT_CLASS(svc_xprt_event,
1151 TP_PROTO(struct svc_xprt *xprt),
1156 __field(struct svc_xprt *, xprt)
1157 __field(unsigned long, flags)
1158 __string(addr, xprt->xpt_remotebuf)
1162 __entry->xprt = xprt;
1163 __entry->flags = xprt->xpt_flags;
1164 __assign_str(addr, xprt->xpt_remotebuf);
1167 TP_printk("xprt=%p addr=%s flags=%s",
1168 __entry->xprt, __get_str(addr),
1169 show_svc_xprt_flags(__entry->flags))
1172 DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space,
1173 TP_PROTO(struct svc_xprt *xprt),
1176 TRACE_EVENT(svc_xprt_dequeue,
1177 TP_PROTO(struct svc_rqst *rqst),
1182 __field(struct svc_xprt *, xprt)
1183 __field(unsigned long, flags)
1184 __field(unsigned long, wakeup)
1185 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1189 __entry->xprt = rqst->rq_xprt;
1190 __entry->flags = rqst->rq_xprt->xpt_flags;
1191 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(),
1193 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1196 TP_printk("xprt=%p addr=%s flags=%s wakeup-us=%lu",
1197 __entry->xprt, __get_str(addr),
1198 show_svc_xprt_flags(__entry->flags),
1202 TRACE_EVENT(svc_wake_up,
1215 TP_printk("pid=%d", __entry->pid)
1218 TRACE_EVENT(svc_handle_xprt,
1219 TP_PROTO(struct svc_xprt *xprt, int len),
1224 __field(struct svc_xprt *, xprt)
1226 __field(unsigned long, flags)
1227 __string(addr, xprt->xpt_remotebuf)
1231 __entry->xprt = xprt;
1233 __entry->flags = xprt->xpt_flags;
1234 __assign_str(addr, xprt->xpt_remotebuf);
1237 TP_printk("xprt=%p addr=%s len=%d flags=%s",
1238 __entry->xprt, __get_str(addr),
1239 __entry->len, show_svc_xprt_flags(__entry->flags))
1242 TRACE_EVENT(svc_stats_latency,
1243 TP_PROTO(const struct svc_rqst *rqst),
1249 __field(unsigned long, execute)
1250 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1254 __entry->xid = be32_to_cpu(rqst->rq_xid);
1255 __entry->execute = ktime_to_us(ktime_sub(ktime_get(),
1257 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1260 TP_printk("addr=%s xid=0x%08x execute-us=%lu",
1261 __get_str(addr), __entry->xid, __entry->execute)
1264 DECLARE_EVENT_CLASS(svc_deferred_event,
1266 const struct svc_deferred_req *dr
1273 __string(addr, dr->xprt->xpt_remotebuf)
1277 __entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
1278 (dr->xprt_hlen>>2)));
1279 __assign_str(addr, dr->xprt->xpt_remotebuf);
1282 TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
1284 #define DEFINE_SVC_DEFERRED_EVENT(name) \
1285 DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \
1287 const struct svc_deferred_req *dr \
1291 DEFINE_SVC_DEFERRED_EVENT(drop);
1292 DEFINE_SVC_DEFERRED_EVENT(revisit);
1294 #endif /* _TRACE_SUNRPC_H */
1296 #include <trace/define_trace.h>