linux/include/trace/events/sunrpc.h
<<
>>
Prefs
   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
  17DECLARE_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
  46DEFINE_RPC_STATUS_EVENT(call);
  47DEFINE_RPC_STATUS_EVENT(bind);
  48DEFINE_RPC_STATUS_EVENT(connect);
  49
  50TRACE_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
  80TRACE_DEFINE_ENUM(RPC_TASK_ASYNC);
  81TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER);
  82TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN);
  83TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS);
  84TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC);
  85TRACE_DEFINE_ENUM(RPC_TASK_SOFT);
  86TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN);
  87TRACE_DEFINE_ENUM(RPC_TASK_SENT);
  88TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT);
  89TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT);
  90TRACE_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
 106TRACE_DEFINE_ENUM(RPC_TASK_RUNNING);
 107TRACE_DEFINE_ENUM(RPC_TASK_QUEUED);
 108TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE);
 109TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT);
 110TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV);
 111TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT);
 112TRACE_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
 124DECLARE_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
 165DEFINE_RPC_RUNNING_EVENT(begin);
 166DEFINE_RPC_RUNNING_EVENT(run_action);
 167DEFINE_RPC_RUNNING_EVENT(complete);
 168
 169DECLARE_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
 213DEFINE_RPC_QUEUED_EVENT(sleep);
 214DEFINE_RPC_QUEUED_EVENT(wakeup);
 215
 216DECLARE_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
 243DEFINE_RPC_FAILURE(callhdr);
 244DEFINE_RPC_FAILURE(verifier);
 245
 246DECLARE_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
 287DEFINE_RPC_REPLY_EVENT(prog_unavail);
 288DEFINE_RPC_REPLY_EVENT(prog_mismatch);
 289DEFINE_RPC_REPLY_EVENT(proc_unavail);
 290DEFINE_RPC_REPLY_EVENT(garbage_args);
 291DEFINE_RPC_REPLY_EVENT(unparsable);
 292DEFINE_RPC_REPLY_EVENT(mismatch);
 293DEFINE_RPC_REPLY_EVENT(stale_creds);
 294DEFINE_RPC_REPLY_EVENT(bad_creds);
 295DEFINE_RPC_REPLY_EVENT(auth_tooweak);
 296
 297TRACE_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
 338TRACE_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
 405TRACE_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
 464TRACE_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
 520RPC_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
 538RPC_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
 549DECLARE_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
 597DECLARE_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
 650DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change);
 651DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect);
 652DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error);
 653DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection);
 654DEFINE_RPC_SOCKET_EVENT(rpc_socket_close);
 655DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown);
 656
 657DECLARE_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
 693DEFINE_RPC_XPRT_EVENT(timer);
 694DEFINE_RPC_XPRT_EVENT(lookup_rqst);
 695DEFINE_RPC_XPRT_EVENT(complete_rqst);
 696
 697TRACE_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
 728TRACE_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
 759TRACE_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
 780TRACE_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
 807TRACE_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
 845TRACE_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
 869TRACE_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
 897DECLARE_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
 928DEFINE_SVC_RQST_EVENT(defer);
 929DEFINE_SVC_RQST_EVENT(drop);
 930
 931DECLARE_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
 956DEFINE_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
 977TRACE_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
1001DECLARE_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
1023DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space,
1024        TP_PROTO(struct svc_xprt *xprt),
1025        TP_ARGS(xprt));
1026
1027TRACE_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
1053TRACE_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
1069TRACE_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
1093TRACE_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
1115DECLARE_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
1142DEFINE_SVC_DEFERRED_EVENT(drop);
1143DEFINE_SVC_DEFERRED_EVENT(revisit);
1144
1145#endif /* _TRACE_SUNRPC_H */
1146
1147#include <trace/define_trace.h>
1148