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(complete_rqst);
 659
 660 TRACE_EVENT(xprt_transmit,
 661         TP_PROTO(
 662                 const struct rpc_rqst *rqst,
 663                 int status
 664         ),
 665
 666         TP_ARGS(rqst, status),
 667
 668         TP_STRUCT__entry(
 669                 __field(unsigned int, task_id)
 670                 __field(unsigned int, client_id)
 671                 __field(u32, xid)
 672                 __field(u32, seqno)
 673                 __field(int, status)
 674         ),
 675
 676         TP_fast_assign(
 677                 __entry->task_id = rqst->rq_task->tk_pid;
 678                 __entry->client_id = rqst->rq_task->tk_client->cl_clid;
 679                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 680                 __entry->seqno = rqst->rq_seqno;
 681                 __entry->status = status;
 682         ),
 683
 684         TP_printk(
 685                 "task:%u@%u xid=0x%08x seqno=%u status=%d",
 686                 __entry->task_id, __entry->client_id, __entry->xid,
 687                 __entry->seqno, __entry->status)
 688 );
 689
 690 TRACE_EVENT(xprt_enq_xmit,
 691         TP_PROTO(
 692                 const struct rpc_task *task,
 693                 int stage
 694         ),
 695
 696         TP_ARGS(task, stage),
 697
 698         TP_STRUCT__entry(
 699                 __field(unsigned int, task_id)
 700                 __field(unsigned int, client_id)
 701                 __field(u32, xid)
 702                 __field(u32, seqno)
 703                 __field(int, stage)
 704         ),
 705
 706         TP_fast_assign(
 707                 __entry->task_id = task->tk_pid;
 708                 __entry->client_id = task->tk_client->cl_clid;
 709                 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
 710                 __entry->seqno = task->tk_rqstp->rq_seqno;
 711                 __entry->stage = stage;
 712         ),
 713
 714         TP_printk(
 715                 "task:%u@%u xid=0x%08x seqno=%u stage=%d",
 716                 __entry->task_id, __entry->client_id, __entry->xid,
 717                 __entry->seqno, __entry->stage)
 718 );
 719
 720 TRACE_EVENT(xprt_ping,
 721         TP_PROTO(const struct rpc_xprt *xprt, int status),
 722
 723         TP_ARGS(xprt, status),
 724
 725         TP_STRUCT__entry(
 726                 __field(int, status)
 727                 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
 728                 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
 729         ),
 730
 731         TP_fast_assign(
 732                 __entry->status = status;
 733                 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
 734                 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
 735         ),
 736
 737         TP_printk("peer=[%s]:%s status=%d",
 738                         __get_str(addr), __get_str(port), __entry->status)
 739 );
 740
 741 TRACE_EVENT(xs_stream_read_data,
 742         TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
 743
 744         TP_ARGS(xprt, err, total),
 745
 746         TP_STRUCT__entry(
 747                 __field(ssize_t, err)
 748                 __field(size_t, total)
 749                 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] :
 750                                 "(null)")
 751                 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] :
 752                                 "(null)")
 753         ),
 754
 755         TP_fast_assign(
 756                 __entry->err = err;
 757                 __entry->total = total;
 758                 __assign_str(addr, xprt ?
 759                         xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)");
 760                 __assign_str(port, xprt ?
 761                         xprt->address_strings[RPC_DISPLAY_PORT] : "(null)");
 762         ),
 763
 764         TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr),
 765                         __get_str(port), __entry->err, __entry->total)
 766 );
 767
 768 TRACE_EVENT(xs_stream_read_request,
 769         TP_PROTO(struct sock_xprt *xs),
 770
 771         TP_ARGS(xs),
 772
 773         TP_STRUCT__entry(
 774                 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR])
 775                 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT])
 776                 __field(u32, xid)
 777                 __field(unsigned long, copied)
 778                 __field(unsigned int, reclen)
 779                 __field(unsigned int, offset)
 780         ),
 781
 782         TP_fast_assign(
 783                 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]);
 784                 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]);
 785                 __entry->xid = be32_to_cpu(xs->recv.xid);
 786                 __entry->copied = xs->recv.copied;
 787                 __entry->reclen = xs->recv.len;
 788                 __entry->offset = xs->recv.offset;
 789         ),
 790
 791         TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u",
 792                         __get_str(addr), __get_str(port), __entry->xid,
 793                         __entry->copied, __entry->reclen, __entry->offset)
 794 );
 795
 796 #define show_rqstp_flags(flags)                                         \
 797         __print_flags(flags, "|",                                       \
 798                 { (1UL << RQ_SECURE),           "RQ_SECURE"},           \
 799                 { (1UL << RQ_LOCAL),            "RQ_LOCAL"},            \
 800                 { (1UL << RQ_USEDEFERRAL),      "RQ_USEDEFERRAL"},      \
 801                 { (1UL << RQ_DROPME),           "RQ_DROPME"},           \
 802                 { (1UL << RQ_SPLICE_OK),        "RQ_SPLICE_OK"},        \
 803                 { (1UL << RQ_VICTIM),           "RQ_VICTIM"},           \
 804                 { (1UL << RQ_BUSY),             "RQ_BUSY"})
 805
 806 TRACE_EVENT(svc_recv,
 807         TP_PROTO(struct svc_rqst *rqst, int len),
 808
 809         TP_ARGS(rqst, len),
 810
 811         TP_STRUCT__entry(
 812                 __field(u32, xid)
 813                 __field(int, len)
 814                 __field(unsigned long, flags)
 815                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 816         ),
 817
 818         TP_fast_assign(
 819                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 820                 __entry->len = len;
 821                 __entry->flags = rqst->rq_flags;
 822                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 823         ),
 824
 825         TP_printk("addr=%s xid=0x%08x len=%d flags=%s",
 826                         __get_str(addr), __entry->xid, __entry->len,
 827                         show_rqstp_flags(__entry->flags))
 828 );
 829
 830 TRACE_EVENT(svc_process,
 831         TP_PROTO(const struct svc_rqst *rqst, const char *name),
 832
 833         TP_ARGS(rqst, name),
 834
 835         TP_STRUCT__entry(
 836                 __field(u32, xid)
 837                 __field(u32, vers)
 838                 __field(u32, proc)
 839                 __string(service, name)
 840                 __string(addr, rqst->rq_xprt ?
 841                          rqst->rq_xprt->xpt_remotebuf : "(null)")
 842         ),
 843
 844         TP_fast_assign(
 845                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 846                 __entry->vers = rqst->rq_vers;
 847                 __entry->proc = rqst->rq_proc;
 848                 __assign_str(service, name);
 849                 __assign_str(addr, rqst->rq_xprt ?
 850                              rqst->rq_xprt->xpt_remotebuf : "(null)");
 851         ),
 852
 853         TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%u",
 854                         __get_str(addr), __entry->xid,
 855                         __get_str(service), __entry->vers, __entry->proc)
 856 );
 857
 858 DECLARE_EVENT_CLASS(svc_rqst_event,
 859
 860         TP_PROTO(
 861                 const struct svc_rqst *rqst
 862         ),
 863
 864         TP_ARGS(rqst),
 865
 866         TP_STRUCT__entry(
 867                 __field(u32, xid)
 868                 __field(unsigned long, flags)
 869                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 870         ),
 871
 872         TP_fast_assign(
 873                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 874                 __entry->flags = rqst->rq_flags;
 875                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 876         ),
 877
 878         TP_printk("addr=%s xid=0x%08x flags=%s",
 879                         __get_str(addr), __entry->xid,
 880                         show_rqstp_flags(__entry->flags))
 881 );
 882 #define DEFINE_SVC_RQST_EVENT(name) \
 883         DEFINE_EVENT(svc_rqst_event, svc_##name, \
 884                         TP_PROTO( \
 885                                 const struct svc_rqst *rqst \
 886                         ), \
 887                         TP_ARGS(rqst))
 888
 889 DEFINE_SVC_RQST_EVENT(defer);
 890 DEFINE_SVC_RQST_EVENT(drop);
 891
 892 DECLARE_EVENT_CLASS(svc_rqst_status,
 893
 894         TP_PROTO(struct svc_rqst *rqst, int status),
 895
 896         TP_ARGS(rqst, status),
 897
 898         TP_STRUCT__entry(
 899                 __field(u32, xid)
 900                 __field(int, status)
 901                 __field(unsigned long, flags)
 902                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 903         ),
 904
 905         TP_fast_assign(
 906                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 907                 __entry->status = status;
 908                 __entry->flags = rqst->rq_flags;
 909                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 910         ),
 911
 912         TP_printk("addr=%s xid=0x%08x status=%d flags=%s",
 913                   __get_str(addr), __entry->xid,
 914                   __entry->status, show_rqstp_flags(__entry->flags))
 915 );
 916
 917 DEFINE_EVENT(svc_rqst_status, svc_send,
 918         TP_PROTO(struct svc_rqst *rqst, int status),
 919         TP_ARGS(rqst, status));
 920
 921 #define show_svc_xprt_flags(flags)                                      \
 922         __print_flags(flags, "|",                                       \
 923                 { (1UL << XPT_BUSY),            "XPT_BUSY"},            \
 924                 { (1UL << XPT_CONN),            "XPT_CONN"},            \
 925                 { (1UL << XPT_CLOSE),           "XPT_CLOSE"},           \
 926                 { (1UL << XPT_DATA),            "XPT_DATA"},            \
 927                 { (1UL << XPT_TEMP),            "XPT_TEMP"},            \
 928                 { (1UL << XPT_DEAD),            "XPT_DEAD"},            \
 929                 { (1UL << XPT_CHNGBUF),         "XPT_CHNGBUF"},         \
 930                 { (1UL << XPT_DEFERRED),        "XPT_DEFERRED"},        \
 931                 { (1UL << XPT_OLD),             "XPT_OLD"},             \
 932                 { (1UL << XPT_LISTENER),        "XPT_LISTENER"},        \
 933                 { (1UL << XPT_CACHE_AUTH),      "XPT_CACHE_AUTH"},      \
 934                 { (1UL << XPT_LOCAL),           "XPT_LOCAL"},           \
 935                 { (1UL << XPT_KILL_TEMP),       "XPT_KILL_TEMP"},       \
 936                 { (1UL << XPT_CONG_CTRL),       "XPT_CONG_CTRL"})
 937
 938 TRACE_EVENT(svc_xprt_do_enqueue,
 939         TP_PROTO(struct svc_xprt *xprt, struct svc_rqst *rqst),
 940
 941         TP_ARGS(xprt, rqst),
 942
 943         TP_STRUCT__entry(
 944                 __field(struct svc_xprt *, xprt)
 945                 __field(int, pid)
 946                 __field(unsigned long, flags)
 947                 __string(addr, xprt->xpt_remotebuf)
 948         ),
 949
 950         TP_fast_assign(
 951                 __entry->xprt = xprt;
 952                 __entry->pid = rqst? rqst->rq_task->pid : 0;
 953                 __entry->flags = xprt->xpt_flags;
 954                 __assign_str(addr, xprt->xpt_remotebuf);
 955         ),
 956
 957         TP_printk("xprt=%p addr=%s pid=%d flags=%s",
 958                         __entry->xprt, __get_str(addr),
 959                         __entry->pid, show_svc_xprt_flags(__entry->flags))
 960 );
 961
 962 DECLARE_EVENT_CLASS(svc_xprt_event,
 963         TP_PROTO(struct svc_xprt *xprt),
 964
 965         TP_ARGS(xprt),
 966
 967         TP_STRUCT__entry(
 968                 __field(struct svc_xprt *, xprt)
 969                 __field(unsigned long, flags)
 970                 __string(addr, xprt->xpt_remotebuf)
 971         ),
 972
 973         TP_fast_assign(
 974                 __entry->xprt = xprt;
 975                 __entry->flags = xprt->xpt_flags;
 976                 __assign_str(addr, xprt->xpt_remotebuf);
 977         ),
 978
 979         TP_printk("xprt=%p addr=%s flags=%s",
 980                         __entry->xprt, __get_str(addr),
 981                         show_svc_xprt_flags(__entry->flags))
 982 );
 983
 984 DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space,
 985         TP_PROTO(struct svc_xprt *xprt),
 986         TP_ARGS(xprt));
 987
 988 TRACE_EVENT(svc_xprt_dequeue,
 989         TP_PROTO(struct svc_rqst *rqst),
 990
 991         TP_ARGS(rqst),
 992
 993         TP_STRUCT__entry(
 994                 __field(struct svc_xprt *, xprt)
 995                 __field(unsigned long, flags)
 996                 __field(unsigned long, wakeup)
 997                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 998         ),
 999
1000         TP_fast_assign(
1001                 __entry->xprt = rqst->rq_xprt;
1002                 __entry->flags = rqst->rq_xprt->xpt_flags;
1003                 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(),
1004                                                         rqst->rq_qtime));
1005                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1006         ),
1007
1008         TP_printk("xprt=%p addr=%s flags=%s wakeup-us=%lu",
1009                         __entry->xprt, __get_str(addr),
1010                         show_svc_xprt_flags(__entry->flags),
1011                         __entry->wakeup)
1012 );
1013
1014 TRACE_EVENT(svc_wake_up,
1015         TP_PROTO(int pid),
1016
1017         TP_ARGS(pid),
1018
1019         TP_STRUCT__entry(
1020                 __field(int, pid)
1021         ),
1022
1023         TP_fast_assign(
1024                 __entry->pid = pid;
1025         ),
1026
1027         TP_printk("pid=%d", __entry->pid)
1028 );
1029
1030 TRACE_EVENT(svc_handle_xprt,
1031         TP_PROTO(struct svc_xprt *xprt, int len),
1032
1033         TP_ARGS(xprt, len),
1034
1035         TP_STRUCT__entry(
1036                 __field(struct svc_xprt *, xprt)
1037                 __field(int, len)
1038                 __field(unsigned long, flags)
1039                 __string(addr, xprt->xpt_remotebuf)
1040         ),
1041
1042         TP_fast_assign(
1043                 __entry->xprt = xprt;
1044                 __entry->len = len;
1045                 __entry->flags = xprt->xpt_flags;
1046                 __assign_str(addr, xprt->xpt_remotebuf);
1047         ),
1048
1049         TP_printk("xprt=%p addr=%s len=%d flags=%s",
1050                 __entry->xprt, __get_str(addr),
1051                 __entry->len, show_svc_xprt_flags(__entry->flags))
1052 );
1053
1054 TRACE_EVENT(svc_stats_latency,
1055         TP_PROTO(const struct svc_rqst *rqst),
1056
1057         TP_ARGS(rqst),
1058
1059         TP_STRUCT__entry(
1060                 __field(u32, xid)
1061                 __field(unsigned long, execute)
1062                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1063         ),
1064
1065         TP_fast_assign(
1066                 __entry->xid = be32_to_cpu(rqst->rq_xid);
1067                 __entry->execute = ktime_to_us(ktime_sub(ktime_get(),
1068                                                          rqst->rq_stime));
1069                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1070         ),
1071
1072         TP_printk("addr=%s xid=0x%08x execute-us=%lu",
1073                 __get_str(addr), __entry->xid, __entry->execute)
1074 );
1075
1076 DECLARE_EVENT_CLASS(svc_deferred_event,
1077         TP_PROTO(
1078                 const struct svc_deferred_req *dr
1079         ),
1080
1081         TP_ARGS(dr),
1082
1083         TP_STRUCT__entry(
1084                 __field(u32, xid)
1085                 __string(addr, dr->xprt->xpt_remotebuf)
1086         ),
1087
1088         TP_fast_assign(
1089                 __entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
1090                                                        (dr->xprt_hlen>>2)));
1091                 __assign_str(addr, dr->xprt->xpt_remotebuf);
1092         ),
1093
1094         TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
1095 );
1096 #define DEFINE_SVC_DEFERRED_EVENT(name) \
1097         DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \
1098                         TP_PROTO( \
1099                                 const struct svc_deferred_req *dr \
1100                         ), \
1101                         TP_ARGS(dr))
1102
1103 DEFINE_SVC_DEFERRED_EVENT(drop);
1104 DEFINE_SVC_DEFERRED_EVENT(revisit);
1105
1106 #endif /* _TRACE_SUNRPC_H */
1107
1108 #include <trace/define_trace.h>