include/trace/events/sunrpc.h

   1 /* SPDX-License-Identifier: GPL-2.0 */
   2 #undef TRACE_SYSTEM
   3 #define TRACE_SYSTEM sunrpc
   4
   5 #if !defined(_TRACE_SUNRPC_H) || defined(TRACE_HEADER_MULTI_READ)
   6 #define _TRACE_SUNRPC_H
   7
   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>
  16
  17 DECLARE_EVENT_CLASS(rpc_task_status,
  18
  19         TP_PROTO(const struct rpc_task *task),
  20
  21         TP_ARGS(task),
  22
  23         TP_STRUCT__entry(
  24                 __field(unsigned int, task_id)
  25                 __field(unsigned int, client_id)
  26                 __field(int, status)
  27         ),
  28
  29         TP_fast_assign(
  30                 __entry->task_id = task->tk_pid;
  31                 __entry->client_id = task->tk_client->cl_clid;
  32                 __entry->status = task->tk_status;
  33         ),
  34
  35         TP_printk("task:%u@%u status=%d",
  36                 __entry->task_id, __entry->client_id,
  37                 __entry->status)
  38 );
  39 #define DEFINE_RPC_STATUS_EVENT(name) \
  40         DEFINE_EVENT(rpc_task_status, rpc_##name##_status, \
  41                         TP_PROTO( \
  42                                 const struct rpc_task *task \
  43                         ), \
  44                         TP_ARGS(task))
  45
  46 DEFINE_RPC_STATUS_EVENT(call);
  47 DEFINE_RPC_STATUS_EVENT(bind);
  48 DEFINE_RPC_STATUS_EVENT(connect);
  49
  50 TRACE_EVENT(rpc_request,
  51         TP_PROTO(const struct rpc_task *task),
  52
  53         TP_ARGS(task),
  54
  55         TP_STRUCT__entry(
  56                 __field(unsigned int, task_id)
  57                 __field(unsigned int, client_id)
  58                 __field(int, version)
  59                 __field(bool, async)
  60                 __string(progname, task->tk_client->cl_program->name)
  61                 __string(procname, rpc_proc_name(task))
  62         ),
  63
  64         TP_fast_assign(
  65                 __entry->task_id = task->tk_pid;
  66                 __entry->client_id = task->tk_client->cl_clid;
  67                 __entry->version = task->tk_client->cl_vers;
  68                 __entry->async = RPC_IS_ASYNC(task);
  69                 __assign_str(progname, task->tk_client->cl_program->name)
  70                 __assign_str(procname, rpc_proc_name(task))
  71         ),
  72
  73         TP_printk("task:%u@%u %sv%d %s (%ssync)",
  74                 __entry->task_id, __entry->client_id,
  75                 __get_str(progname), __entry->version,
  76                 __get_str(procname), __entry->async ? "a": ""
  77                 )
  78 );
  79
  80 TRACE_DEFINE_ENUM(RPC_TASK_ASYNC);
  81 TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER);
  82 TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN);
  83 TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS);
  84 TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC);
  85 TRACE_DEFINE_ENUM(RPC_TASK_KILLED);
  86 TRACE_DEFINE_ENUM(RPC_TASK_SOFT);
  87 TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
  88 TRACE_DEFINE_ENUM(RPC_TASK_SENT);
  89 TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
  90 TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
  91 TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT);
  92
  93 #define rpc_show_task_flags(flags)                                      \
  94         __print_flags(flags, "|",                                       \
  95                 { RPC_TASK_ASYNC, "ASYNC" },                            \
  96                 { RPC_TASK_SWAPPER, "SWAPPER" },                        \
  97                 { RPC_CALL_MAJORSEEN, "MAJORSEEN" },                    \
  98                 { RPC_TASK_ROOTCREDS, "ROOTCREDS" },                    \
  99                 { RPC_TASK_DYNAMIC, "DYNAMIC" },                        \
 100                 { RPC_TASK_KILLED, "KILLED" },                          \
 101                 { RPC_TASK_SOFT, "SOFT" },                              \
 102                 { RPC_TASK_SOFTCONN, "SOFTCONN" },                      \
 103                 { RPC_TASK_SENT, "SENT" },                              \
 104                 { RPC_TASK_TIMEOUT, "TIMEOUT" },                        \
 105                 { RPC_TASK_NOCONNECT, "NOCONNECT" },                    \
 106                 { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" })
 107
 108 TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
 109 TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
 110 TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
 111 TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
 112 TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
 113 TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
 114
 115 #define rpc_show_runstate(flags)                                        \
 116         __print_flags(flags, "|",                                       \
 117                 { (1UL << RPC_TASK_RUNNING), "RUNNING" },               \
 118                 { (1UL << RPC_TASK_QUEUED), "QUEUED" },                 \
 119                 { (1UL << RPC_TASK_ACTIVE), "ACTIVE" },                 \
 120                 { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" },           \
 121                 { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" },           \
 122                 { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" })
 123
 124 DECLARE_EVENT_CLASS(rpc_task_running,
 125
 126         TP_PROTO(const struct rpc_task *task, const void *action),
 127
 128         TP_ARGS(task, action),
 129
 130         TP_STRUCT__entry(
 131                 __field(unsigned int, task_id)
 132                 __field(unsigned int, client_id)
 133                 __field(const void *, action)
 134                 __field(unsigned long, runstate)
 135                 __field(int, status)
 136                 __field(unsigned short, flags)
 137                 ),
 138
 139         TP_fast_assign(
 140                 __entry->client_id = task->tk_client ?
 141                                      task->tk_client->cl_clid : -1;
 142                 __entry->task_id = task->tk_pid;
 143                 __entry->action = action;
 144                 __entry->runstate = task->tk_runstate;
 145                 __entry->status = task->tk_status;
 146                 __entry->flags = task->tk_flags;
 147                 ),
 148
 149         TP_printk("task:%u@%d flags=%s runstate=%s status=%d action=%pf",
 150                 __entry->task_id, __entry->client_id,
 151                 rpc_show_task_flags(__entry->flags),
 152                 rpc_show_runstate(__entry->runstate),
 153                 __entry->status,
 154                 __entry->action
 155                 )
 156 );
 157 #define DEFINE_RPC_RUNNING_EVENT(name) \
 158         DEFINE_EVENT(rpc_task_running, rpc_task_##name, \
 159                         TP_PROTO( \
 160                                 const struct rpc_task *task, \
 161                                 const void *action \
 162                         ), \
 163                         TP_ARGS(task, action))
 164
 165 DEFINE_RPC_RUNNING_EVENT(begin);
 166 DEFINE_RPC_RUNNING_EVENT(run_action);
 167 DEFINE_RPC_RUNNING_EVENT(complete);
 168
 169 DECLARE_EVENT_CLASS(rpc_task_queued,
 170
 171         TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q),
 172
 173         TP_ARGS(task, q),
 174
 175         TP_STRUCT__entry(
 176                 __field(unsigned int, task_id)
 177                 __field(unsigned int, client_id)
 178                 __field(unsigned long, timeout)
 179                 __field(unsigned long, runstate)
 180                 __field(int, status)
 181                 __field(unsigned short, flags)
 182                 __string(q_name, rpc_qname(q))
 183                 ),
 184
 185         TP_fast_assign(
 186                 __entry->client_id = task->tk_client ?
 187                                      task->tk_client->cl_clid : -1;
 188                 __entry->task_id = task->tk_pid;
 189                 __entry->timeout = task->tk_timeout;
 190                 __entry->runstate = task->tk_runstate;
 191                 __entry->status = task->tk_status;
 192                 __entry->flags = task->tk_flags;
 193                 __assign_str(q_name, rpc_qname(q));
 194                 ),
 195
 196         TP_printk("task:%u@%d flags=%s runstate=%s status=%d timeout=%lu queue=%s",
 197                 __entry->task_id, __entry->client_id,
 198                 rpc_show_task_flags(__entry->flags),
 199                 rpc_show_runstate(__entry->runstate),
 200                 __entry->status,
 201                 __entry->timeout,
 202                 __get_str(q_name)
 203                 )
 204 );
 205 #define DEFINE_RPC_QUEUED_EVENT(name) \
 206         DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \
 207                         TP_PROTO( \
 208                                 const struct rpc_task *task, \
 209                                 const struct rpc_wait_queue *q \
 210                         ), \
 211                         TP_ARGS(task, q))
 212
 213 DEFINE_RPC_QUEUED_EVENT(sleep);
 214 DEFINE_RPC_QUEUED_EVENT(wakeup);
 215
 216 DECLARE_EVENT_CLASS(rpc_failure,
 217
 218         TP_PROTO(const struct rpc_task *task),
 219
 220         TP_ARGS(task),
 221
 222         TP_STRUCT__entry(
 223                 __field(unsigned int, task_id)
 224                 __field(unsigned int, client_id)
 225         ),
 226
 227         TP_fast_assign(
 228                 __entry->task_id = task->tk_pid;
 229                 __entry->client_id = task->tk_client->cl_clid;
 230         ),
 231
 232         TP_printk("task:%u@%u",
 233                 __entry->task_id, __entry->client_id)
 234 );
 235
 236 #define DEFINE_RPC_FAILURE(name)                                        \
 237         DEFINE_EVENT(rpc_failure, rpc_bad_##name,                       \
 238                         TP_PROTO(                                       \
 239                                 const struct rpc_task *task             \
 240                         ),                                              \
 241                         TP_ARGS(task))
 242
 243 DEFINE_RPC_FAILURE(callhdr);
 244 DEFINE_RPC_FAILURE(verifier);
 245
 246 DECLARE_EVENT_CLASS(rpc_reply_event,
 247
 248         TP_PROTO(
 249                 const struct rpc_task *task
 250         ),
 251
 252         TP_ARGS(task),
 253
 254         TP_STRUCT__entry(
 255                 __field(unsigned int, task_id)
 256                 __field(unsigned int, client_id)
 257                 __field(u32, xid)
 258                 __string(progname, task->tk_client->cl_program->name)
 259                 __field(u32, version)
 260                 __string(procname, rpc_proc_name(task))
 261                 __string(servername, task->tk_xprt->servername)
 262         ),
 263
 264         TP_fast_assign(
 265                 __entry->task_id = task->tk_pid;
 266                 __entry->client_id = task->tk_client->cl_clid;
 267                 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
 268                 __assign_str(progname, task->tk_client->cl_program->name)
 269                 __entry->version = task->tk_client->cl_vers;
 270                 __assign_str(procname, rpc_proc_name(task))
 271                 __assign_str(servername, task->tk_xprt->servername)
 272         ),
 273
 274         TP_printk("task:%u@%d server=%s xid=0x%08x %sv%d %s",
 275                 __entry->task_id, __entry->client_id, __get_str(servername),
 276                 __entry->xid, __get_str(progname), __entry->version,
 277                 __get_str(procname))
 278 )
 279
 280 #define DEFINE_RPC_REPLY_EVENT(name)                                    \
 281         DEFINE_EVENT(rpc_reply_event, rpc__##name,                      \
 282                         TP_PROTO(                                       \
 283                                 const struct rpc_task *task             \
 284                         ),                                              \
 285                         TP_ARGS(task))
 286
 287 DEFINE_RPC_REPLY_EVENT(prog_unavail);
 288 DEFINE_RPC_REPLY_EVENT(prog_mismatch);
 289 DEFINE_RPC_REPLY_EVENT(proc_unavail);
 290 DEFINE_RPC_REPLY_EVENT(garbage_args);
 291 DEFINE_RPC_REPLY_EVENT(unparsable);
 292 DEFINE_RPC_REPLY_EVENT(mismatch);
 293 DEFINE_RPC_REPLY_EVENT(stale_creds);
 294 DEFINE_RPC_REPLY_EVENT(bad_creds);
 295 DEFINE_RPC_REPLY_EVENT(auth_tooweak);
 296
 297 TRACE_EVENT(rpc_stats_latency,
 298
 299         TP_PROTO(
 300                 const struct rpc_task *task,
 301                 ktime_t backlog,
 302                 ktime_t rtt,
 303                 ktime_t execute
 304         ),
 305
 306         TP_ARGS(task, backlog, rtt, execute),
 307
 308         TP_STRUCT__entry(
 309                 __field(unsigned int, task_id)
 310                 __field(unsigned int, client_id)
 311                 __field(u32, xid)
 312                 __field(int, version)
 313                 __string(progname, task->tk_client->cl_program->name)
 314                 __string(procname, rpc_proc_name(task))
 315                 __field(unsigned long, backlog)
 316                 __field(unsigned long, rtt)
 317                 __field(unsigned long, execute)
 318         ),
 319
 320         TP_fast_assign(
 321                 __entry->client_id = task->tk_client->cl_clid;
 322                 __entry->task_id = task->tk_pid;
 323                 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
 324                 __entry->version = task->tk_client->cl_vers;
 325                 __assign_str(progname, task->tk_client->cl_program->name)
 326                 __assign_str(procname, rpc_proc_name(task))
 327                 __entry->backlog = ktime_to_us(backlog);
 328                 __entry->rtt = ktime_to_us(rtt);
 329                 __entry->execute = ktime_to_us(execute);
 330         ),
 331
 332         TP_printk("task:%u@%d xid=0x%08x %sv%d %s backlog=%lu rtt=%lu execute=%lu",
 333                 __entry->task_id, __entry->client_id, __entry->xid,
 334                 __get_str(progname), __entry->version, __get_str(procname),
 335                 __entry->backlog, __entry->rtt, __entry->execute)
 336 );
 337
 338 TRACE_EVENT(rpc_xdr_overflow,
 339         TP_PROTO(
 340                 const struct xdr_stream *xdr,
 341                 size_t requested
 342         ),
 343
 344         TP_ARGS(xdr, requested),
 345
 346         TP_STRUCT__entry(
 347                 __field(unsigned int, task_id)
 348                 __field(unsigned int, client_id)
 349                 __field(int, version)
 350                 __field(size_t, requested)
 351                 __field(const void *, end)
 352                 __field(const void *, p)
 353                 __field(const void *, head_base)
 354                 __field(size_t, head_len)
 355                 __field(const void *, tail_base)
 356                 __field(size_t, tail_len)
 357                 __field(unsigned int, page_len)
 358                 __field(unsigned int, len)
 359                 __string(progname,
 360                          xdr->rqst->rq_task->tk_client->cl_program->name)
 361                 __string(procedure,
 362                          xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
 363         ),
 364
 365         TP_fast_assign(
 366                 if (xdr->rqst) {
 367                         const struct rpc_task *task = xdr->rqst->rq_task;
 368
 369                         __entry->task_id = task->tk_pid;
 370                         __entry->client_id = task->tk_client->cl_clid;
 371                         __assign_str(progname,
 372                                      task->tk_client->cl_program->name)
 373                         __entry->version = task->tk_client->cl_vers;
 374                         __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
 375                 } else {
 376                         __entry->task_id = 0;
 377                         __entry->client_id = 0;
 378                         __assign_str(progname, "unknown")
 379                         __entry->version = 0;
 380                         __assign_str(procedure, "unknown")
 381                 }
 382                 __entry->requested = requested;
 383                 __entry->end = xdr->end;
 384                 __entry->p = xdr->p;
 385                 __entry->head_base = xdr->buf->head[0].iov_base,
 386                 __entry->head_len = xdr->buf->head[0].iov_len,
 387                 __entry->page_len = xdr->buf->page_len,
 388                 __entry->tail_base = xdr->buf->tail[0].iov_base,
 389                 __entry->tail_len = xdr->buf->tail[0].iov_len,
 390                 __entry->len = xdr->buf->len;
 391         ),
 392
 393         TP_printk(
 394                 "task:%u@%u %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
 395                 __entry->task_id, __entry->client_id,
 396                 __get_str(progname), __entry->version, __get_str(procedure),
 397                 __entry->requested, __entry->p, __entry->end,
 398                 __entry->head_base, __entry->head_len,
 399                 __entry->page_len,
 400                 __entry->tail_base, __entry->tail_len,
 401                 __entry->len
 402         )
 403 );
 404
 405 TRACE_EVENT(rpc_xdr_alignment,
 406         TP_PROTO(
 407                 const struct xdr_stream *xdr,
 408                 size_t offset,
 409                 unsigned int copied
 410         ),
 411
 412         TP_ARGS(xdr, offset, copied),
 413
 414         TP_STRUCT__entry(
 415                 __field(unsigned int, task_id)
 416                 __field(unsigned int, client_id)
 417                 __field(int, version)
 418                 __field(size_t, offset)
 419                 __field(unsigned int, copied)
 420                 __field(const void *, head_base)
 421                 __field(size_t, head_len)
 422                 __field(const void *, tail_base)
 423                 __field(size_t, tail_len)
 424                 __field(unsigned int, page_len)
 425                 __field(unsigned int, len)
 426                 __string(progname,
 427                          xdr->rqst->rq_task->tk_client->cl_program->name)
 428                 __string(procedure,
 429                          xdr->rqst->rq_task->tk_msg.rpc_proc->p_name)
 430         ),
 431
 432         TP_fast_assign(
 433                 const struct rpc_task *task = xdr->rqst->rq_task;
 434
 435                 __entry->task_id = task->tk_pid;
 436                 __entry->client_id = task->tk_client->cl_clid;
 437                 __assign_str(progname,
 438                              task->tk_client->cl_program->name)
 439                 __entry->version = task->tk_client->cl_vers;
 440                 __assign_str(procedure, task->tk_msg.rpc_proc->p_name)
 441
 442                 __entry->offset = offset;
 443                 __entry->copied = copied;
 444                 __entry->head_base = xdr->buf->head[0].iov_base,
 445                 __entry->head_len = xdr->buf->head[0].iov_len,
 446                 __entry->page_len = xdr->buf->page_len,
 447                 __entry->tail_base = xdr->buf->tail[0].iov_base,
 448                 __entry->tail_len = xdr->buf->tail[0].iov_len,
 449                 __entry->len = xdr->buf->len;
 450         ),
 451
 452         TP_printk(
 453                 "task:%u@%u %sv%d %s offset=%zu copied=%u xdr=[%p,%zu]/%u/[%p,%zu]/%u\n",
 454                 __entry->task_id, __entry->client_id,
 455                 __get_str(progname), __entry->version, __get_str(procedure),
 456                 __entry->offset, __entry->copied,
 457                 __entry->head_base, __entry->head_len,
 458                 __entry->page_len,
 459                 __entry->tail_base, __entry->tail_len,
 460                 __entry->len
 461         )
 462 );
 463
 464 /*
 465  * First define the enums in the below macros to be exported to userspace
 466  * via TRACE_DEFINE_ENUM().
 467  */
 468 #undef EM
 469 #undef EMe
 470 #define EM(a, b)        TRACE_DEFINE_ENUM(a);
 471 #define EMe(a, b)       TRACE_DEFINE_ENUM(a);
 472
 473 #define RPC_SHOW_SOCKET                         \
 474         EM( SS_FREE, "FREE" )                   \
 475         EM( SS_UNCONNECTED, "UNCONNECTED" )     \
 476         EM( SS_CONNECTING, "CONNECTING," )      \
 477         EM( SS_CONNECTED, "CONNECTED," )        \
 478         EMe(SS_DISCONNECTING, "DISCONNECTING" )
 479
 480 #define rpc_show_socket_state(state) \
 481         __print_symbolic(state, RPC_SHOW_SOCKET)
 482
 483 RPC_SHOW_SOCKET
 484
 485 #define RPC_SHOW_SOCK                           \
 486         EM( TCP_ESTABLISHED, "ESTABLISHED" )    \
 487         EM( TCP_SYN_SENT, "SYN_SENT" )          \
 488         EM( TCP_SYN_RECV, "SYN_RECV" )          \
 489         EM( TCP_FIN_WAIT1, "FIN_WAIT1" )        \
 490         EM( TCP_FIN_WAIT2, "FIN_WAIT2" )        \
 491         EM( TCP_TIME_WAIT, "TIME_WAIT" )        \
 492         EM( TCP_CLOSE, "CLOSE" )                \
 493         EM( TCP_CLOSE_WAIT, "CLOSE_WAIT" )      \
 494         EM( TCP_LAST_ACK, "LAST_ACK" )          \
 495         EM( TCP_LISTEN, "LISTEN" )              \
 496         EMe( TCP_CLOSING, "CLOSING" )
 497
 498 #define rpc_show_sock_state(state) \
 499         __print_symbolic(state, RPC_SHOW_SOCK)
 500
 501 RPC_SHOW_SOCK
 502
 503 /*
 504  * Now redefine the EM() and EMe() macros to map the enums to the strings
 505  * that will be printed in the output.
 506  */
 507 #undef EM
 508 #undef EMe
 509 #define EM(a, b)        {a, b},
 510 #define EMe(a, b)       {a, b}
 511
 512 DECLARE_EVENT_CLASS(xs_socket_event,
 513
 514                 TP_PROTO(
 515                         struct rpc_xprt *xprt,
 516                         struct socket *socket
 517                 ),
 518
 519                 TP_ARGS(xprt, socket),
 520
 521                 TP_STRUCT__entry(
 522                         __field(unsigned int, socket_state)
 523                         __field(unsigned int, sock_state)
 524                         __field(unsigned long long, ino)
 525                         __string(dstaddr,
 526                                 xprt->address_strings[RPC_DISPLAY_ADDR])
 527                         __string(dstport,
 528                                 xprt->address_strings[RPC_DISPLAY_PORT])
 529                 ),
 530
 531                 TP_fast_assign(
 532                         struct inode *inode = SOCK_INODE(socket);
 533                         __entry->socket_state = socket->state;
 534                         __entry->sock_state = socket->sk->sk_state;
 535                         __entry->ino = (unsigned long long)inode->i_ino;
 536                         __assign_str(dstaddr,
 537                                 xprt->address_strings[RPC_DISPLAY_ADDR]);
 538                         __assign_str(dstport,
 539                                 xprt->address_strings[RPC_DISPLAY_PORT]);
 540                 ),
 541
 542                 TP_printk(
 543                         "socket:[%llu] dstaddr=%s/%s "
 544                         "state=%u (%s) sk_state=%u (%s)",
 545                         __entry->ino, __get_str(dstaddr), __get_str(dstport),
 546                         __entry->socket_state,
 547                         rpc_show_socket_state(__entry->socket_state),
 548                         __entry->sock_state,
 549                         rpc_show_sock_state(__entry->sock_state)
 550                 )
 551 );
 552 #define DEFINE_RPC_SOCKET_EVENT(name) \
 553         DEFINE_EVENT(xs_socket_event, name, \
 554                         TP_PROTO( \
 555                                 struct rpc_xprt *xprt, \
 556                                 struct socket *socket \
 557                         ), \
 558                         TP_ARGS(xprt, socket))
 559
 560 DECLARE_EVENT_CLASS(xs_socket_event_done,
 561
 562                 TP_PROTO(
 563                         struct rpc_xprt *xprt,
 564                         struct socket *socket,
 565                         int error
 566                 ),
 567
 568                 TP_ARGS(xprt, socket, error),
 569
 570                 TP_STRUCT__entry(
 571                         __field(int, error)
 572                         __field(unsigned int, socket_state)
 573                         __field(unsigned int, sock_state)
 574                         __field(unsigned long long, ino)
 575                         __string(dstaddr,
 576                                 xprt->address_strings[RPC_DISPLAY_ADDR])
 577                         __string(dstport,
 578                                 xprt->address_strings[RPC_DISPLAY_PORT])
 579                 ),
 580
 581                 TP_fast_assign(
 582                         struct inode *inode = SOCK_INODE(socket);
 583                         __entry->socket_state = socket->state;
 584                         __entry->sock_state = socket->sk->sk_state;
 585                         __entry->ino = (unsigned long long)inode->i_ino;
 586                         __entry->error = error;
 587                         __assign_str(dstaddr,
 588                                 xprt->address_strings[RPC_DISPLAY_ADDR]);
 589                         __assign_str(dstport,
 590                                 xprt->address_strings[RPC_DISPLAY_PORT]);
 591                 ),
 592
 593                 TP_printk(
 594                         "error=%d socket:[%llu] dstaddr=%s/%s "
 595                         "state=%u (%s) sk_state=%u (%s)",
 596                         __entry->error,
 597                         __entry->ino, __get_str(dstaddr), __get_str(dstport),
 598                         __entry->socket_state,
 599                         rpc_show_socket_state(__entry->socket_state),
 600                         __entry->sock_state,
 601                         rpc_show_sock_state(__entry->sock_state)
 602                 )
 603 );
 604 #define DEFINE_RPC_SOCKET_EVENT_DONE(name) \
 605         DEFINE_EVENT(xs_socket_event_done, name, \
 606                         TP_PROTO( \
 607                                 struct rpc_xprt *xprt, \
 608                                 struct socket *socket, \
 609                                 int error \
 610                         ), \
 611                         TP_ARGS(xprt, socket, error))
 612
 613 DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change);
 614 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect);
 615 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error);
 616 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
 617 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
 618 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
 619
 620 DECLARE_EVENT_CLASS(rpc_xprt_event,
 621         TP_PROTO(
 622                 const struct rpc_xprt *xprt,
 623                 __be32 xid,
 624                 int status
 625         ),
 626
 627         TP_ARGS(xprt, xid, status),
 628
 629         TP_STRUCT__entry(
 630                 __field(u32, xid)
 631                 __field(int, status)
 632                 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
 633                 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
 634         ),
 635
 636         TP_fast_assign(
 637                 __entry->xid = be32_to_cpu(xid);
 638                 __entry->status = status;
 639                 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
 640                 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
 641         ),
 642
 643         TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr),
 644                         __get_str(port), __entry->xid,
 645                         __entry->status)
 646 );
 647 #define DEFINE_RPC_XPRT_EVENT(name) \
 648         DEFINE_EVENT(rpc_xprt_event, xprt_##name, \
 649                         TP_PROTO( \
 650                                 const struct rpc_xprt *xprt, \
 651                                 __be32 xid, \
 652                                 int status \
 653                         ), \
 654                         TP_ARGS(xprt, xid, status))
 655
 656 DEFINE_RPC_XPRT_EVENT(timer);
 657 DEFINE_RPC_XPRT_EVENT(lookup_rqst);
 658 DEFINE_RPC_XPRT_EVENT(transmit);
 659 DEFINE_RPC_XPRT_EVENT(complete_rqst);
 660
 661 TRACE_EVENT(xprt_ping,
 662         TP_PROTO(const struct rpc_xprt *xprt, int status),
 663
 664         TP_ARGS(xprt, status),
 665
 666         TP_STRUCT__entry(
 667                 __field(int, status)
 668                 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
 669                 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
 670         ),
 671
 672         TP_fast_assign(
 673                 __entry->status = status;
 674                 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
 675                 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
 676         ),
 677
 678         TP_printk("peer=[%s]:%s status=%d",
 679                         __get_str(addr), __get_str(port), __entry->status)
 680 );
 681
 682 TRACE_EVENT(xs_stream_read_data,
 683         TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
 684
 685         TP_ARGS(xprt, err, total),
 686
 687         TP_STRUCT__entry(
 688                 __field(ssize_t, err)
 689                 __field(size_t, total)
 690                 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] :
 691                                 "(null)")
 692                 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] :
 693                                 "(null)")
 694         ),
 695
 696         TP_fast_assign(
 697                 __entry->err = err;
 698                 __entry->total = total;
 699                 __assign_str(addr, xprt ?
 700                         xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)");
 701                 __assign_str(port, xprt ?
 702                         xprt->address_strings[RPC_DISPLAY_PORT] : "(null)");
 703         ),
 704
 705         TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr),
 706                         __get_str(port), __entry->err, __entry->total)
 707 );
 708
 709 TRACE_EVENT(xs_stream_read_request,
 710         TP_PROTO(struct sock_xprt *xs),
 711
 712         TP_ARGS(xs),
 713
 714         TP_STRUCT__entry(
 715                 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR])
 716                 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT])
 717                 __field(u32, xid)
 718                 __field(unsigned long, copied)
 719                 __field(unsigned int, reclen)
 720                 __field(unsigned int, offset)
 721         ),
 722
 723         TP_fast_assign(
 724                 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]);
 725                 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]);
 726                 __entry->xid = be32_to_cpu(xs->recv.xid);
 727                 __entry->copied = xs->recv.copied;
 728                 __entry->reclen = xs->recv.len;
 729                 __entry->offset = xs->recv.offset;
 730         ),
 731
 732         TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u",
 733                         __get_str(addr), __get_str(port), __entry->xid,
 734                         __entry->copied, __entry->reclen, __entry->offset)
 735 );
 736
 737 #define show_rqstp_flags(flags)                                         \
 738         __print_flags(flags, "|",                                       \
 739                 { (1UL << RQ_SECURE),           "RQ_SECURE"},           \
 740                 { (1UL << RQ_LOCAL),            "RQ_LOCAL"},            \
 741                 { (1UL << RQ_USEDEFERRAL),      "RQ_USEDEFERRAL"},      \
 742                 { (1UL << RQ_DROPME),           "RQ_DROPME"},           \
 743                 { (1UL << RQ_SPLICE_OK),        "RQ_SPLICE_OK"},        \
 744                 { (1UL << RQ_VICTIM),           "RQ_VICTIM"},           \
 745                 { (1UL << RQ_BUSY),             "RQ_BUSY"})
 746
 747 TRACE_EVENT(svc_recv,
 748         TP_PROTO(struct svc_rqst *rqst, int len),
 749
 750         TP_ARGS(rqst, len),
 751
 752         TP_STRUCT__entry(
 753                 __field(u32, xid)
 754                 __field(int, len)
 755                 __field(unsigned long, flags)
 756                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 757         ),
 758
 759         TP_fast_assign(
 760                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 761                 __entry->len = len;
 762                 __entry->flags = rqst->rq_flags;
 763                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 764         ),
 765
 766         TP_printk("addr=%s xid=0x%08x len=%d flags=%s",
 767                         __get_str(addr), __entry->xid, __entry->len,
 768                         show_rqstp_flags(__entry->flags))
 769 );
 770
 771 TRACE_EVENT(svc_process,
 772         TP_PROTO(const struct svc_rqst *rqst, const char *name),
 773
 774         TP_ARGS(rqst, name),
 775
 776         TP_STRUCT__entry(
 777                 __field(u32, xid)
 778                 __field(u32, vers)
 779                 __field(u32, proc)
 780                 __string(service, name)
 781                 __string(addr, rqst->rq_xprt ?
 782                          rqst->rq_xprt->xpt_remotebuf : "(null)")
 783         ),
 784
 785         TP_fast_assign(
 786                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 787                 __entry->vers = rqst->rq_vers;
 788                 __entry->proc = rqst->rq_proc;
 789                 __assign_str(service, name);
 790                 __assign_str(addr, rqst->rq_xprt ?
 791                              rqst->rq_xprt->xpt_remotebuf : "(null)");
 792         ),
 793
 794         TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%u",
 795                         __get_str(addr), __entry->xid,
 796                         __get_str(service), __entry->vers, __entry->proc)
 797 );
 798
 799 DECLARE_EVENT_CLASS(svc_rqst_event,
 800
 801         TP_PROTO(
 802                 const struct svc_rqst *rqst
 803         ),
 804
 805         TP_ARGS(rqst),
 806
 807         TP_STRUCT__entry(
 808                 __field(u32, xid)
 809                 __field(unsigned long, flags)
 810                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 811         ),
 812
 813         TP_fast_assign(
 814                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 815                 __entry->flags = rqst->rq_flags;
 816                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 817         ),
 818
 819         TP_printk("addr=%s xid=0x%08x flags=%s",
 820                         __get_str(addr), __entry->xid,
 821                         show_rqstp_flags(__entry->flags))
 822 );
 823 #define DEFINE_SVC_RQST_EVENT(name) \
 824         DEFINE_EVENT(svc_rqst_event, svc_##name, \
 825                         TP_PROTO( \
 826                                 const struct svc_rqst *rqst \
 827                         ), \
 828                         TP_ARGS(rqst))
 829
 830 DEFINE_SVC_RQST_EVENT(defer);
 831 DEFINE_SVC_RQST_EVENT(drop);
 832
 833 DECLARE_EVENT_CLASS(svc_rqst_status,
 834
 835         TP_PROTO(struct svc_rqst *rqst, int status),
 836
 837         TP_ARGS(rqst, status),
 838
 839         TP_STRUCT__entry(
 840                 __field(u32, xid)
 841                 __field(int, status)
 842                 __field(unsigned long, flags)
 843                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 844         ),
 845
 846         TP_fast_assign(
 847                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 848                 __entry->status = status;
 849                 __entry->flags = rqst->rq_flags;
 850                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 851         ),
 852
 853         TP_printk("addr=%s xid=0x%08x status=%d flags=%s",
 854                   __get_str(addr), __entry->xid,
 855                   __entry->status, show_rqstp_flags(__entry->flags))
 856 );
 857
 858 DEFINE_EVENT(svc_rqst_status, svc_send,
 859         TP_PROTO(struct svc_rqst *rqst, int status),
 860         TP_ARGS(rqst, status));
 861
 862 #define show_svc_xprt_flags(flags)                                      \
 863         __print_flags(flags, "|",                                       \
 864                 { (1UL << XPT_BUSY),            "XPT_BUSY"},            \
 865                 { (1UL << XPT_CONN),            "XPT_CONN"},            \
 866                 { (1UL << XPT_CLOSE),           "XPT_CLOSE"},           \
 867                 { (1UL << XPT_DATA),            "XPT_DATA"},            \
 868                 { (1UL << XPT_TEMP),            "XPT_TEMP"},            \
 869                 { (1UL << XPT_DEAD),            "XPT_DEAD"},            \
 870                 { (1UL << XPT_CHNGBUF),         "XPT_CHNGBUF"},         \
 871                 { (1UL << XPT_DEFERRED),        "XPT_DEFERRED"},        \
 872                 { (1UL << XPT_OLD),             "XPT_OLD"},             \
 873                 { (1UL << XPT_LISTENER),        "XPT_LISTENER"},        \
 874                 { (1UL << XPT_CACHE_AUTH),      "XPT_CACHE_AUTH"},      \
 875                 { (1UL << XPT_LOCAL),           "XPT_LOCAL"},           \
 876                 { (1UL << XPT_KILL_TEMP),       "XPT_KILL_TEMP"},       \
 877                 { (1UL << XPT_CONG_CTRL),       "XPT_CONG_CTRL"})
 878
 879 TRACE_EVENT(svc_xprt_do_enqueue,
 880         TP_PROTO(struct svc_xprt *xprt, struct svc_rqst *rqst),
 881
 882         TP_ARGS(xprt, rqst),
 883
 884         TP_STRUCT__entry(
 885                 __field(struct svc_xprt *, xprt)
 886                 __field(int, pid)
 887                 __field(unsigned long, flags)
 888                 __string(addr, xprt->xpt_remotebuf)
 889         ),
 890
 891         TP_fast_assign(
 892                 __entry->xprt = xprt;
 893                 __entry->pid = rqst? rqst->rq_task->pid : 0;
 894                 __entry->flags = xprt->xpt_flags;
 895                 __assign_str(addr, xprt->xpt_remotebuf);
 896         ),
 897
 898         TP_printk("xprt=%p addr=%s pid=%d flags=%s",
 899                         __entry->xprt, __get_str(addr),
 900                         __entry->pid, show_svc_xprt_flags(__entry->flags))
 901 );
 902
 903 DECLARE_EVENT_CLASS(svc_xprt_event,
 904         TP_PROTO(struct svc_xprt *xprt),
 905
 906         TP_ARGS(xprt),
 907
 908         TP_STRUCT__entry(
 909                 __field(struct svc_xprt *, xprt)
 910                 __field(unsigned long, flags)
 911                 __string(addr, xprt->xpt_remotebuf)
 912         ),
 913
 914         TP_fast_assign(
 915                 __entry->xprt = xprt;
 916                 __entry->flags = xprt->xpt_flags;
 917                 __assign_str(addr, xprt->xpt_remotebuf);
 918         ),
 919
 920         TP_printk("xprt=%p addr=%s flags=%s",
 921                         __entry->xprt, __get_str(addr),
 922                         show_svc_xprt_flags(__entry->flags))
 923 );
 924
 925 DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space,
 926         TP_PROTO(struct svc_xprt *xprt),
 927         TP_ARGS(xprt));
 928
 929 TRACE_EVENT(svc_xprt_dequeue,
 930         TP_PROTO(struct svc_rqst *rqst),
 931
 932         TP_ARGS(rqst),
 933
 934         TP_STRUCT__entry(
 935                 __field(struct svc_xprt *, xprt)
 936                 __field(unsigned long, flags)
 937                 __field(unsigned long, wakeup)
 938                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 939         ),
 940
 941         TP_fast_assign(
 942                 __entry->xprt = rqst->rq_xprt;
 943                 __entry->flags = rqst->rq_xprt->xpt_flags;
 944                 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(),
 945                                                         rqst->rq_qtime));
 946                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 947         ),
 948
 949         TP_printk("xprt=%p addr=%s flags=%s wakeup-us=%lu",
 950                         __entry->xprt, __get_str(addr),
 951                         show_svc_xprt_flags(__entry->flags),
 952                         __entry->wakeup)
 953 );
 954
 955 TRACE_EVENT(svc_wake_up,
 956         TP_PROTO(int pid),
 957
 958         TP_ARGS(pid),
 959
 960         TP_STRUCT__entry(
 961                 __field(int, pid)
 962         ),
 963
 964         TP_fast_assign(
 965                 __entry->pid = pid;
 966         ),
 967
 968         TP_printk("pid=%d", __entry->pid)
 969 );
 970
 971 TRACE_EVENT(svc_handle_xprt,
 972         TP_PROTO(struct svc_xprt *xprt, int len),
 973
 974         TP_ARGS(xprt, len),
 975
 976         TP_STRUCT__entry(
 977                 __field(struct svc_xprt *, xprt)
 978                 __field(int, len)
 979                 __field(unsigned long, flags)
 980                 __string(addr, xprt->xpt_remotebuf)
 981         ),
 982
 983         TP_fast_assign(
 984                 __entry->xprt = xprt;
 985                 __entry->len = len;
 986                 __entry->flags = xprt->xpt_flags;
 987                 __assign_str(addr, xprt->xpt_remotebuf);
 988         ),
 989
 990         TP_printk("xprt=%p addr=%s len=%d flags=%s",
 991                 __entry->xprt, __get_str(addr),
 992                 __entry->len, show_svc_xprt_flags(__entry->flags))
 993 );
 994
 995 TRACE_EVENT(svc_stats_latency,
 996         TP_PROTO(const struct svc_rqst *rqst),
 997
 998         TP_ARGS(rqst),
 999
1000         TP_STRUCT__entry(
1001                 __field(u32, xid)
1002                 __field(unsigned long, execute)
1003                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1004         ),
1005
1006         TP_fast_assign(
1007                 __entry->xid = be32_to_cpu(rqst->rq_xid);
1008                 __entry->execute = ktime_to_us(ktime_sub(ktime_get(),
1009                                                          rqst->rq_stime));
1010                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1011         ),
1012
1013         TP_printk("addr=%s xid=0x%08x execute-us=%lu",
1014                 __get_str(addr), __entry->xid, __entry->execute)
1015 );
1016
1017 DECLARE_EVENT_CLASS(svc_deferred_event,
1018         TP_PROTO(
1019                 const struct svc_deferred_req *dr
1020         ),
1021
1022         TP_ARGS(dr),
1023
1024         TP_STRUCT__entry(
1025                 __field(u32, xid)
1026                 __string(addr, dr->xprt->xpt_remotebuf)
1027         ),
1028
1029         TP_fast_assign(
1030                 __entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
1031                                                        (dr->xprt_hlen>>2)));
1032                 __assign_str(addr, dr->xprt->xpt_remotebuf);
1033         ),
1034
1035         TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
1036 );
1037 #define DEFINE_SVC_DEFERRED_EVENT(name) \
1038         DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \
1039                         TP_PROTO( \
1040                                 const struct svc_deferred_req *dr \
1041                         ), \
1042                         TP_ARGS(dr))
1043
1044 DEFINE_SVC_DEFERRED_EVENT(drop);
1045 DEFINE_SVC_DEFERRED_EVENT(revisit);
1046
1047 #endif /* _TRACE_SUNRPC_H */
1048
1049 #include <trace/define_trace.h>