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_SOFT);
  86 TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
  87 TRACE_DEFINE_ENUM(RPC_TASK_SENT);
  88 TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
  89 TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
  90 TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT);
  91
  92 #define rpc_show_task_flags(flags)                                      \
  93         __print_flags(flags, "|",                                       \
  94                 { RPC_TASK_ASYNC, "ASYNC" },                            \
  95                 { RPC_TASK_SWAPPER, "SWAPPER" },                        \
  96                 { RPC_CALL_MAJORSEEN, "MAJORSEEN" },                    \
  97                 { RPC_TASK_ROOTCREDS, "ROOTCREDS" },                    \
  98                 { RPC_TASK_DYNAMIC, "DYNAMIC" },                        \
  99                 { RPC_TASK_SOFT, "SOFT" },                              \
 100                 { RPC_TASK_SOFTCONN, "SOFTCONN" },                      \
 101                 { RPC_TASK_SENT, "SENT" },                              \
 102                 { RPC_TASK_TIMEOUT, "TIMEOUT" },                        \
 103                 { RPC_TASK_NOCONNECT, "NOCONNECT" },                    \
 104                 { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" })
 105
 106 TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
 107 TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
 108 TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
 109 TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
 110 TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
 111 TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
 112 TRACE_DEFINE_ENUM(RPC_TASK_SIGNALLED);
 113
 114 #define rpc_show_runstate(flags)                                        \
 115         __print_flags(flags, "|",                                       \
 116                 { (1UL << RPC_TASK_RUNNING), "RUNNING" },               \
 117                 { (1UL << RPC_TASK_QUEUED), "QUEUED" },                 \
 118                 { (1UL << RPC_TASK_ACTIVE), "ACTIVE" },                 \
 119                 { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" },           \
 120                 { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" },           \
 121                 { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" },     \
 122                 { (1UL << RPC_TASK_SIGNALLED), "SIGNALLED" })
 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=%ps",
 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 = rpc_task_timeout(task);
 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 TRACE_EVENT(rpc_reply_pages,
 465         TP_PROTO(
 466                 const struct rpc_rqst *req
 467         ),
 468
 469         TP_ARGS(req),
 470
 471         TP_STRUCT__entry(
 472                 __field(unsigned int, task_id)
 473                 __field(unsigned int, client_id)
 474                 __field(const void *, head_base)
 475                 __field(size_t, head_len)
 476                 __field(const void *, tail_base)
 477                 __field(size_t, tail_len)
 478                 __field(unsigned int, page_len)
 479         ),
 480
 481         TP_fast_assign(
 482                 __entry->task_id = req->rq_task->tk_pid;
 483                 __entry->client_id = req->rq_task->tk_client->cl_clid;
 484
 485                 __entry->head_base = req->rq_rcv_buf.head[0].iov_base;
 486                 __entry->head_len = req->rq_rcv_buf.head[0].iov_len;
 487                 __entry->page_len = req->rq_rcv_buf.page_len;
 488                 __entry->tail_base = req->rq_rcv_buf.tail[0].iov_base;
 489                 __entry->tail_len = req->rq_rcv_buf.tail[0].iov_len;
 490         ),
 491
 492         TP_printk(
 493                 "task:%u@%u xdr=[%p,%zu]/%u/[%p,%zu]\n",
 494                 __entry->task_id, __entry->client_id,
 495                 __entry->head_base, __entry->head_len,
 496                 __entry->page_len,
 497                 __entry->tail_base, __entry->tail_len
 498         )
 499 );
 500
 501 /*
 502  * First define the enums in the below macros to be exported to userspace
 503  * via TRACE_DEFINE_ENUM().
 504  */
 505 #undef EM
 506 #undef EMe
 507 #define EM(a, b)        TRACE_DEFINE_ENUM(a);
 508 #define EMe(a, b)       TRACE_DEFINE_ENUM(a);
 509
 510 #define RPC_SHOW_SOCKET                         \
 511         EM( SS_FREE, "FREE" )                   \
 512         EM( SS_UNCONNECTED, "UNCONNECTED" )     \
 513         EM( SS_CONNECTING, "CONNECTING," )      \
 514         EM( SS_CONNECTED, "CONNECTED," )        \
 515         EMe(SS_DISCONNECTING, "DISCONNECTING" )
 516
 517 #define rpc_show_socket_state(state) \
 518         __print_symbolic(state, RPC_SHOW_SOCKET)
 519
 520 RPC_SHOW_SOCKET
 521
 522 #define RPC_SHOW_SOCK                           \
 523         EM( TCP_ESTABLISHED, "ESTABLISHED" )    \
 524         EM( TCP_SYN_SENT, "SYN_SENT" )          \
 525         EM( TCP_SYN_RECV, "SYN_RECV" )          \
 526         EM( TCP_FIN_WAIT1, "FIN_WAIT1" )        \
 527         EM( TCP_FIN_WAIT2, "FIN_WAIT2" )        \
 528         EM( TCP_TIME_WAIT, "TIME_WAIT" )        \
 529         EM( TCP_CLOSE, "CLOSE" )                \
 530         EM( TCP_CLOSE_WAIT, "CLOSE_WAIT" )      \
 531         EM( TCP_LAST_ACK, "LAST_ACK" )          \
 532         EM( TCP_LISTEN, "LISTEN" )              \
 533         EMe( TCP_CLOSING, "CLOSING" )
 534
 535 #define rpc_show_sock_state(state) \
 536         __print_symbolic(state, RPC_SHOW_SOCK)
 537
 538 RPC_SHOW_SOCK
 539
 540 /*
 541  * Now redefine the EM() and EMe() macros to map the enums to the strings
 542  * that will be printed in the output.
 543  */
 544 #undef EM
 545 #undef EMe
 546 #define EM(a, b)        {a, b},
 547 #define EMe(a, b)       {a, b}
 548
 549 DECLARE_EVENT_CLASS(xs_socket_event,
 550
 551                 TP_PROTO(
 552                         struct rpc_xprt *xprt,
 553                         struct socket *socket
 554                 ),
 555
 556                 TP_ARGS(xprt, socket),
 557
 558                 TP_STRUCT__entry(
 559                         __field(unsigned int, socket_state)
 560                         __field(unsigned int, sock_state)
 561                         __field(unsigned long long, ino)
 562                         __string(dstaddr,
 563                                 xprt->address_strings[RPC_DISPLAY_ADDR])
 564                         __string(dstport,
 565                                 xprt->address_strings[RPC_DISPLAY_PORT])
 566                 ),
 567
 568                 TP_fast_assign(
 569                         struct inode *inode = SOCK_INODE(socket);
 570                         __entry->socket_state = socket->state;
 571                         __entry->sock_state = socket->sk->sk_state;
 572                         __entry->ino = (unsigned long long)inode->i_ino;
 573                         __assign_str(dstaddr,
 574                                 xprt->address_strings[RPC_DISPLAY_ADDR]);
 575                         __assign_str(dstport,
 576                                 xprt->address_strings[RPC_DISPLAY_PORT]);
 577                 ),
 578
 579                 TP_printk(
 580                         "socket:[%llu] dstaddr=%s/%s "
 581                         "state=%u (%s) sk_state=%u (%s)",
 582                         __entry->ino, __get_str(dstaddr), __get_str(dstport),
 583                         __entry->socket_state,
 584                         rpc_show_socket_state(__entry->socket_state),
 585                         __entry->sock_state,
 586                         rpc_show_sock_state(__entry->sock_state)
 587                 )
 588 );
 589 #define DEFINE_RPC_SOCKET_EVENT(name) \
 590         DEFINE_EVENT(xs_socket_event, name, \
 591                         TP_PROTO( \
 592                                 struct rpc_xprt *xprt, \
 593                                 struct socket *socket \
 594                         ), \
 595                         TP_ARGS(xprt, socket))
 596
 597 DECLARE_EVENT_CLASS(xs_socket_event_done,
 598
 599                 TP_PROTO(
 600                         struct rpc_xprt *xprt,
 601                         struct socket *socket,
 602                         int error
 603                 ),
 604
 605                 TP_ARGS(xprt, socket, error),
 606
 607                 TP_STRUCT__entry(
 608                         __field(int, error)
 609                         __field(unsigned int, socket_state)
 610                         __field(unsigned int, sock_state)
 611                         __field(unsigned long long, ino)
 612                         __string(dstaddr,
 613                                 xprt->address_strings[RPC_DISPLAY_ADDR])
 614                         __string(dstport,
 615                                 xprt->address_strings[RPC_DISPLAY_PORT])
 616                 ),
 617
 618                 TP_fast_assign(
 619                         struct inode *inode = SOCK_INODE(socket);
 620                         __entry->socket_state = socket->state;
 621                         __entry->sock_state = socket->sk->sk_state;
 622                         __entry->ino = (unsigned long long)inode->i_ino;
 623                         __entry->error = error;
 624                         __assign_str(dstaddr,
 625                                 xprt->address_strings[RPC_DISPLAY_ADDR]);
 626                         __assign_str(dstport,
 627                                 xprt->address_strings[RPC_DISPLAY_PORT]);
 628                 ),
 629
 630                 TP_printk(
 631                         "error=%d socket:[%llu] dstaddr=%s/%s "
 632                         "state=%u (%s) sk_state=%u (%s)",
 633                         __entry->error,
 634                         __entry->ino, __get_str(dstaddr), __get_str(dstport),
 635                         __entry->socket_state,
 636                         rpc_show_socket_state(__entry->socket_state),
 637                         __entry->sock_state,
 638                         rpc_show_sock_state(__entry->sock_state)
 639                 )
 640 );
 641 #define DEFINE_RPC_SOCKET_EVENT_DONE(name) \
 642         DEFINE_EVENT(xs_socket_event_done, name, \
 643                         TP_PROTO( \
 644                                 struct rpc_xprt *xprt, \
 645                                 struct socket *socket, \
 646                                 int error \
 647                         ), \
 648                         TP_ARGS(xprt, socket, error))
 649
 650 DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change);
 651 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect);
 652 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error);
 653 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
 654 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
 655 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
 656
 657 DECLARE_EVENT_CLASS(rpc_xprt_event,
 658         TP_PROTO(
 659                 const struct rpc_xprt *xprt,
 660                 __be32 xid,
 661                 int status
 662         ),
 663
 664         TP_ARGS(xprt, xid, status),
 665
 666         TP_STRUCT__entry(
 667                 __field(u32, xid)
 668                 __field(int, status)
 669                 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
 670                 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
 671         ),
 672
 673         TP_fast_assign(
 674                 __entry->xid = be32_to_cpu(xid);
 675                 __entry->status = status;
 676                 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
 677                 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
 678         ),
 679
 680         TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr),
 681                         __get_str(port), __entry->xid,
 682                         __entry->status)
 683 );
 684 #define DEFINE_RPC_XPRT_EVENT(name) \
 685         DEFINE_EVENT(rpc_xprt_event, xprt_##name, \
 686                         TP_PROTO( \
 687                                 const struct rpc_xprt *xprt, \
 688                                 __be32 xid, \
 689                                 int status \
 690                         ), \
 691                         TP_ARGS(xprt, xid, status))
 692
 693 DEFINE_RPC_XPRT_EVENT(timer);
 694 DEFINE_RPC_XPRT_EVENT(lookup_rqst);
 695 DEFINE_RPC_XPRT_EVENT(complete_rqst);
 696
 697 TRACE_EVENT(xprt_transmit,
 698         TP_PROTO(
 699                 const struct rpc_rqst *rqst,
 700                 int status
 701         ),
 702
 703         TP_ARGS(rqst, status),
 704
 705         TP_STRUCT__entry(
 706                 __field(unsigned int, task_id)
 707                 __field(unsigned int, client_id)
 708                 __field(u32, xid)
 709                 __field(u32, seqno)
 710                 __field(int, status)
 711         ),
 712
 713         TP_fast_assign(
 714                 __entry->task_id = rqst->rq_task->tk_pid;
 715                 __entry->client_id = rqst->rq_task->tk_client ?
 716                         rqst->rq_task->tk_client->cl_clid : -1;
 717                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 718                 __entry->seqno = rqst->rq_seqno;
 719                 __entry->status = status;
 720         ),
 721
 722         TP_printk(
 723                 "task:%u@%u xid=0x%08x seqno=%u status=%d",
 724                 __entry->task_id, __entry->client_id, __entry->xid,
 725                 __entry->seqno, __entry->status)
 726 );
 727
 728 TRACE_EVENT(xprt_enq_xmit,
 729         TP_PROTO(
 730                 const struct rpc_task *task,
 731                 int stage
 732         ),
 733
 734         TP_ARGS(task, stage),
 735
 736         TP_STRUCT__entry(
 737                 __field(unsigned int, task_id)
 738                 __field(unsigned int, client_id)
 739                 __field(u32, xid)
 740                 __field(u32, seqno)
 741                 __field(int, stage)
 742         ),
 743
 744         TP_fast_assign(
 745                 __entry->task_id = task->tk_pid;
 746                 __entry->client_id = task->tk_client ?
 747                         task->tk_client->cl_clid : -1;
 748                 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid);
 749                 __entry->seqno = task->tk_rqstp->rq_seqno;
 750                 __entry->stage = stage;
 751         ),
 752
 753         TP_printk(
 754                 "task:%u@%u xid=0x%08x seqno=%u stage=%d",
 755                 __entry->task_id, __entry->client_id, __entry->xid,
 756                 __entry->seqno, __entry->stage)
 757 );
 758
 759 TRACE_EVENT(xprt_ping,
 760         TP_PROTO(const struct rpc_xprt *xprt, int status),
 761
 762         TP_ARGS(xprt, status),
 763
 764         TP_STRUCT__entry(
 765                 __field(int, status)
 766                 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR])
 767                 __string(port, xprt->address_strings[RPC_DISPLAY_PORT])
 768         ),
 769
 770         TP_fast_assign(
 771                 __entry->status = status;
 772                 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]);
 773                 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]);
 774         ),
 775
 776         TP_printk("peer=[%s]:%s status=%d",
 777                         __get_str(addr), __get_str(port), __entry->status)
 778 );
 779
 780 TRACE_EVENT(xs_stream_read_data,
 781         TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total),
 782
 783         TP_ARGS(xprt, err, total),
 784
 785         TP_STRUCT__entry(
 786                 __field(ssize_t, err)
 787                 __field(size_t, total)
 788                 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] :
 789                                 "(null)")
 790                 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] :
 791                                 "(null)")
 792         ),
 793
 794         TP_fast_assign(
 795                 __entry->err = err;
 796                 __entry->total = total;
 797                 __assign_str(addr, xprt ?
 798                         xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)");
 799                 __assign_str(port, xprt ?
 800                         xprt->address_strings[RPC_DISPLAY_PORT] : "(null)");
 801         ),
 802
 803         TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr),
 804                         __get_str(port), __entry->err, __entry->total)
 805 );
 806
 807 TRACE_EVENT(xs_stream_read_request,
 808         TP_PROTO(struct sock_xprt *xs),
 809
 810         TP_ARGS(xs),
 811
 812         TP_STRUCT__entry(
 813                 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR])
 814                 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT])
 815                 __field(u32, xid)
 816                 __field(unsigned long, copied)
 817                 __field(unsigned int, reclen)
 818                 __field(unsigned int, offset)
 819         ),
 820
 821         TP_fast_assign(
 822                 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]);
 823                 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]);
 824                 __entry->xid = be32_to_cpu(xs->recv.xid);
 825                 __entry->copied = xs->recv.copied;
 826                 __entry->reclen = xs->recv.len;
 827                 __entry->offset = xs->recv.offset;
 828         ),
 829
 830         TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u",
 831                         __get_str(addr), __get_str(port), __entry->xid,
 832                         __entry->copied, __entry->reclen, __entry->offset)
 833 );
 834
 835 #define show_rqstp_flags(flags)                                         \
 836         __print_flags(flags, "|",                                       \
 837                 { (1UL << RQ_SECURE),           "RQ_SECURE"},           \
 838                 { (1UL << RQ_LOCAL),            "RQ_LOCAL"},            \
 839                 { (1UL << RQ_USEDEFERRAL),      "RQ_USEDEFERRAL"},      \
 840                 { (1UL << RQ_DROPME),           "RQ_DROPME"},           \
 841                 { (1UL << RQ_SPLICE_OK),        "RQ_SPLICE_OK"},        \
 842                 { (1UL << RQ_VICTIM),           "RQ_VICTIM"},           \
 843                 { (1UL << RQ_BUSY),             "RQ_BUSY"})
 844
 845 TRACE_EVENT(svc_recv,
 846         TP_PROTO(struct svc_rqst *rqst, int len),
 847
 848         TP_ARGS(rqst, len),
 849
 850         TP_STRUCT__entry(
 851                 __field(u32, xid)
 852                 __field(int, len)
 853                 __field(unsigned long, flags)
 854                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 855         ),
 856
 857         TP_fast_assign(
 858                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 859                 __entry->len = len;
 860                 __entry->flags = rqst->rq_flags;
 861                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 862         ),
 863
 864         TP_printk("addr=%s xid=0x%08x len=%d flags=%s",
 865                         __get_str(addr), __entry->xid, __entry->len,
 866                         show_rqstp_flags(__entry->flags))
 867 );
 868
 869 TRACE_EVENT(svc_process,
 870         TP_PROTO(const struct svc_rqst *rqst, const char *name),
 871
 872         TP_ARGS(rqst, name),
 873
 874         TP_STRUCT__entry(
 875                 __field(u32, xid)
 876                 __field(u32, vers)
 877                 __field(u32, proc)
 878                 __string(service, name)
 879                 __string(addr, rqst->rq_xprt ?
 880                          rqst->rq_xprt->xpt_remotebuf : "(null)")
 881         ),
 882
 883         TP_fast_assign(
 884                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 885                 __entry->vers = rqst->rq_vers;
 886                 __entry->proc = rqst->rq_proc;
 887                 __assign_str(service, name);
 888                 __assign_str(addr, rqst->rq_xprt ?
 889                              rqst->rq_xprt->xpt_remotebuf : "(null)");
 890         ),
 891
 892         TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%u",
 893                         __get_str(addr), __entry->xid,
 894                         __get_str(service), __entry->vers, __entry->proc)
 895 );
 896
 897 DECLARE_EVENT_CLASS(svc_rqst_event,
 898
 899         TP_PROTO(
 900                 const struct svc_rqst *rqst
 901         ),
 902
 903         TP_ARGS(rqst),
 904
 905         TP_STRUCT__entry(
 906                 __field(u32, xid)
 907                 __field(unsigned long, flags)
 908                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 909         ),
 910
 911         TP_fast_assign(
 912                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 913                 __entry->flags = rqst->rq_flags;
 914                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 915         ),
 916
 917         TP_printk("addr=%s xid=0x%08x flags=%s",
 918                         __get_str(addr), __entry->xid,
 919                         show_rqstp_flags(__entry->flags))
 920 );
 921 #define DEFINE_SVC_RQST_EVENT(name) \
 922         DEFINE_EVENT(svc_rqst_event, svc_##name, \
 923                         TP_PROTO( \
 924                                 const struct svc_rqst *rqst \
 925                         ), \
 926                         TP_ARGS(rqst))
 927
 928 DEFINE_SVC_RQST_EVENT(defer);
 929 DEFINE_SVC_RQST_EVENT(drop);
 930
 931 DECLARE_EVENT_CLASS(svc_rqst_status,
 932
 933         TP_PROTO(struct svc_rqst *rqst, int status),
 934
 935         TP_ARGS(rqst, status),
 936
 937         TP_STRUCT__entry(
 938                 __field(u32, xid)
 939                 __field(int, status)
 940                 __field(unsigned long, flags)
 941                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
 942         ),
 943
 944         TP_fast_assign(
 945                 __entry->xid = be32_to_cpu(rqst->rq_xid);
 946                 __entry->status = status;
 947                 __entry->flags = rqst->rq_flags;
 948                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
 949         ),
 950
 951         TP_printk("addr=%s xid=0x%08x status=%d flags=%s",
 952                   __get_str(addr), __entry->xid,
 953                   __entry->status, show_rqstp_flags(__entry->flags))
 954 );
 955
 956 DEFINE_EVENT(svc_rqst_status, svc_send,
 957         TP_PROTO(struct svc_rqst *rqst, int status),
 958         TP_ARGS(rqst, status));
 959
 960 #define show_svc_xprt_flags(flags)                                      \
 961         __print_flags(flags, "|",                                       \
 962                 { (1UL << XPT_BUSY),            "XPT_BUSY"},            \
 963                 { (1UL << XPT_CONN),            "XPT_CONN"},            \
 964                 { (1UL << XPT_CLOSE),           "XPT_CLOSE"},           \
 965                 { (1UL << XPT_DATA),            "XPT_DATA"},            \
 966                 { (1UL << XPT_TEMP),            "XPT_TEMP"},            \
 967                 { (1UL << XPT_DEAD),            "XPT_DEAD"},            \
 968                 { (1UL << XPT_CHNGBUF),         "XPT_CHNGBUF"},         \
 969                 { (1UL << XPT_DEFERRED),        "XPT_DEFERRED"},        \
 970                 { (1UL << XPT_OLD),             "XPT_OLD"},             \
 971                 { (1UL << XPT_LISTENER),        "XPT_LISTENER"},        \
 972                 { (1UL << XPT_CACHE_AUTH),      "XPT_CACHE_AUTH"},      \
 973                 { (1UL << XPT_LOCAL),           "XPT_LOCAL"},           \
 974                 { (1UL << XPT_KILL_TEMP),       "XPT_KILL_TEMP"},       \
 975                 { (1UL << XPT_CONG_CTRL),       "XPT_CONG_CTRL"})
 976
 977 TRACE_EVENT(svc_xprt_do_enqueue,
 978         TP_PROTO(struct svc_xprt *xprt, struct svc_rqst *rqst),
 979
 980         TP_ARGS(xprt, rqst),
 981
 982         TP_STRUCT__entry(
 983                 __field(struct svc_xprt *, xprt)
 984                 __field(int, pid)
 985                 __field(unsigned long, flags)
 986                 __string(addr, xprt->xpt_remotebuf)
 987         ),
 988
 989         TP_fast_assign(
 990                 __entry->xprt = xprt;
 991                 __entry->pid = rqst? rqst->rq_task->pid : 0;
 992                 __entry->flags = xprt->xpt_flags;
 993                 __assign_str(addr, xprt->xpt_remotebuf);
 994         ),
 995
 996         TP_printk("xprt=%p addr=%s pid=%d flags=%s",
 997                         __entry->xprt, __get_str(addr),
 998                         __entry->pid, show_svc_xprt_flags(__entry->flags))
 999 );
1000
1001 DECLARE_EVENT_CLASS(svc_xprt_event,
1002         TP_PROTO(struct svc_xprt *xprt),
1003
1004         TP_ARGS(xprt),
1005
1006         TP_STRUCT__entry(
1007                 __field(struct svc_xprt *, xprt)
1008                 __field(unsigned long, flags)
1009                 __string(addr, xprt->xpt_remotebuf)
1010         ),
1011
1012         TP_fast_assign(
1013                 __entry->xprt = xprt;
1014                 __entry->flags = xprt->xpt_flags;
1015                 __assign_str(addr, xprt->xpt_remotebuf);
1016         ),
1017
1018         TP_printk("xprt=%p addr=%s flags=%s",
1019                         __entry->xprt, __get_str(addr),
1020                         show_svc_xprt_flags(__entry->flags))
1021 );
1022
1023 DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space,
1024         TP_PROTO(struct svc_xprt *xprt),
1025         TP_ARGS(xprt));
1026
1027 TRACE_EVENT(svc_xprt_dequeue,
1028         TP_PROTO(struct svc_rqst *rqst),
1029
1030         TP_ARGS(rqst),
1031
1032         TP_STRUCT__entry(
1033                 __field(struct svc_xprt *, xprt)
1034                 __field(unsigned long, flags)
1035                 __field(unsigned long, wakeup)
1036                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1037         ),
1038
1039         TP_fast_assign(
1040                 __entry->xprt = rqst->rq_xprt;
1041                 __entry->flags = rqst->rq_xprt->xpt_flags;
1042                 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(),
1043                                                         rqst->rq_qtime));
1044                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1045         ),
1046
1047         TP_printk("xprt=%p addr=%s flags=%s wakeup-us=%lu",
1048                         __entry->xprt, __get_str(addr),
1049                         show_svc_xprt_flags(__entry->flags),
1050                         __entry->wakeup)
1051 );
1052
1053 TRACE_EVENT(svc_wake_up,
1054         TP_PROTO(int pid),
1055
1056         TP_ARGS(pid),
1057
1058         TP_STRUCT__entry(
1059                 __field(int, pid)
1060         ),
1061
1062         TP_fast_assign(
1063                 __entry->pid = pid;
1064         ),
1065
1066         TP_printk("pid=%d", __entry->pid)
1067 );
1068
1069 TRACE_EVENT(svc_handle_xprt,
1070         TP_PROTO(struct svc_xprt *xprt, int len),
1071
1072         TP_ARGS(xprt, len),
1073
1074         TP_STRUCT__entry(
1075                 __field(struct svc_xprt *, xprt)
1076                 __field(int, len)
1077                 __field(unsigned long, flags)
1078                 __string(addr, xprt->xpt_remotebuf)
1079         ),
1080
1081         TP_fast_assign(
1082                 __entry->xprt = xprt;
1083                 __entry->len = len;
1084                 __entry->flags = xprt->xpt_flags;
1085                 __assign_str(addr, xprt->xpt_remotebuf);
1086         ),
1087
1088         TP_printk("xprt=%p addr=%s len=%d flags=%s",
1089                 __entry->xprt, __get_str(addr),
1090                 __entry->len, show_svc_xprt_flags(__entry->flags))
1091 );
1092
1093 TRACE_EVENT(svc_stats_latency,
1094         TP_PROTO(const struct svc_rqst *rqst),
1095
1096         TP_ARGS(rqst),
1097
1098         TP_STRUCT__entry(
1099                 __field(u32, xid)
1100                 __field(unsigned long, execute)
1101                 __string(addr, rqst->rq_xprt->xpt_remotebuf)
1102         ),
1103
1104         TP_fast_assign(
1105                 __entry->xid = be32_to_cpu(rqst->rq_xid);
1106                 __entry->execute = ktime_to_us(ktime_sub(ktime_get(),
1107                                                          rqst->rq_stime));
1108                 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
1109         ),
1110
1111         TP_printk("addr=%s xid=0x%08x execute-us=%lu",
1112                 __get_str(addr), __entry->xid, __entry->execute)
1113 );
1114
1115 DECLARE_EVENT_CLASS(svc_deferred_event,
1116         TP_PROTO(
1117                 const struct svc_deferred_req *dr
1118         ),
1119
1120         TP_ARGS(dr),
1121
1122         TP_STRUCT__entry(
1123                 __field(u32, xid)
1124                 __string(addr, dr->xprt->xpt_remotebuf)
1125         ),
1126
1127         TP_fast_assign(
1128                 __entry->xid = be32_to_cpu(*(__be32 *)(dr->args +
1129                                                        (dr->xprt_hlen>>2)));
1130                 __assign_str(addr, dr->xprt->xpt_remotebuf);
1131         ),
1132
1133         TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
1134 );
1135 #define DEFINE_SVC_DEFERRED_EVENT(name) \
1136         DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \
1137                         TP_PROTO( \
1138                                 const struct svc_deferred_req *dr \
1139                         ), \
1140                         TP_ARGS(dr))
1141
1142 DEFINE_SVC_DEFERRED_EVENT(drop);
1143 DEFINE_SVC_DEFERRED_EVENT(revisit);
1144
1145 #endif /* _TRACE_SUNRPC_H */
1146
1147 #include <trace/define_trace.h>