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 #include <trace/misc/sunrpc.h> 18 19 TRACE_DEFINE_ENUM(SOCK_STREAM); 20 TRACE_DEFINE_ENUM(SOCK_DGRAM); 21 TRACE_DEFINE_ENUM(SOCK_RAW); 22 TRACE_DEFINE_ENUM(SOCK_RDM); 23 TRACE_DEFINE_ENUM(SOCK_SEQPACKET); 24 TRACE_DEFINE_ENUM(SOCK_PACKET); 25 26 #define show_socket_type(type) \ 27 __print_symbolic(type, \ 28 { SOCK_STREAM, "STREAM" }, \ 29 { SOCK_DGRAM, "DGRAM" }, \ 30 { SOCK_RAW, "RAW" }, \ 31 { SOCK_RDM, "RDM" }, \ 32 { SOCK_SEQPACKET, "SEQPACKET" }, \ 33 { SOCK_PACKET, "PACKET" }) 34 35 /* This list is known to be incomplete, add new enums as needed. */ 36 TRACE_DEFINE_ENUM(AF_UNSPEC); 37 TRACE_DEFINE_ENUM(AF_UNIX); 38 TRACE_DEFINE_ENUM(AF_LOCAL); 39 TRACE_DEFINE_ENUM(AF_INET); 40 TRACE_DEFINE_ENUM(AF_INET6); 41 42 #define rpc_show_address_family(family) \ 43 __print_symbolic(family, \ 44 { AF_UNSPEC, "AF_UNSPEC" }, \ 45 { AF_UNIX, "AF_UNIX" }, \ 46 { AF_LOCAL, "AF_LOCAL" }, \ 47 { AF_INET, "AF_INET" }, \ 48 { AF_INET6, "AF_INET6" }) 49 50 DECLARE_EVENT_CLASS(rpc_xdr_buf_class, 51 TP_PROTO( 52 const struct rpc_task *task, 53 const struct xdr_buf *xdr 54 ), 55 56 TP_ARGS(task, xdr), 57 58 TP_STRUCT__entry( 59 __field(unsigned int, task_id) 60 __field(unsigned int, client_id) 61 __field(const void *, head_base) 62 __field(size_t, head_len) 63 __field(const void *, tail_base) 64 __field(size_t, tail_len) 65 __field(unsigned int, page_base) 66 __field(unsigned int, page_len) 67 __field(unsigned int, msg_len) 68 ), 69 70 TP_fast_assign( 71 __entry->task_id = task->tk_pid; 72 __entry->client_id = task->tk_client ? 73 task->tk_client->cl_clid : -1; 74 __entry->head_base = xdr->head[0].iov_base; 75 __entry->head_len = xdr->head[0].iov_len; 76 __entry->tail_base = xdr->tail[0].iov_base; 77 __entry->tail_len = xdr->tail[0].iov_len; 78 __entry->page_base = xdr->page_base; 79 __entry->page_len = xdr->page_len; 80 __entry->msg_len = xdr->len; 81 ), 82 83 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 84 " head=[%p,%zu] page=%u(%u) tail=[%p,%zu] len=%u", 85 __entry->task_id, __entry->client_id, 86 __entry->head_base, __entry->head_len, 87 __entry->page_len, __entry->page_base, 88 __entry->tail_base, __entry->tail_len, 89 __entry->msg_len 90 ) 91 ); 92 93 #define DEFINE_RPCXDRBUF_EVENT(name) \ 94 DEFINE_EVENT(rpc_xdr_buf_class, \ 95 rpc_xdr_##name, \ 96 TP_PROTO( \ 97 const struct rpc_task *task, \ 98 const struct xdr_buf *xdr \ 99 ), \ 100 TP_ARGS(task, xdr)) 101 102 DEFINE_RPCXDRBUF_EVENT(sendto); 103 DEFINE_RPCXDRBUF_EVENT(recvfrom); 104 DEFINE_RPCXDRBUF_EVENT(reply_pages); 105 106 107 DECLARE_EVENT_CLASS(rpc_clnt_class, 108 TP_PROTO( 109 const struct rpc_clnt *clnt 110 ), 111 112 TP_ARGS(clnt), 113 114 TP_STRUCT__entry( 115 __field(unsigned int, client_id) 116 ), 117 118 TP_fast_assign( 119 __entry->client_id = clnt->cl_clid; 120 ), 121 122 TP_printk("client=" SUNRPC_TRACE_CLID_SPECIFIER, __entry->client_id) 123 ); 124 125 #define DEFINE_RPC_CLNT_EVENT(name) \ 126 DEFINE_EVENT(rpc_clnt_class, \ 127 rpc_clnt_##name, \ 128 TP_PROTO( \ 129 const struct rpc_clnt *clnt \ 130 ), \ 131 TP_ARGS(clnt)) 132 133 DEFINE_RPC_CLNT_EVENT(free); 134 DEFINE_RPC_CLNT_EVENT(killall); 135 DEFINE_RPC_CLNT_EVENT(shutdown); 136 DEFINE_RPC_CLNT_EVENT(release); 137 DEFINE_RPC_CLNT_EVENT(replace_xprt); 138 DEFINE_RPC_CLNT_EVENT(replace_xprt_err); 139 140 TRACE_DEFINE_ENUM(RPC_XPRTSEC_NONE); 141 TRACE_DEFINE_ENUM(RPC_XPRTSEC_TLS_X509); 142 143 #define rpc_show_xprtsec_policy(policy) \ 144 __print_symbolic(policy, \ 145 { RPC_XPRTSEC_NONE, "none" }, \ 146 { RPC_XPRTSEC_TLS_ANON, "tls-anon" }, \ 147 { RPC_XPRTSEC_TLS_X509, "tls-x509" }) 148 149 #define rpc_show_create_flags(flags) \ 150 __print_flags(flags, "|", \ 151 { RPC_CLNT_CREATE_HARDRTRY, "HARDRTRY" }, \ 152 { RPC_CLNT_CREATE_AUTOBIND, "AUTOBIND" }, \ 153 { RPC_CLNT_CREATE_NONPRIVPORT, "NONPRIVPORT" }, \ 154 { RPC_CLNT_CREATE_NOPING, "NOPING" }, \ 155 { RPC_CLNT_CREATE_DISCRTRY, "DISCRTRY" }, \ 156 { RPC_CLNT_CREATE_QUIET, "QUIET" }, \ 157 { RPC_CLNT_CREATE_INFINITE_SLOTS, \ 158 "INFINITE_SLOTS" }, \ 159 { RPC_CLNT_CREATE_NO_IDLE_TIMEOUT, \ 160 "NO_IDLE_TIMEOUT" }, \ 161 { RPC_CLNT_CREATE_NO_RETRANS_TIMEOUT, \ 162 "NO_RETRANS_TIMEOUT" }, \ 163 { RPC_CLNT_CREATE_SOFTERR, "SOFTERR" }, \ 164 { RPC_CLNT_CREATE_REUSEPORT, "REUSEPORT" }) 165 166 TRACE_EVENT(rpc_clnt_new, 167 TP_PROTO( 168 const struct rpc_clnt *clnt, 169 const struct rpc_xprt *xprt, 170 const struct rpc_create_args *args 171 ), 172 173 TP_ARGS(clnt, xprt, args), 174 175 TP_STRUCT__entry( 176 __field(unsigned int, client_id) 177 __field(unsigned long, xprtsec) 178 __field(unsigned long, flags) 179 __string(program, clnt->cl_program->name) 180 __string(server, xprt->servername) 181 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 182 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 183 ), 184 185 TP_fast_assign( 186 __entry->client_id = clnt->cl_clid; 187 __entry->xprtsec = args->xprtsec.policy; 188 __entry->flags = args->flags; 189 __assign_str(program); 190 __assign_str(server); 191 __assign_str(addr); 192 __assign_str(port); 193 ), 194 195 TP_printk("client=" SUNRPC_TRACE_CLID_SPECIFIER " peer=[%s]:%s" 196 " program=%s server=%s xprtsec=%s flags=%s", 197 __entry->client_id, __get_str(addr), __get_str(port), 198 __get_str(program), __get_str(server), 199 rpc_show_xprtsec_policy(__entry->xprtsec), 200 rpc_show_create_flags(__entry->flags) 201 ) 202 ); 203 204 TRACE_EVENT(rpc_clnt_new_err, 205 TP_PROTO( 206 const char *program, 207 const char *server, 208 int error 209 ), 210 211 TP_ARGS(program, server, error), 212 213 TP_STRUCT__entry( 214 __field(int, error) 215 __string(program, program) 216 __string(server, server) 217 ), 218 219 TP_fast_assign( 220 __entry->error = error; 221 __assign_str(program); 222 __assign_str(server); 223 ), 224 225 TP_printk("program=%s server=%s error=%d", 226 __get_str(program), __get_str(server), __entry->error) 227 ); 228 229 TRACE_EVENT(rpc_clnt_clone_err, 230 TP_PROTO( 231 const struct rpc_clnt *clnt, 232 int error 233 ), 234 235 TP_ARGS(clnt, error), 236 237 TP_STRUCT__entry( 238 __field(unsigned int, client_id) 239 __field(int, error) 240 ), 241 242 TP_fast_assign( 243 __entry->client_id = clnt->cl_clid; 244 __entry->error = error; 245 ), 246 247 TP_printk("client=" SUNRPC_TRACE_CLID_SPECIFIER " error=%d", 248 __entry->client_id, __entry->error) 249 ); 250 251 252 TRACE_DEFINE_ENUM(RPC_AUTH_OK); 253 TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED); 254 TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED); 255 TRACE_DEFINE_ENUM(RPC_AUTH_BADVERF); 256 TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDVERF); 257 TRACE_DEFINE_ENUM(RPC_AUTH_TOOWEAK); 258 TRACE_DEFINE_ENUM(RPCSEC_GSS_CREDPROBLEM); 259 TRACE_DEFINE_ENUM(RPCSEC_GSS_CTXPROBLEM); 260 261 #define rpc_show_auth_stat(status) \ 262 __print_symbolic(status, \ 263 { RPC_AUTH_OK, "AUTH_OK" }, \ 264 { RPC_AUTH_BADCRED, "BADCRED" }, \ 265 { RPC_AUTH_REJECTEDCRED, "REJECTEDCRED" }, \ 266 { RPC_AUTH_BADVERF, "BADVERF" }, \ 267 { RPC_AUTH_REJECTEDVERF, "REJECTEDVERF" }, \ 268 { RPC_AUTH_TOOWEAK, "TOOWEAK" }, \ 269 { RPCSEC_GSS_CREDPROBLEM, "GSS_CREDPROBLEM" }, \ 270 { RPCSEC_GSS_CTXPROBLEM, "GSS_CTXPROBLEM" }) \ 271 272 DECLARE_EVENT_CLASS(rpc_task_status, 273 274 TP_PROTO(const struct rpc_task *task), 275 276 TP_ARGS(task), 277 278 TP_STRUCT__entry( 279 __field(unsigned int, task_id) 280 __field(unsigned int, client_id) 281 __field(int, status) 282 ), 283 284 TP_fast_assign( 285 __entry->task_id = task->tk_pid; 286 __entry->client_id = task->tk_client->cl_clid; 287 __entry->status = task->tk_status; 288 ), 289 290 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " status=%d", 291 __entry->task_id, __entry->client_id, 292 __entry->status) 293 ); 294 #define DEFINE_RPC_STATUS_EVENT(name) \ 295 DEFINE_EVENT(rpc_task_status, rpc_##name##_status, \ 296 TP_PROTO( \ 297 const struct rpc_task *task \ 298 ), \ 299 TP_ARGS(task)) 300 301 DEFINE_RPC_STATUS_EVENT(call); 302 DEFINE_RPC_STATUS_EVENT(connect); 303 DEFINE_RPC_STATUS_EVENT(timeout); 304 DEFINE_RPC_STATUS_EVENT(retry_refresh); 305 DEFINE_RPC_STATUS_EVENT(refresh); 306 307 TRACE_EVENT(rpc_request, 308 TP_PROTO(const struct rpc_task *task), 309 310 TP_ARGS(task), 311 312 TP_STRUCT__entry( 313 __field(unsigned int, task_id) 314 __field(unsigned int, client_id) 315 __field(int, version) 316 __field(bool, async) 317 __string(progname, task->tk_client->cl_program->name) 318 __string(procname, rpc_proc_name(task)) 319 ), 320 321 TP_fast_assign( 322 __entry->task_id = task->tk_pid; 323 __entry->client_id = task->tk_client->cl_clid; 324 __entry->version = task->tk_client->cl_vers; 325 __entry->async = RPC_IS_ASYNC(task); 326 __assign_str(progname); 327 __assign_str(procname); 328 ), 329 330 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " %sv%d %s (%ssync)", 331 __entry->task_id, __entry->client_id, 332 __get_str(progname), __entry->version, 333 __get_str(procname), __entry->async ? "a": "" 334 ) 335 ); 336 337 #define rpc_show_task_flags(flags) \ 338 __print_flags(flags, "|", \ 339 { RPC_TASK_ASYNC, "ASYNC" }, \ 340 { RPC_TASK_SWAPPER, "SWAPPER" }, \ 341 { RPC_TASK_MOVEABLE, "MOVEABLE" }, \ 342 { RPC_TASK_NULLCREDS, "NULLCREDS" }, \ 343 { RPC_CALL_MAJORSEEN, "MAJORSEEN" }, \ 344 { RPC_TASK_NETUNREACH_FATAL, "NETUNREACH_FATAL"}, \ 345 { RPC_TASK_DYNAMIC, "DYNAMIC" }, \ 346 { RPC_TASK_NO_ROUND_ROBIN, "NO_ROUND_ROBIN" }, \ 347 { RPC_TASK_SOFT, "SOFT" }, \ 348 { RPC_TASK_SOFTCONN, "SOFTCONN" }, \ 349 { RPC_TASK_SENT, "SENT" }, \ 350 { RPC_TASK_TIMEOUT, "TIMEOUT" }, \ 351 { RPC_TASK_NOCONNECT, "NOCONNECT" }, \ 352 { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" }, \ 353 { RPC_TASK_CRED_NOREF, "CRED_NOREF" }) 354 355 #define rpc_show_runstate(flags) \ 356 __print_flags(flags, "|", \ 357 { (1UL << RPC_TASK_RUNNING), "RUNNING" }, \ 358 { (1UL << RPC_TASK_QUEUED), "QUEUED" }, \ 359 { (1UL << RPC_TASK_ACTIVE), "ACTIVE" }, \ 360 { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" }, \ 361 { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" }, \ 362 { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" }) 363 364 DECLARE_EVENT_CLASS(rpc_task_running, 365 366 TP_PROTO(const struct rpc_task *task, const void *action), 367 368 TP_ARGS(task, action), 369 370 TP_STRUCT__entry( 371 __field(unsigned int, task_id) 372 __field(unsigned int, client_id) 373 __field(const void *, action) 374 __field(unsigned long, runstate) 375 __field(int, status) 376 __field(unsigned short, flags) 377 ), 378 379 TP_fast_assign( 380 __entry->client_id = task->tk_client ? 381 task->tk_client->cl_clid : -1; 382 __entry->task_id = task->tk_pid; 383 __entry->action = action; 384 __entry->runstate = task->tk_runstate; 385 __entry->status = task->tk_status; 386 __entry->flags = task->tk_flags; 387 ), 388 389 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 390 " flags=%s runstate=%s status=%d action=%ps", 391 __entry->task_id, __entry->client_id, 392 rpc_show_task_flags(__entry->flags), 393 rpc_show_runstate(__entry->runstate), 394 __entry->status, 395 __entry->action 396 ) 397 ); 398 #define DEFINE_RPC_RUNNING_EVENT(name) \ 399 DEFINE_EVENT(rpc_task_running, rpc_task_##name, \ 400 TP_PROTO( \ 401 const struct rpc_task *task, \ 402 const void *action \ 403 ), \ 404 TP_ARGS(task, action)) 405 406 DEFINE_RPC_RUNNING_EVENT(begin); 407 DEFINE_RPC_RUNNING_EVENT(run_action); 408 DEFINE_RPC_RUNNING_EVENT(sync_sleep); 409 DEFINE_RPC_RUNNING_EVENT(sync_wake); 410 DEFINE_RPC_RUNNING_EVENT(complete); 411 DEFINE_RPC_RUNNING_EVENT(timeout); 412 DEFINE_RPC_RUNNING_EVENT(signalled); 413 DEFINE_RPC_RUNNING_EVENT(end); 414 DEFINE_RPC_RUNNING_EVENT(call_done); 415 416 DECLARE_EVENT_CLASS(rpc_task_queued, 417 418 TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q), 419 420 TP_ARGS(task, q), 421 422 TP_STRUCT__entry( 423 __field(unsigned int, task_id) 424 __field(unsigned int, client_id) 425 __field(unsigned long, timeout) 426 __field(unsigned long, runstate) 427 __field(int, status) 428 __field(unsigned short, flags) 429 __string(q_name, rpc_qname(q)) 430 ), 431 432 TP_fast_assign( 433 __entry->client_id = task->tk_client ? 434 task->tk_client->cl_clid : -1; 435 __entry->task_id = task->tk_pid; 436 __entry->timeout = rpc_task_timeout(task); 437 __entry->runstate = task->tk_runstate; 438 __entry->status = task->tk_status; 439 __entry->flags = task->tk_flags; 440 __assign_str(q_name); 441 ), 442 443 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 444 " flags=%s runstate=%s status=%d timeout=%lu queue=%s", 445 __entry->task_id, __entry->client_id, 446 rpc_show_task_flags(__entry->flags), 447 rpc_show_runstate(__entry->runstate), 448 __entry->status, 449 __entry->timeout, 450 __get_str(q_name) 451 ) 452 ); 453 #define DEFINE_RPC_QUEUED_EVENT(name) \ 454 DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \ 455 TP_PROTO( \ 456 const struct rpc_task *task, \ 457 const struct rpc_wait_queue *q \ 458 ), \ 459 TP_ARGS(task, q)) 460 461 DEFINE_RPC_QUEUED_EVENT(sleep); 462 DEFINE_RPC_QUEUED_EVENT(wakeup); 463 464 DECLARE_EVENT_CLASS(rpc_failure, 465 466 TP_PROTO(const struct rpc_task *task), 467 468 TP_ARGS(task), 469 470 TP_STRUCT__entry( 471 __field(unsigned int, task_id) 472 __field(unsigned int, client_id) 473 ), 474 475 TP_fast_assign( 476 __entry->task_id = task->tk_pid; 477 __entry->client_id = task->tk_client->cl_clid; 478 ), 479 480 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER, 481 __entry->task_id, __entry->client_id) 482 ); 483 484 #define DEFINE_RPC_FAILURE(name) \ 485 DEFINE_EVENT(rpc_failure, rpc_bad_##name, \ 486 TP_PROTO( \ 487 const struct rpc_task *task \ 488 ), \ 489 TP_ARGS(task)) 490 491 DEFINE_RPC_FAILURE(callhdr); 492 DEFINE_RPC_FAILURE(verifier); 493 494 DECLARE_EVENT_CLASS(rpc_reply_event, 495 496 TP_PROTO( 497 const struct rpc_task *task 498 ), 499 500 TP_ARGS(task), 501 502 TP_STRUCT__entry( 503 __field(unsigned int, task_id) 504 __field(unsigned int, client_id) 505 __field(u32, xid) 506 __string(progname, task->tk_client->cl_program->name) 507 __field(u32, version) 508 __string(procname, rpc_proc_name(task)) 509 __string(servername, task->tk_xprt->servername) 510 ), 511 512 TP_fast_assign( 513 __entry->task_id = task->tk_pid; 514 __entry->client_id = task->tk_client->cl_clid; 515 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 516 __assign_str(progname); 517 __entry->version = task->tk_client->cl_vers; 518 __assign_str(procname); 519 __assign_str(servername); 520 ), 521 522 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 523 " server=%s xid=0x%08x %sv%d %s", 524 __entry->task_id, __entry->client_id, __get_str(servername), 525 __entry->xid, __get_str(progname), __entry->version, 526 __get_str(procname)) 527 ) 528 529 #define DEFINE_RPC_REPLY_EVENT(name) \ 530 DEFINE_EVENT(rpc_reply_event, rpc__##name, \ 531 TP_PROTO( \ 532 const struct rpc_task *task \ 533 ), \ 534 TP_ARGS(task)) 535 536 DEFINE_RPC_REPLY_EVENT(prog_unavail); 537 DEFINE_RPC_REPLY_EVENT(prog_mismatch); 538 DEFINE_RPC_REPLY_EVENT(proc_unavail); 539 DEFINE_RPC_REPLY_EVENT(garbage_args); 540 DEFINE_RPC_REPLY_EVENT(unparsable); 541 DEFINE_RPC_REPLY_EVENT(mismatch); 542 DEFINE_RPC_REPLY_EVENT(stale_creds); 543 DEFINE_RPC_REPLY_EVENT(bad_creds); 544 DEFINE_RPC_REPLY_EVENT(auth_tooweak); 545 546 #define DEFINE_RPCB_ERROR_EVENT(name) \ 547 DEFINE_EVENT(rpc_reply_event, rpcb_##name##_err, \ 548 TP_PROTO( \ 549 const struct rpc_task *task \ 550 ), \ 551 TP_ARGS(task)) 552 553 DEFINE_RPCB_ERROR_EVENT(prog_unavail); 554 DEFINE_RPCB_ERROR_EVENT(timeout); 555 DEFINE_RPCB_ERROR_EVENT(bind_version); 556 DEFINE_RPCB_ERROR_EVENT(unreachable); 557 DEFINE_RPCB_ERROR_EVENT(unrecognized); 558 559 TRACE_EVENT(rpc_buf_alloc, 560 TP_PROTO( 561 const struct rpc_task *task, 562 int status 563 ), 564 565 TP_ARGS(task, status), 566 567 TP_STRUCT__entry( 568 __field(unsigned int, task_id) 569 __field(unsigned int, client_id) 570 __field(size_t, callsize) 571 __field(size_t, recvsize) 572 __field(int, status) 573 ), 574 575 TP_fast_assign( 576 __entry->task_id = task->tk_pid; 577 __entry->client_id = task->tk_client->cl_clid; 578 __entry->callsize = task->tk_rqstp->rq_callsize; 579 __entry->recvsize = task->tk_rqstp->rq_rcvsize; 580 __entry->status = status; 581 ), 582 583 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 584 " callsize=%zu recvsize=%zu status=%d", 585 __entry->task_id, __entry->client_id, 586 __entry->callsize, __entry->recvsize, __entry->status 587 ) 588 ); 589 590 TRACE_EVENT(rpc_call_rpcerror, 591 TP_PROTO( 592 const struct rpc_task *task, 593 int tk_status, 594 int rpc_status 595 ), 596 597 TP_ARGS(task, tk_status, rpc_status), 598 599 TP_STRUCT__entry( 600 __field(unsigned int, task_id) 601 __field(unsigned int, client_id) 602 __field(int, tk_status) 603 __field(int, rpc_status) 604 ), 605 606 TP_fast_assign( 607 __entry->client_id = task->tk_client->cl_clid; 608 __entry->task_id = task->tk_pid; 609 __entry->tk_status = tk_status; 610 __entry->rpc_status = rpc_status; 611 ), 612 613 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 614 " tk_status=%d rpc_status=%d", 615 __entry->task_id, __entry->client_id, 616 __entry->tk_status, __entry->rpc_status) 617 ); 618 619 TRACE_EVENT(rpc_stats_latency, 620 621 TP_PROTO( 622 const struct rpc_task *task, 623 ktime_t backlog, 624 ktime_t rtt, 625 ktime_t execute 626 ), 627 628 TP_ARGS(task, backlog, rtt, execute), 629 630 TP_STRUCT__entry( 631 __field(unsigned int, task_id) 632 __field(unsigned int, client_id) 633 __field(u32, xid) 634 __field(int, version) 635 __string(progname, task->tk_client->cl_program->name) 636 __string(procname, rpc_proc_name(task)) 637 __field(unsigned long, backlog) 638 __field(unsigned long, rtt) 639 __field(unsigned long, execute) 640 __field(u32, xprt_id) 641 ), 642 643 TP_fast_assign( 644 __entry->client_id = task->tk_client->cl_clid; 645 __entry->task_id = task->tk_pid; 646 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 647 __entry->version = task->tk_client->cl_vers; 648 __assign_str(progname); 649 __assign_str(procname); 650 __entry->backlog = ktime_to_us(backlog); 651 __entry->rtt = ktime_to_us(rtt); 652 __entry->execute = ktime_to_us(execute); 653 __entry->xprt_id = task->tk_xprt->id; 654 ), 655 656 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 657 " xid=0x%08x %sv%d %s backlog=%lu rtt=%lu execute=%lu" 658 " xprt_id=%d", 659 __entry->task_id, __entry->client_id, __entry->xid, 660 __get_str(progname), __entry->version, __get_str(procname), 661 __entry->backlog, __entry->rtt, __entry->execute, 662 __entry->xprt_id) 663 ); 664 665 TRACE_EVENT(rpc_xdr_overflow, 666 TP_PROTO( 667 const struct xdr_stream *xdr, 668 size_t requested 669 ), 670 671 TP_ARGS(xdr, requested), 672 673 TP_STRUCT__entry( 674 __field(unsigned int, task_id) 675 __field(unsigned int, client_id) 676 __field(int, version) 677 __field(size_t, requested) 678 __field(const void *, end) 679 __field(const void *, p) 680 __field(const void *, head_base) 681 __field(size_t, head_len) 682 __field(const void *, tail_base) 683 __field(size_t, tail_len) 684 __field(unsigned int, page_len) 685 __field(unsigned int, len) 686 __string(progname, xdr->rqst ? 687 xdr->rqst->rq_task->tk_client->cl_program->name : "unknown") 688 __string(procedure, xdr->rqst ? 689 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name : "unknown") 690 ), 691 692 TP_fast_assign( 693 if (xdr->rqst) { 694 const struct rpc_task *task = xdr->rqst->rq_task; 695 696 __entry->task_id = task->tk_pid; 697 __entry->client_id = task->tk_client->cl_clid; 698 __assign_str(progname); 699 __entry->version = task->tk_client->cl_vers; 700 __assign_str(procedure); 701 } else { 702 __entry->task_id = -1; 703 __entry->client_id = -1; 704 __assign_str(progname); 705 __entry->version = 0; 706 __assign_str(procedure); 707 } 708 __entry->requested = requested; 709 __entry->end = xdr->end; 710 __entry->p = xdr->p; 711 __entry->head_base = xdr->buf->head[0].iov_base, 712 __entry->head_len = xdr->buf->head[0].iov_len, 713 __entry->page_len = xdr->buf->page_len, 714 __entry->tail_base = xdr->buf->tail[0].iov_base, 715 __entry->tail_len = xdr->buf->tail[0].iov_len, 716 __entry->len = xdr->buf->len; 717 ), 718 719 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 720 " %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u", 721 __entry->task_id, __entry->client_id, 722 __get_str(progname), __entry->version, __get_str(procedure), 723 __entry->requested, __entry->p, __entry->end, 724 __entry->head_base, __entry->head_len, 725 __entry->page_len, 726 __entry->tail_base, __entry->tail_len, 727 __entry->len 728 ) 729 ); 730 731 TRACE_EVENT(rpc_xdr_alignment, 732 TP_PROTO( 733 const struct xdr_stream *xdr, 734 size_t offset, 735 unsigned int copied 736 ), 737 738 TP_ARGS(xdr, offset, copied), 739 740 TP_STRUCT__entry( 741 __field(unsigned int, task_id) 742 __field(unsigned int, client_id) 743 __field(int, version) 744 __field(size_t, offset) 745 __field(unsigned int, copied) 746 __field(const void *, head_base) 747 __field(size_t, head_len) 748 __field(const void *, tail_base) 749 __field(size_t, tail_len) 750 __field(unsigned int, page_len) 751 __field(unsigned int, len) 752 __string(progname, 753 xdr->rqst->rq_task->tk_client->cl_program->name) 754 __string(procedure, 755 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name) 756 ), 757 758 TP_fast_assign( 759 const struct rpc_task *task = xdr->rqst->rq_task; 760 761 __entry->task_id = task->tk_pid; 762 __entry->client_id = task->tk_client->cl_clid; 763 __assign_str(progname); 764 __entry->version = task->tk_client->cl_vers; 765 __assign_str(procedure); 766 767 __entry->offset = offset; 768 __entry->copied = copied; 769 __entry->head_base = xdr->buf->head[0].iov_base, 770 __entry->head_len = xdr->buf->head[0].iov_len, 771 __entry->page_len = xdr->buf->page_len, 772 __entry->tail_base = xdr->buf->tail[0].iov_base, 773 __entry->tail_len = xdr->buf->tail[0].iov_len, 774 __entry->len = xdr->buf->len; 775 ), 776 777 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 778 " %sv%d %s offset=%zu copied=%u xdr=[%p,%zu]/%u/[%p,%zu]/%u", 779 __entry->task_id, __entry->client_id, 780 __get_str(progname), __entry->version, __get_str(procedure), 781 __entry->offset, __entry->copied, 782 __entry->head_base, __entry->head_len, 783 __entry->page_len, 784 __entry->tail_base, __entry->tail_len, 785 __entry->len 786 ) 787 ); 788 789 /* 790 * First define the enums in the below macros to be exported to userspace 791 * via TRACE_DEFINE_ENUM(). 792 */ 793 #undef EM 794 #undef EMe 795 #define EM(a, b) TRACE_DEFINE_ENUM(a); 796 #define EMe(a, b) TRACE_DEFINE_ENUM(a); 797 798 #define RPC_SHOW_SOCKET \ 799 EM( SS_FREE, "FREE" ) \ 800 EM( SS_UNCONNECTED, "UNCONNECTED" ) \ 801 EM( SS_CONNECTING, "CONNECTING" ) \ 802 EM( SS_CONNECTED, "CONNECTED" ) \ 803 EMe( SS_DISCONNECTING, "DISCONNECTING" ) 804 805 #define rpc_show_socket_state(state) \ 806 __print_symbolic(state, RPC_SHOW_SOCKET) 807 808 RPC_SHOW_SOCKET 809 810 #define RPC_SHOW_SOCK \ 811 EM( TCP_ESTABLISHED, "ESTABLISHED" ) \ 812 EM( TCP_SYN_SENT, "SYN_SENT" ) \ 813 EM( TCP_SYN_RECV, "SYN_RECV" ) \ 814 EM( TCP_FIN_WAIT1, "FIN_WAIT1" ) \ 815 EM( TCP_FIN_WAIT2, "FIN_WAIT2" ) \ 816 EM( TCP_TIME_WAIT, "TIME_WAIT" ) \ 817 EM( TCP_CLOSE, "CLOSE" ) \ 818 EM( TCP_CLOSE_WAIT, "CLOSE_WAIT" ) \ 819 EM( TCP_LAST_ACK, "LAST_ACK" ) \ 820 EM( TCP_LISTEN, "LISTEN" ) \ 821 EMe( TCP_CLOSING, "CLOSING" ) 822 823 #define rpc_show_sock_state(state) \ 824 __print_symbolic(state, RPC_SHOW_SOCK) 825 826 RPC_SHOW_SOCK 827 828 829 #include <trace/events/net_probe_common.h> 830 831 /* 832 * Now redefine the EM() and EMe() macros to map the enums to the strings 833 * that will be printed in the output. 834 */ 835 #undef EM 836 #undef EMe 837 #define EM(a, b) {a, b}, 838 #define EMe(a, b) {a, b} 839 840 DECLARE_EVENT_CLASS(xs_socket_event, 841 842 TP_PROTO( 843 struct rpc_xprt *xprt, 844 struct socket *socket 845 ), 846 847 TP_ARGS(xprt, socket), 848 849 TP_STRUCT__entry( 850 __field(unsigned int, socket_state) 851 __field(unsigned int, sock_state) 852 __field(unsigned long long, ino) 853 __array(__u8, saddr, sizeof(struct sockaddr_in6)) 854 __array(__u8, daddr, sizeof(struct sockaddr_in6)) 855 ), 856 857 TP_fast_assign( 858 struct inode *inode = SOCK_INODE(socket); 859 const struct sock *sk = socket->sk; 860 const struct inet_sock *inet = inet_sk(sk); 861 862 memset(__entry->saddr, 0, sizeof(struct sockaddr_in6)); 863 memset(__entry->daddr, 0, sizeof(struct sockaddr_in6)); 864 865 TP_STORE_ADDR_PORTS(__entry, inet, sk); 866 867 __entry->socket_state = socket->state; 868 __entry->sock_state = socket->sk->sk_state; 869 __entry->ino = (unsigned long long)inode->i_ino; 870 871 ), 872 873 TP_printk( 874 "socket:[%llu] srcaddr=%pISpc dstaddr=%pISpc " 875 "state=%u (%s) sk_state=%u (%s)", 876 __entry->ino, 877 __entry->saddr, 878 __entry->daddr, 879 __entry->socket_state, 880 rpc_show_socket_state(__entry->socket_state), 881 __entry->sock_state, 882 rpc_show_sock_state(__entry->sock_state) 883 ) 884 ); 885 #define DEFINE_RPC_SOCKET_EVENT(name) \ 886 DEFINE_EVENT(xs_socket_event, name, \ 887 TP_PROTO( \ 888 struct rpc_xprt *xprt, \ 889 struct socket *socket \ 890 ), \ 891 TP_ARGS(xprt, socket)) 892 893 DECLARE_EVENT_CLASS(xs_socket_event_done, 894 895 TP_PROTO( 896 struct rpc_xprt *xprt, 897 struct socket *socket, 898 int error 899 ), 900 901 TP_ARGS(xprt, socket, error), 902 903 TP_STRUCT__entry( 904 __field(int, error) 905 __field(unsigned int, socket_state) 906 __field(unsigned int, sock_state) 907 __field(unsigned long long, ino) 908 __array(__u8, saddr, sizeof(struct sockaddr_in6)) 909 __array(__u8, daddr, sizeof(struct sockaddr_in6)) 910 ), 911 912 TP_fast_assign( 913 struct inode *inode = SOCK_INODE(socket); 914 const struct sock *sk = socket->sk; 915 const struct inet_sock *inet = inet_sk(sk); 916 917 memset(__entry->saddr, 0, sizeof(struct sockaddr_in6)); 918 memset(__entry->daddr, 0, sizeof(struct sockaddr_in6)); 919 920 TP_STORE_ADDR_PORTS(__entry, inet, sk); 921 922 __entry->socket_state = socket->state; 923 __entry->sock_state = socket->sk->sk_state; 924 __entry->ino = (unsigned long long)inode->i_ino; 925 __entry->error = error; 926 ), 927 928 TP_printk( 929 "error=%d socket:[%llu] srcaddr=%pISpc dstaddr=%pISpc " 930 "state=%u (%s) sk_state=%u (%s)", 931 __entry->error, 932 __entry->ino, 933 __entry->saddr, 934 __entry->daddr, 935 __entry->socket_state, 936 rpc_show_socket_state(__entry->socket_state), 937 __entry->sock_state, 938 rpc_show_sock_state(__entry->sock_state) 939 ) 940 ); 941 #define DEFINE_RPC_SOCKET_EVENT_DONE(name) \ 942 DEFINE_EVENT(xs_socket_event_done, name, \ 943 TP_PROTO( \ 944 struct rpc_xprt *xprt, \ 945 struct socket *socket, \ 946 int error \ 947 ), \ 948 TP_ARGS(xprt, socket, error)) 949 950 DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change); 951 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect); 952 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error); 953 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection); 954 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close); 955 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown); 956 957 TRACE_EVENT(rpc_socket_nospace, 958 TP_PROTO( 959 const struct rpc_rqst *rqst, 960 const struct sock_xprt *transport 961 ), 962 963 TP_ARGS(rqst, transport), 964 965 TP_STRUCT__entry( 966 __field(unsigned int, task_id) 967 __field(unsigned int, client_id) 968 __field(unsigned int, total) 969 __field(unsigned int, remaining) 970 ), 971 972 TP_fast_assign( 973 __entry->task_id = rqst->rq_task->tk_pid; 974 __entry->client_id = rqst->rq_task->tk_client->cl_clid; 975 __entry->total = rqst->rq_slen; 976 __entry->remaining = rqst->rq_slen - transport->xmit.offset; 977 ), 978 979 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 980 " total=%u remaining=%u", 981 __entry->task_id, __entry->client_id, 982 __entry->total, __entry->remaining 983 ) 984 ); 985 986 #define rpc_show_xprt_state(x) \ 987 __print_flags(x, "|", \ 988 { BIT(XPRT_LOCKED), "LOCKED" }, \ 989 { BIT(XPRT_CONNECTED), "CONNECTED" }, \ 990 { BIT(XPRT_CONNECTING), "CONNECTING" }, \ 991 { BIT(XPRT_CLOSE_WAIT), "CLOSE_WAIT" }, \ 992 { BIT(XPRT_BOUND), "BOUND" }, \ 993 { BIT(XPRT_BINDING), "BINDING" }, \ 994 { BIT(XPRT_CLOSING), "CLOSING" }, \ 995 { BIT(XPRT_OFFLINE), "OFFLINE" }, \ 996 { BIT(XPRT_REMOVE), "REMOVE" }, \ 997 { BIT(XPRT_CONGESTED), "CONGESTED" }, \ 998 { BIT(XPRT_CWND_WAIT), "CWND_WAIT" }, \ 999 { BIT(XPRT_WRITE_SPACE), "WRITE_SPACE" }, \ 1000 { BIT(XPRT_SND_IS_COOKIE), "SND_IS_COOKIE" }) 1001 1002 DECLARE_EVENT_CLASS(rpc_xprt_lifetime_class, 1003 TP_PROTO( 1004 const struct rpc_xprt *xprt 1005 ), 1006 1007 TP_ARGS(xprt), 1008 1009 TP_STRUCT__entry( 1010 __field(unsigned long, state) 1011 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 1012 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 1013 ), 1014 1015 TP_fast_assign( 1016 __entry->state = xprt->state; 1017 __assign_str(addr); 1018 __assign_str(port); 1019 ), 1020 1021 TP_printk("peer=[%s]:%s state=%s", 1022 __get_str(addr), __get_str(port), 1023 rpc_show_xprt_state(__entry->state)) 1024 ); 1025 1026 #define DEFINE_RPC_XPRT_LIFETIME_EVENT(name) \ 1027 DEFINE_EVENT(rpc_xprt_lifetime_class, \ 1028 xprt_##name, \ 1029 TP_PROTO( \ 1030 const struct rpc_xprt *xprt \ 1031 ), \ 1032 TP_ARGS(xprt)) 1033 1034 DEFINE_RPC_XPRT_LIFETIME_EVENT(create); 1035 DEFINE_RPC_XPRT_LIFETIME_EVENT(connect); 1036 DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_auto); 1037 DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_done); 1038 DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_force); 1039 DEFINE_RPC_XPRT_LIFETIME_EVENT(destroy); 1040 1041 DECLARE_EVENT_CLASS(rpc_xprt_event, 1042 TP_PROTO( 1043 const struct rpc_xprt *xprt, 1044 __be32 xid, 1045 int status 1046 ), 1047 1048 TP_ARGS(xprt, xid, status), 1049 1050 TP_STRUCT__entry( 1051 __field(u32, xid) 1052 __field(int, status) 1053 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 1054 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 1055 ), 1056 1057 TP_fast_assign( 1058 __entry->xid = be32_to_cpu(xid); 1059 __entry->status = status; 1060 __assign_str(addr); 1061 __assign_str(port); 1062 ), 1063 1064 TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr), 1065 __get_str(port), __entry->xid, 1066 __entry->status) 1067 ); 1068 #define DEFINE_RPC_XPRT_EVENT(name) \ 1069 DEFINE_EVENT(rpc_xprt_event, xprt_##name, \ 1070 TP_PROTO( \ 1071 const struct rpc_xprt *xprt, \ 1072 __be32 xid, \ 1073 int status \ 1074 ), \ 1075 TP_ARGS(xprt, xid, status)) 1076 1077 DEFINE_RPC_XPRT_EVENT(timer); 1078 DEFINE_RPC_XPRT_EVENT(lookup_rqst); 1079 1080 TRACE_EVENT(xprt_transmit, 1081 TP_PROTO( 1082 const struct rpc_rqst *rqst, 1083 int status 1084 ), 1085 1086 TP_ARGS(rqst, status), 1087 1088 TP_STRUCT__entry( 1089 __field(unsigned int, task_id) 1090 __field(unsigned int, client_id) 1091 __field(u32, xid) 1092 __field(u32, seqno) 1093 __field(int, status) 1094 ), 1095 1096 TP_fast_assign( 1097 __entry->task_id = rqst->rq_task->tk_pid; 1098 __entry->client_id = rqst->rq_task->tk_client ? 1099 rqst->rq_task->tk_client->cl_clid : -1; 1100 __entry->xid = be32_to_cpu(rqst->rq_xid); 1101 __entry->seqno = *rqst->rq_seqnos; 1102 __entry->status = status; 1103 ), 1104 1105 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1106 " xid=0x%08x seqno=%u status=%d", 1107 __entry->task_id, __entry->client_id, __entry->xid, 1108 __entry->seqno, __entry->status) 1109 ); 1110 1111 TRACE_EVENT(xprt_retransmit, 1112 TP_PROTO( 1113 const struct rpc_rqst *rqst 1114 ), 1115 1116 TP_ARGS(rqst), 1117 1118 TP_STRUCT__entry( 1119 __field(unsigned int, task_id) 1120 __field(unsigned int, client_id) 1121 __field(u32, xid) 1122 __field(int, ntrans) 1123 __field(int, version) 1124 __field(unsigned long, timeout) 1125 __string(progname, 1126 rqst->rq_task->tk_client->cl_program->name) 1127 __string(procname, rpc_proc_name(rqst->rq_task)) 1128 ), 1129 1130 TP_fast_assign( 1131 struct rpc_task *task = rqst->rq_task; 1132 1133 __entry->task_id = task->tk_pid; 1134 __entry->client_id = task->tk_client ? 1135 task->tk_client->cl_clid : -1; 1136 __entry->xid = be32_to_cpu(rqst->rq_xid); 1137 __entry->ntrans = rqst->rq_ntrans; 1138 __entry->timeout = task->tk_timeout; 1139 __assign_str(progname); 1140 __entry->version = task->tk_client->cl_vers; 1141 __assign_str(procname); 1142 ), 1143 1144 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1145 " xid=0x%08x %sv%d %s ntrans=%d timeout=%lu", 1146 __entry->task_id, __entry->client_id, __entry->xid, 1147 __get_str(progname), __entry->version, __get_str(procname), 1148 __entry->ntrans, __entry->timeout 1149 ) 1150 ); 1151 1152 TRACE_EVENT(xprt_ping, 1153 TP_PROTO(const struct rpc_xprt *xprt, int status), 1154 1155 TP_ARGS(xprt, status), 1156 1157 TP_STRUCT__entry( 1158 __field(int, status) 1159 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 1160 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 1161 ), 1162 1163 TP_fast_assign( 1164 __entry->status = status; 1165 __assign_str(addr); 1166 __assign_str(port); 1167 ), 1168 1169 TP_printk("peer=[%s]:%s status=%d", 1170 __get_str(addr), __get_str(port), __entry->status) 1171 ); 1172 1173 DECLARE_EVENT_CLASS(xprt_writelock_event, 1174 TP_PROTO( 1175 const struct rpc_xprt *xprt, const struct rpc_task *task 1176 ), 1177 1178 TP_ARGS(xprt, task), 1179 1180 TP_STRUCT__entry( 1181 __field(unsigned int, task_id) 1182 __field(unsigned int, client_id) 1183 __field(unsigned int, snd_task_id) 1184 ), 1185 1186 TP_fast_assign( 1187 if (task) { 1188 __entry->task_id = task->tk_pid; 1189 __entry->client_id = task->tk_client ? 1190 task->tk_client->cl_clid : -1; 1191 } else { 1192 __entry->task_id = -1; 1193 __entry->client_id = -1; 1194 } 1195 if (xprt->snd_task && 1196 !test_bit(XPRT_SND_IS_COOKIE, &xprt->state)) 1197 __entry->snd_task_id = xprt->snd_task->tk_pid; 1198 else 1199 __entry->snd_task_id = -1; 1200 ), 1201 1202 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1203 " snd_task:" SUNRPC_TRACE_PID_SPECIFIER, 1204 __entry->task_id, __entry->client_id, 1205 __entry->snd_task_id) 1206 ); 1207 1208 #define DEFINE_WRITELOCK_EVENT(name) \ 1209 DEFINE_EVENT(xprt_writelock_event, xprt_##name, \ 1210 TP_PROTO( \ 1211 const struct rpc_xprt *xprt, \ 1212 const struct rpc_task *task \ 1213 ), \ 1214 TP_ARGS(xprt, task)) 1215 1216 DEFINE_WRITELOCK_EVENT(reserve_xprt); 1217 DEFINE_WRITELOCK_EVENT(release_xprt); 1218 1219 DECLARE_EVENT_CLASS(xprt_cong_event, 1220 TP_PROTO( 1221 const struct rpc_xprt *xprt, const struct rpc_task *task 1222 ), 1223 1224 TP_ARGS(xprt, task), 1225 1226 TP_STRUCT__entry( 1227 __field(unsigned int, task_id) 1228 __field(unsigned int, client_id) 1229 __field(unsigned int, snd_task_id) 1230 __field(unsigned long, cong) 1231 __field(unsigned long, cwnd) 1232 __field(bool, wait) 1233 ), 1234 1235 TP_fast_assign( 1236 if (task) { 1237 __entry->task_id = task->tk_pid; 1238 __entry->client_id = task->tk_client ? 1239 task->tk_client->cl_clid : -1; 1240 } else { 1241 __entry->task_id = -1; 1242 __entry->client_id = -1; 1243 } 1244 if (xprt->snd_task && 1245 !test_bit(XPRT_SND_IS_COOKIE, &xprt->state)) 1246 __entry->snd_task_id = xprt->snd_task->tk_pid; 1247 else 1248 __entry->snd_task_id = -1; 1249 1250 __entry->cong = xprt->cong; 1251 __entry->cwnd = xprt->cwnd; 1252 __entry->wait = test_bit(XPRT_CWND_WAIT, &xprt->state); 1253 ), 1254 1255 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1256 " snd_task:" SUNRPC_TRACE_PID_SPECIFIER 1257 " cong=%lu cwnd=%lu%s", 1258 __entry->task_id, __entry->client_id, 1259 __entry->snd_task_id, __entry->cong, __entry->cwnd, 1260 __entry->wait ? " (wait)" : "") 1261 ); 1262 1263 #define DEFINE_CONG_EVENT(name) \ 1264 DEFINE_EVENT(xprt_cong_event, xprt_##name, \ 1265 TP_PROTO( \ 1266 const struct rpc_xprt *xprt, \ 1267 const struct rpc_task *task \ 1268 ), \ 1269 TP_ARGS(xprt, task)) 1270 1271 DEFINE_CONG_EVENT(reserve_cong); 1272 DEFINE_CONG_EVENT(release_cong); 1273 DEFINE_CONG_EVENT(get_cong); 1274 DEFINE_CONG_EVENT(put_cong); 1275 1276 TRACE_EVENT(xprt_reserve, 1277 TP_PROTO( 1278 const struct rpc_rqst *rqst 1279 ), 1280 1281 TP_ARGS(rqst), 1282 1283 TP_STRUCT__entry( 1284 __field(unsigned int, task_id) 1285 __field(unsigned int, client_id) 1286 __field(u32, xid) 1287 ), 1288 1289 TP_fast_assign( 1290 __entry->task_id = rqst->rq_task->tk_pid; 1291 __entry->client_id = rqst->rq_task->tk_client->cl_clid; 1292 __entry->xid = be32_to_cpu(rqst->rq_xid); 1293 ), 1294 1295 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " xid=0x%08x", 1296 __entry->task_id, __entry->client_id, __entry->xid 1297 ) 1298 ); 1299 1300 TRACE_EVENT(xs_data_ready, 1301 TP_PROTO( 1302 const struct rpc_xprt *xprt 1303 ), 1304 1305 TP_ARGS(xprt), 1306 1307 TP_STRUCT__entry( 1308 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 1309 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 1310 ), 1311 1312 TP_fast_assign( 1313 __assign_str(addr); 1314 __assign_str(port); 1315 ), 1316 1317 TP_printk("peer=[%s]:%s", __get_str(addr), __get_str(port)) 1318 ); 1319 1320 TRACE_EVENT(xs_stream_read_data, 1321 TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total), 1322 1323 TP_ARGS(xprt, err, total), 1324 1325 TP_STRUCT__entry( 1326 __field(ssize_t, err) 1327 __field(size_t, total) 1328 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] : 1329 EVENT_NULL_STR) 1330 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] : 1331 EVENT_NULL_STR) 1332 ), 1333 1334 TP_fast_assign( 1335 __entry->err = err; 1336 __entry->total = total; 1337 __assign_str(addr); 1338 __assign_str(port); 1339 ), 1340 1341 TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr), 1342 __get_str(port), __entry->err, __entry->total) 1343 ); 1344 1345 TRACE_EVENT(xs_stream_read_request, 1346 TP_PROTO(struct sock_xprt *xs), 1347 1348 TP_ARGS(xs), 1349 1350 TP_STRUCT__entry( 1351 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]) 1352 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]) 1353 __field(u32, xid) 1354 __field(unsigned long, copied) 1355 __field(unsigned int, reclen) 1356 __field(unsigned int, offset) 1357 ), 1358 1359 TP_fast_assign( 1360 __assign_str(addr); 1361 __assign_str(port); 1362 __entry->xid = be32_to_cpu(xs->recv.xid); 1363 __entry->copied = xs->recv.copied; 1364 __entry->reclen = xs->recv.len; 1365 __entry->offset = xs->recv.offset; 1366 ), 1367 1368 TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u", 1369 __get_str(addr), __get_str(port), __entry->xid, 1370 __entry->copied, __entry->reclen, __entry->offset) 1371 ); 1372 1373 TRACE_EVENT(rpcb_getport, 1374 TP_PROTO( 1375 const struct rpc_clnt *clnt, 1376 const struct rpc_task *task, 1377 unsigned int bind_version 1378 ), 1379 1380 TP_ARGS(clnt, task, bind_version), 1381 1382 TP_STRUCT__entry( 1383 __field(unsigned int, task_id) 1384 __field(unsigned int, client_id) 1385 __field(unsigned int, program) 1386 __field(unsigned int, version) 1387 __field(int, protocol) 1388 __field(unsigned int, bind_version) 1389 __string(servername, task->tk_xprt->servername) 1390 ), 1391 1392 TP_fast_assign( 1393 __entry->task_id = task->tk_pid; 1394 __entry->client_id = clnt->cl_clid; 1395 __entry->program = clnt->cl_prog; 1396 __entry->version = clnt->cl_vers; 1397 __entry->protocol = task->tk_xprt->prot; 1398 __entry->bind_version = bind_version; 1399 __assign_str(servername); 1400 ), 1401 1402 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1403 " server=%s program=%u version=%u protocol=%d bind_version=%u", 1404 __entry->task_id, __entry->client_id, __get_str(servername), 1405 __entry->program, __entry->version, __entry->protocol, 1406 __entry->bind_version 1407 ) 1408 ); 1409 1410 TRACE_EVENT(rpcb_setport, 1411 TP_PROTO( 1412 const struct rpc_task *task, 1413 int status, 1414 unsigned short port 1415 ), 1416 1417 TP_ARGS(task, status, port), 1418 1419 TP_STRUCT__entry( 1420 __field(unsigned int, task_id) 1421 __field(unsigned int, client_id) 1422 __field(int, status) 1423 __field(unsigned short, port) 1424 ), 1425 1426 TP_fast_assign( 1427 __entry->task_id = task->tk_pid; 1428 __entry->client_id = task->tk_client->cl_clid; 1429 __entry->status = status; 1430 __entry->port = port; 1431 ), 1432 1433 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " status=%d port=%u", 1434 __entry->task_id, __entry->client_id, 1435 __entry->status, __entry->port 1436 ) 1437 ); 1438 1439 TRACE_EVENT(pmap_register, 1440 TP_PROTO( 1441 u32 program, 1442 u32 version, 1443 int protocol, 1444 unsigned short port 1445 ), 1446 1447 TP_ARGS(program, version, protocol, port), 1448 1449 TP_STRUCT__entry( 1450 __field(unsigned int, program) 1451 __field(unsigned int, version) 1452 __field(int, protocol) 1453 __field(unsigned int, port) 1454 ), 1455 1456 TP_fast_assign( 1457 __entry->program = program; 1458 __entry->version = version; 1459 __entry->protocol = protocol; 1460 __entry->port = port; 1461 ), 1462 1463 TP_printk("program=%u version=%u protocol=%d port=%u", 1464 __entry->program, __entry->version, 1465 __entry->protocol, __entry->port 1466 ) 1467 ); 1468 1469 TRACE_EVENT(rpcb_register, 1470 TP_PROTO( 1471 u32 program, 1472 u32 version, 1473 const char *addr, 1474 const char *netid 1475 ), 1476 1477 TP_ARGS(program, version, addr, netid), 1478 1479 TP_STRUCT__entry( 1480 __field(unsigned int, program) 1481 __field(unsigned int, version) 1482 __string(addr, addr) 1483 __string(netid, netid) 1484 ), 1485 1486 TP_fast_assign( 1487 __entry->program = program; 1488 __entry->version = version; 1489 __assign_str(addr); 1490 __assign_str(netid); 1491 ), 1492 1493 TP_printk("program=%u version=%u addr=%s netid=%s", 1494 __entry->program, __entry->version, 1495 __get_str(addr), __get_str(netid) 1496 ) 1497 ); 1498 1499 TRACE_EVENT(rpcb_unregister, 1500 TP_PROTO( 1501 u32 program, 1502 u32 version, 1503 const char *netid 1504 ), 1505 1506 TP_ARGS(program, version, netid), 1507 1508 TP_STRUCT__entry( 1509 __field(unsigned int, program) 1510 __field(unsigned int, version) 1511 __string(netid, netid) 1512 ), 1513 1514 TP_fast_assign( 1515 __entry->program = program; 1516 __entry->version = version; 1517 __assign_str(netid); 1518 ), 1519 1520 TP_printk("program=%u version=%u netid=%s", 1521 __entry->program, __entry->version, __get_str(netid) 1522 ) 1523 ); 1524 1525 /** 1526 ** RPC-over-TLS tracepoints 1527 **/ 1528 1529 DECLARE_EVENT_CLASS(rpc_tls_class, 1530 TP_PROTO( 1531 const struct rpc_clnt *clnt, 1532 const struct rpc_xprt *xprt 1533 ), 1534 1535 TP_ARGS(clnt, xprt), 1536 1537 TP_STRUCT__entry( 1538 __field(unsigned long, requested_policy) 1539 __field(u32, version) 1540 __string(servername, xprt->servername) 1541 __string(progname, clnt->cl_program->name) 1542 ), 1543 1544 TP_fast_assign( 1545 __entry->requested_policy = clnt->cl_xprtsec.policy; 1546 __entry->version = clnt->cl_vers; 1547 __assign_str(servername); 1548 __assign_str(progname); 1549 ), 1550 1551 TP_printk("server=%s %sv%u requested_policy=%s", 1552 __get_str(servername), __get_str(progname), __entry->version, 1553 rpc_show_xprtsec_policy(__entry->requested_policy) 1554 ) 1555 ); 1556 1557 #define DEFINE_RPC_TLS_EVENT(name) \ 1558 DEFINE_EVENT(rpc_tls_class, rpc_tls_##name, \ 1559 TP_PROTO( \ 1560 const struct rpc_clnt *clnt, \ 1561 const struct rpc_xprt *xprt \ 1562 ), \ 1563 TP_ARGS(clnt, xprt)) 1564 1565 DEFINE_RPC_TLS_EVENT(unavailable); 1566 DEFINE_RPC_TLS_EVENT(not_started); 1567 1568 1569 /* Record an xdr_buf containing a fully-formed RPC message */ 1570 DECLARE_EVENT_CLASS(svc_xdr_msg_class, 1571 TP_PROTO( 1572 const struct xdr_buf *xdr 1573 ), 1574 1575 TP_ARGS(xdr), 1576 1577 TP_STRUCT__entry( 1578 __field(u32, xid) 1579 __field(const void *, head_base) 1580 __field(size_t, head_len) 1581 __field(const void *, tail_base) 1582 __field(size_t, tail_len) 1583 __field(unsigned int, page_len) 1584 __field(unsigned int, msg_len) 1585 ), 1586 1587 TP_fast_assign( 1588 __be32 *p = (__be32 *)xdr->head[0].iov_base; 1589 1590 __entry->xid = be32_to_cpu(*p); 1591 __entry->head_base = p; 1592 __entry->head_len = xdr->head[0].iov_len; 1593 __entry->tail_base = xdr->tail[0].iov_base; 1594 __entry->tail_len = xdr->tail[0].iov_len; 1595 __entry->page_len = xdr->page_len; 1596 __entry->msg_len = xdr->len; 1597 ), 1598 1599 TP_printk("xid=0x%08x head=[%p,%zu] page=%u tail=[%p,%zu] len=%u", 1600 __entry->xid, 1601 __entry->head_base, __entry->head_len, __entry->page_len, 1602 __entry->tail_base, __entry->tail_len, __entry->msg_len 1603 ) 1604 ); 1605 1606 #define DEFINE_SVCXDRMSG_EVENT(name) \ 1607 DEFINE_EVENT(svc_xdr_msg_class, \ 1608 svc_xdr_##name, \ 1609 TP_PROTO( \ 1610 const struct xdr_buf *xdr \ 1611 ), \ 1612 TP_ARGS(xdr)) 1613 1614 DEFINE_SVCXDRMSG_EVENT(recvfrom); 1615 1616 /* Record an xdr_buf containing arbitrary data, tagged with an XID */ 1617 DECLARE_EVENT_CLASS(svc_xdr_buf_class, 1618 TP_PROTO( 1619 __be32 xid, 1620 const struct xdr_buf *xdr 1621 ), 1622 1623 TP_ARGS(xid, xdr), 1624 1625 TP_STRUCT__entry( 1626 __field(u32, xid) 1627 __field(const void *, head_base) 1628 __field(size_t, head_len) 1629 __field(const void *, tail_base) 1630 __field(size_t, tail_len) 1631 __field(unsigned int, page_base) 1632 __field(unsigned int, page_len) 1633 __field(unsigned int, msg_len) 1634 ), 1635 1636 TP_fast_assign( 1637 __entry->xid = be32_to_cpu(xid); 1638 __entry->head_base = xdr->head[0].iov_base; 1639 __entry->head_len = xdr->head[0].iov_len; 1640 __entry->tail_base = xdr->tail[0].iov_base; 1641 __entry->tail_len = xdr->tail[0].iov_len; 1642 __entry->page_base = xdr->page_base; 1643 __entry->page_len = xdr->page_len; 1644 __entry->msg_len = xdr->len; 1645 ), 1646 1647 TP_printk("xid=0x%08x head=[%p,%zu] page=%u(%u) tail=[%p,%zu] len=%u", 1648 __entry->xid, 1649 __entry->head_base, __entry->head_len, 1650 __entry->page_len, __entry->page_base, 1651 __entry->tail_base, __entry->tail_len, 1652 __entry->msg_len 1653 ) 1654 ); 1655 1656 #define DEFINE_SVCXDRBUF_EVENT(name) \ 1657 DEFINE_EVENT(svc_xdr_buf_class, \ 1658 svc_xdr_##name, \ 1659 TP_PROTO( \ 1660 __be32 xid, \ 1661 const struct xdr_buf *xdr \ 1662 ), \ 1663 TP_ARGS(xid, xdr)) 1664 1665 DEFINE_SVCXDRBUF_EVENT(sendto); 1666 1667 /* 1668 * from include/linux/sunrpc/svc.h 1669 */ 1670 #define SVC_RQST_FLAG_LIST \ 1671 svc_rqst_flag(SECURE) \ 1672 svc_rqst_flag(LOCAL) \ 1673 svc_rqst_flag(USEDEFERRAL) \ 1674 svc_rqst_flag(DROPME) \ 1675 svc_rqst_flag(VICTIM) \ 1676 svc_rqst_flag_end(DATA) 1677 1678 #undef svc_rqst_flag 1679 #undef svc_rqst_flag_end 1680 #define svc_rqst_flag(x) TRACE_DEFINE_ENUM(RQ_##x); 1681 #define svc_rqst_flag_end(x) TRACE_DEFINE_ENUM(RQ_##x); 1682 1683 SVC_RQST_FLAG_LIST 1684 1685 #undef svc_rqst_flag 1686 #undef svc_rqst_flag_end 1687 #define svc_rqst_flag(x) { BIT(RQ_##x), #x }, 1688 #define svc_rqst_flag_end(x) { BIT(RQ_##x), #x } 1689 1690 #define show_rqstp_flags(flags) \ 1691 __print_flags(flags, "|", SVC_RQST_FLAG_LIST) 1692 1693 TRACE_DEFINE_ENUM(SVC_GARBAGE); 1694 TRACE_DEFINE_ENUM(SVC_VALID); 1695 TRACE_DEFINE_ENUM(SVC_NEGATIVE); 1696 TRACE_DEFINE_ENUM(SVC_OK); 1697 TRACE_DEFINE_ENUM(SVC_DROP); 1698 TRACE_DEFINE_ENUM(SVC_CLOSE); 1699 TRACE_DEFINE_ENUM(SVC_DENIED); 1700 TRACE_DEFINE_ENUM(SVC_PENDING); 1701 TRACE_DEFINE_ENUM(SVC_COMPLETE); 1702 1703 #define show_svc_auth_status(status) \ 1704 __print_symbolic(status, \ 1705 { SVC_GARBAGE, "SVC_GARBAGE" }, \ 1706 { SVC_VALID, "SVC_VALID" }, \ 1707 { SVC_NEGATIVE, "SVC_NEGATIVE" }, \ 1708 { SVC_OK, "SVC_OK" }, \ 1709 { SVC_DROP, "SVC_DROP" }, \ 1710 { SVC_CLOSE, "SVC_CLOSE" }, \ 1711 { SVC_DENIED, "SVC_DENIED" }, \ 1712 { SVC_PENDING, "SVC_PENDING" }, \ 1713 { SVC_COMPLETE, "SVC_COMPLETE" }) 1714 1715 #define SVC_RQST_ENDPOINT_FIELDS(r) \ 1716 __sockaddr(server, (r)->rq_xprt->xpt_locallen) \ 1717 __sockaddr(client, (r)->rq_xprt->xpt_remotelen) \ 1718 __field(unsigned int, netns_ino) \ 1719 __field(u32, xid) 1720 1721 #define SVC_RQST_ENDPOINT_ASSIGNMENTS(r) \ 1722 do { \ 1723 struct svc_xprt *xprt = (r)->rq_xprt; \ 1724 __assign_sockaddr(server, &xprt->xpt_local, \ 1725 xprt->xpt_locallen); \ 1726 __assign_sockaddr(client, &xprt->xpt_remote, \ 1727 xprt->xpt_remotelen); \ 1728 __entry->netns_ino = xprt->xpt_net->ns.inum; \ 1729 __entry->xid = be32_to_cpu((r)->rq_xid); \ 1730 } while (0) 1731 1732 #define SVC_RQST_ENDPOINT_FORMAT \ 1733 "xid=0x%08x server=%pISpc client=%pISpc" 1734 1735 #define SVC_RQST_ENDPOINT_VARARGS \ 1736 __entry->xid, __get_sockaddr(server), __get_sockaddr(client) 1737 1738 TRACE_EVENT_CONDITION(svc_authenticate, 1739 TP_PROTO( 1740 const struct svc_rqst *rqst, 1741 enum svc_auth_status auth_res 1742 ), 1743 1744 TP_ARGS(rqst, auth_res), 1745 1746 TP_CONDITION(auth_res != SVC_OK && auth_res != SVC_COMPLETE), 1747 1748 TP_STRUCT__entry( 1749 SVC_RQST_ENDPOINT_FIELDS(rqst) 1750 1751 __field(unsigned long, svc_status) 1752 __field(unsigned long, auth_stat) 1753 ), 1754 1755 TP_fast_assign( 1756 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1757 1758 __entry->svc_status = auth_res; 1759 __entry->auth_stat = be32_to_cpu(rqst->rq_auth_stat); 1760 ), 1761 1762 TP_printk(SVC_RQST_ENDPOINT_FORMAT 1763 " auth_res=%s auth_stat=%s", 1764 SVC_RQST_ENDPOINT_VARARGS, 1765 show_svc_auth_status(__entry->svc_status), 1766 rpc_show_auth_stat(__entry->auth_stat)) 1767 ); 1768 1769 TRACE_EVENT(svc_process, 1770 TP_PROTO(const struct svc_rqst *rqst, const char *name), 1771 1772 TP_ARGS(rqst, name), 1773 1774 TP_STRUCT__entry( 1775 __field(u32, xid) 1776 __field(u32, vers) 1777 __field(u32, proc) 1778 __string(service, name) 1779 __string(procedure, svc_proc_name(rqst)) 1780 __string(addr, rqst->rq_xprt ? 1781 rqst->rq_xprt->xpt_remotebuf : EVENT_NULL_STR) 1782 ), 1783 1784 TP_fast_assign( 1785 __entry->xid = be32_to_cpu(rqst->rq_xid); 1786 __entry->vers = rqst->rq_vers; 1787 __entry->proc = rqst->rq_proc; 1788 __assign_str(service); 1789 __assign_str(procedure); 1790 __assign_str(addr); 1791 ), 1792 1793 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%s", 1794 __get_str(addr), __entry->xid, 1795 __get_str(service), __entry->vers, 1796 __get_str(procedure) 1797 ) 1798 ); 1799 1800 DECLARE_EVENT_CLASS(svc_rqst_event, 1801 TP_PROTO( 1802 const struct svc_rqst *rqst 1803 ), 1804 1805 TP_ARGS(rqst), 1806 1807 TP_STRUCT__entry( 1808 SVC_RQST_ENDPOINT_FIELDS(rqst) 1809 1810 __field(unsigned long, flags) 1811 ), 1812 1813 TP_fast_assign( 1814 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1815 1816 __entry->flags = rqst->rq_flags; 1817 ), 1818 1819 TP_printk(SVC_RQST_ENDPOINT_FORMAT " flags=%s", 1820 SVC_RQST_ENDPOINT_VARARGS, 1821 show_rqstp_flags(__entry->flags)) 1822 ); 1823 #define DEFINE_SVC_RQST_EVENT(name) \ 1824 DEFINE_EVENT(svc_rqst_event, svc_##name, \ 1825 TP_PROTO( \ 1826 const struct svc_rqst *rqst \ 1827 ), \ 1828 TP_ARGS(rqst)) 1829 1830 DEFINE_SVC_RQST_EVENT(defer); 1831 DEFINE_SVC_RQST_EVENT(drop); 1832 1833 DECLARE_EVENT_CLASS(svc_rqst_status, 1834 TP_PROTO( 1835 const struct svc_rqst *rqst, 1836 int status 1837 ), 1838 1839 TP_ARGS(rqst, status), 1840 1841 TP_STRUCT__entry( 1842 SVC_RQST_ENDPOINT_FIELDS(rqst) 1843 1844 __field(int, status) 1845 __field(unsigned long, flags) 1846 ), 1847 1848 TP_fast_assign( 1849 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1850 1851 __entry->status = status; 1852 __entry->flags = rqst->rq_flags; 1853 ), 1854 1855 TP_printk(SVC_RQST_ENDPOINT_FORMAT " status=%d flags=%s", 1856 SVC_RQST_ENDPOINT_VARARGS, 1857 __entry->status, show_rqstp_flags(__entry->flags)) 1858 ); 1859 1860 DEFINE_EVENT(svc_rqst_status, svc_send, 1861 TP_PROTO(const struct svc_rqst *rqst, int status), 1862 TP_ARGS(rqst, status)); 1863 1864 TRACE_EVENT(svc_replace_page_err, 1865 TP_PROTO(const struct svc_rqst *rqst), 1866 1867 TP_ARGS(rqst), 1868 TP_STRUCT__entry( 1869 SVC_RQST_ENDPOINT_FIELDS(rqst) 1870 1871 __field(const void *, begin) 1872 __field(const void *, respages) 1873 __field(const void *, nextpage) 1874 ), 1875 1876 TP_fast_assign( 1877 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1878 1879 __entry->begin = rqst->rq_pages; 1880 __entry->respages = rqst->rq_respages; 1881 __entry->nextpage = rqst->rq_next_page; 1882 ), 1883 1884 TP_printk(SVC_RQST_ENDPOINT_FORMAT " begin=%p respages=%p nextpage=%p", 1885 SVC_RQST_ENDPOINT_VARARGS, 1886 __entry->begin, __entry->respages, __entry->nextpage) 1887 ); 1888 1889 TRACE_EVENT(svc_stats_latency, 1890 TP_PROTO( 1891 const struct svc_rqst *rqst 1892 ), 1893 1894 TP_ARGS(rqst), 1895 1896 TP_STRUCT__entry( 1897 SVC_RQST_ENDPOINT_FIELDS(rqst) 1898 1899 __field(unsigned long, execute) 1900 __string(procedure, svc_proc_name(rqst)) 1901 ), 1902 1903 TP_fast_assign( 1904 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1905 1906 __entry->execute = ktime_to_us(ktime_sub(ktime_get(), 1907 rqst->rq_stime)); 1908 __assign_str(procedure); 1909 ), 1910 1911 TP_printk(SVC_RQST_ENDPOINT_FORMAT " proc=%s execute-us=%lu", 1912 SVC_RQST_ENDPOINT_VARARGS, 1913 __get_str(procedure), __entry->execute) 1914 ); 1915 1916 /* 1917 * from include/linux/sunrpc/svc_xprt.h 1918 */ 1919 #define SVC_XPRT_FLAG_LIST \ 1920 svc_xprt_flag(BUSY) \ 1921 svc_xprt_flag(CONN) \ 1922 svc_xprt_flag(CLOSE) \ 1923 svc_xprt_flag(DATA) \ 1924 svc_xprt_flag(TEMP) \ 1925 svc_xprt_flag(DEAD) \ 1926 svc_xprt_flag(CHNGBUF) \ 1927 svc_xprt_flag(DEFERRED) \ 1928 svc_xprt_flag(OLD) \ 1929 svc_xprt_flag(LISTENER) \ 1930 svc_xprt_flag(CACHE_AUTH) \ 1931 svc_xprt_flag(LOCAL) \ 1932 svc_xprt_flag(KILL_TEMP) \ 1933 svc_xprt_flag(CONG_CTRL) \ 1934 svc_xprt_flag(HANDSHAKE) \ 1935 svc_xprt_flag(TLS_SESSION) \ 1936 svc_xprt_flag_end(PEER_AUTH) 1937 1938 #undef svc_xprt_flag 1939 #undef svc_xprt_flag_end 1940 #define svc_xprt_flag(x) TRACE_DEFINE_ENUM(XPT_##x); 1941 #define svc_xprt_flag_end(x) TRACE_DEFINE_ENUM(XPT_##x); 1942 1943 SVC_XPRT_FLAG_LIST 1944 1945 #undef svc_xprt_flag 1946 #undef svc_xprt_flag_end 1947 #define svc_xprt_flag(x) { BIT(XPT_##x), #x }, 1948 #define svc_xprt_flag_end(x) { BIT(XPT_##x), #x } 1949 1950 #define show_svc_xprt_flags(flags) \ 1951 __print_flags(flags, "|", SVC_XPRT_FLAG_LIST) 1952 1953 TRACE_EVENT(svc_xprt_create_err, 1954 TP_PROTO( 1955 const char *program, 1956 const char *protocol, 1957 struct sockaddr *sap, 1958 size_t salen, 1959 const struct svc_xprt *xprt 1960 ), 1961 1962 TP_ARGS(program, protocol, sap, salen, xprt), 1963 1964 TP_STRUCT__entry( 1965 __field(long, error) 1966 __string(program, program) 1967 __string(protocol, protocol) 1968 __sockaddr(addr, salen) 1969 ), 1970 1971 TP_fast_assign( 1972 __entry->error = PTR_ERR(xprt); 1973 __assign_str(program); 1974 __assign_str(protocol); 1975 __assign_sockaddr(addr, sap, salen); 1976 ), 1977 1978 TP_printk("addr=%pISpc program=%s protocol=%s error=%ld", 1979 __get_sockaddr(addr), __get_str(program), __get_str(protocol), 1980 __entry->error) 1981 ); 1982 1983 #define SVC_XPRT_ENDPOINT_FIELDS(x) \ 1984 __sockaddr(server, (x)->xpt_locallen) \ 1985 __sockaddr(client, (x)->xpt_remotelen) \ 1986 __field(unsigned long, flags) \ 1987 __field(unsigned int, netns_ino) 1988 1989 #define SVC_XPRT_ENDPOINT_ASSIGNMENTS(x) \ 1990 do { \ 1991 __assign_sockaddr(server, &(x)->xpt_local, \ 1992 (x)->xpt_locallen); \ 1993 __assign_sockaddr(client, &(x)->xpt_remote, \ 1994 (x)->xpt_remotelen); \ 1995 __entry->flags = (x)->xpt_flags; \ 1996 __entry->netns_ino = (x)->xpt_net->ns.inum; \ 1997 } while (0) 1998 1999 #define SVC_XPRT_ENDPOINT_FORMAT \ 2000 "server=%pISpc client=%pISpc flags=%s" 2001 2002 #define SVC_XPRT_ENDPOINT_VARARGS \ 2003 __get_sockaddr(server), __get_sockaddr(client), \ 2004 show_svc_xprt_flags(__entry->flags) 2005 2006 TRACE_EVENT(svc_xprt_enqueue, 2007 TP_PROTO( 2008 const struct svc_xprt *xprt, 2009 unsigned long flags 2010 ), 2011 2012 TP_ARGS(xprt, flags), 2013 2014 TP_STRUCT__entry( 2015 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2016 ), 2017 2018 TP_fast_assign( 2019 __assign_sockaddr(server, &xprt->xpt_local, 2020 xprt->xpt_locallen); 2021 __assign_sockaddr(client, &xprt->xpt_remote, 2022 xprt->xpt_remotelen); 2023 __entry->flags = flags; 2024 __entry->netns_ino = xprt->xpt_net->ns.inum; 2025 ), 2026 2027 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2028 ); 2029 2030 TRACE_EVENT(svc_xprt_dequeue, 2031 TP_PROTO( 2032 const struct svc_rqst *rqst 2033 ), 2034 2035 TP_ARGS(rqst), 2036 2037 TP_STRUCT__entry( 2038 SVC_XPRT_ENDPOINT_FIELDS(rqst->rq_xprt) 2039 __field(unsigned long, wakeup) 2040 __field(unsigned long, qtime) 2041 ), 2042 2043 TP_fast_assign( 2044 ktime_t ktime = ktime_get(); 2045 2046 SVC_XPRT_ENDPOINT_ASSIGNMENTS(rqst->rq_xprt); 2047 __entry->wakeup = ktime_to_us(ktime_sub(ktime, rqst->rq_qtime)); 2048 __entry->qtime = ktime_to_us(ktime_sub(ktime, rqst->rq_xprt->xpt_qtime)); 2049 ), 2050 2051 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " wakeup-us=%lu qtime-us=%lu", 2052 SVC_XPRT_ENDPOINT_VARARGS, __entry->wakeup, __entry->qtime) 2053 ); 2054 2055 DECLARE_EVENT_CLASS(svc_xprt_event, 2056 TP_PROTO( 2057 const struct svc_xprt *xprt 2058 ), 2059 2060 TP_ARGS(xprt), 2061 2062 TP_STRUCT__entry( 2063 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2064 ), 2065 2066 TP_fast_assign( 2067 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2068 ), 2069 2070 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2071 ); 2072 2073 #define DEFINE_SVC_XPRT_EVENT(name) \ 2074 DEFINE_EVENT(svc_xprt_event, svc_xprt_##name, \ 2075 TP_PROTO( \ 2076 const struct svc_xprt *xprt \ 2077 ), \ 2078 TP_ARGS(xprt)) 2079 2080 DEFINE_SVC_XPRT_EVENT(no_write_space); 2081 DEFINE_SVC_XPRT_EVENT(close); 2082 DEFINE_SVC_XPRT_EVENT(detach); 2083 DEFINE_SVC_XPRT_EVENT(free); 2084 2085 #define DEFINE_SVC_TLS_EVENT(name) \ 2086 DEFINE_EVENT(svc_xprt_event, svc_tls_##name, \ 2087 TP_PROTO(const struct svc_xprt *xprt), \ 2088 TP_ARGS(xprt)) 2089 2090 DEFINE_SVC_TLS_EVENT(start); 2091 DEFINE_SVC_TLS_EVENT(upcall); 2092 DEFINE_SVC_TLS_EVENT(unavailable); 2093 DEFINE_SVC_TLS_EVENT(not_started); 2094 DEFINE_SVC_TLS_EVENT(timed_out); 2095 2096 TRACE_EVENT(svc_xprt_accept, 2097 TP_PROTO( 2098 const struct svc_xprt *xprt, 2099 const char *service 2100 ), 2101 2102 TP_ARGS(xprt, service), 2103 2104 TP_STRUCT__entry( 2105 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2106 2107 __string(protocol, xprt->xpt_class->xcl_name) 2108 __string(service, service) 2109 ), 2110 2111 TP_fast_assign( 2112 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2113 2114 __assign_str(protocol); 2115 __assign_str(service); 2116 ), 2117 2118 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " protocol=%s service=%s", 2119 SVC_XPRT_ENDPOINT_VARARGS, 2120 __get_str(protocol), __get_str(service) 2121 ) 2122 ); 2123 2124 DECLARE_EVENT_CLASS(svc_pool_thread_event, 2125 TP_PROTO(const struct svc_pool *pool, pid_t pid), 2126 2127 TP_ARGS(pool, pid), 2128 2129 TP_STRUCT__entry( 2130 __field(unsigned int, pool_id) 2131 __field(pid_t, pid) 2132 ), 2133 2134 TP_fast_assign( 2135 __entry->pool_id = pool->sp_id; 2136 __entry->pid = pid; 2137 ), 2138 2139 TP_printk("pool=%u pid=%d", __entry->pool_id, __entry->pid) 2140 ); 2141 2142 #define DEFINE_SVC_POOL_THREAD_EVENT(name) \ 2143 DEFINE_EVENT(svc_pool_thread_event, svc_pool_thread_##name, \ 2144 TP_PROTO( \ 2145 const struct svc_pool *pool, pid_t pid \ 2146 ), \ 2147 TP_ARGS(pool, pid)) 2148 2149 DEFINE_SVC_POOL_THREAD_EVENT(wake); 2150 DEFINE_SVC_POOL_THREAD_EVENT(running); 2151 DEFINE_SVC_POOL_THREAD_EVENT(noidle); 2152 2153 TRACE_EVENT(svc_alloc_arg_err, 2154 TP_PROTO( 2155 unsigned int requested, 2156 unsigned int allocated 2157 ), 2158 2159 TP_ARGS(requested, allocated), 2160 2161 TP_STRUCT__entry( 2162 __field(unsigned int, requested) 2163 __field(unsigned int, allocated) 2164 ), 2165 2166 TP_fast_assign( 2167 __entry->requested = requested; 2168 __entry->allocated = allocated; 2169 ), 2170 2171 TP_printk("requested=%u allocated=%u", 2172 __entry->requested, __entry->allocated) 2173 ); 2174 2175 DECLARE_EVENT_CLASS(svc_deferred_event, 2176 TP_PROTO( 2177 const struct svc_deferred_req *dr 2178 ), 2179 2180 TP_ARGS(dr), 2181 2182 TP_STRUCT__entry( 2183 __field(const void *, dr) 2184 __field(u32, xid) 2185 __sockaddr(addr, dr->addrlen) 2186 ), 2187 2188 TP_fast_assign( 2189 __entry->dr = dr; 2190 __entry->xid = be32_to_cpu(*(__be32 *)dr->args); 2191 __assign_sockaddr(addr, &dr->addr, dr->addrlen); 2192 ), 2193 2194 TP_printk("addr=%pISpc dr=%p xid=0x%08x", __get_sockaddr(addr), 2195 __entry->dr, __entry->xid) 2196 ); 2197 2198 #define DEFINE_SVC_DEFERRED_EVENT(name) \ 2199 DEFINE_EVENT(svc_deferred_event, svc_defer_##name, \ 2200 TP_PROTO( \ 2201 const struct svc_deferred_req *dr \ 2202 ), \ 2203 TP_ARGS(dr)) 2204 2205 DEFINE_SVC_DEFERRED_EVENT(drop); 2206 DEFINE_SVC_DEFERRED_EVENT(queue); 2207 DEFINE_SVC_DEFERRED_EVENT(recv); 2208 2209 DECLARE_EVENT_CLASS(svcsock_lifetime_class, 2210 TP_PROTO( 2211 const void *svsk, 2212 const struct socket *socket 2213 ), 2214 TP_ARGS(svsk, socket), 2215 TP_STRUCT__entry( 2216 __field(unsigned int, netns_ino) 2217 __field(const void *, svsk) 2218 __field(const void *, sk) 2219 __field(unsigned long, type) 2220 __field(unsigned long, family) 2221 __field(unsigned long, state) 2222 ), 2223 TP_fast_assign( 2224 struct sock *sk = socket->sk; 2225 2226 __entry->netns_ino = sock_net(sk)->ns.inum; 2227 __entry->svsk = svsk; 2228 __entry->sk = sk; 2229 __entry->type = socket->type; 2230 __entry->family = sk->sk_family; 2231 __entry->state = sk->sk_state; 2232 ), 2233 TP_printk("svsk=%p type=%s family=%s%s", 2234 __entry->svsk, show_socket_type(__entry->type), 2235 rpc_show_address_family(__entry->family), 2236 __entry->state == TCP_LISTEN ? " (listener)" : "" 2237 ) 2238 ); 2239 #define DEFINE_SVCSOCK_LIFETIME_EVENT(name) \ 2240 DEFINE_EVENT(svcsock_lifetime_class, name, \ 2241 TP_PROTO( \ 2242 const void *svsk, \ 2243 const struct socket *socket \ 2244 ), \ 2245 TP_ARGS(svsk, socket)) 2246 2247 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_new); 2248 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_free); 2249 2250 TRACE_EVENT(svcsock_marker, 2251 TP_PROTO( 2252 const struct svc_xprt *xprt, 2253 __be32 marker 2254 ), 2255 2256 TP_ARGS(xprt, marker), 2257 2258 TP_STRUCT__entry( 2259 __field(unsigned int, length) 2260 __field(bool, last) 2261 __string(addr, xprt->xpt_remotebuf) 2262 ), 2263 2264 TP_fast_assign( 2265 __entry->length = be32_to_cpu(marker) & RPC_FRAGMENT_SIZE_MASK; 2266 __entry->last = be32_to_cpu(marker) & RPC_LAST_STREAM_FRAGMENT; 2267 __assign_str(addr); 2268 ), 2269 2270 TP_printk("addr=%s length=%u%s", __get_str(addr), 2271 __entry->length, __entry->last ? " (last)" : "") 2272 ); 2273 2274 DECLARE_EVENT_CLASS(svcsock_class, 2275 TP_PROTO( 2276 const struct svc_xprt *xprt, 2277 ssize_t result 2278 ), 2279 2280 TP_ARGS(xprt, result), 2281 2282 TP_STRUCT__entry( 2283 __field(ssize_t, result) 2284 __field(unsigned long, flags) 2285 __string(addr, xprt->xpt_remotebuf) 2286 ), 2287 2288 TP_fast_assign( 2289 __entry->result = result; 2290 __entry->flags = xprt->xpt_flags; 2291 __assign_str(addr); 2292 ), 2293 2294 TP_printk("addr=%s result=%zd flags=%s", __get_str(addr), 2295 __entry->result, show_svc_xprt_flags(__entry->flags) 2296 ) 2297 ); 2298 2299 #define DEFINE_SVCSOCK_EVENT(name) \ 2300 DEFINE_EVENT(svcsock_class, svcsock_##name, \ 2301 TP_PROTO( \ 2302 const struct svc_xprt *xprt, \ 2303 ssize_t result \ 2304 ), \ 2305 TP_ARGS(xprt, result)) 2306 2307 DEFINE_SVCSOCK_EVENT(udp_send); 2308 DEFINE_SVCSOCK_EVENT(udp_recv); 2309 DEFINE_SVCSOCK_EVENT(udp_recv_err); 2310 DEFINE_SVCSOCK_EVENT(tcp_send); 2311 DEFINE_SVCSOCK_EVENT(tcp_recv); 2312 DEFINE_SVCSOCK_EVENT(tcp_recv_eagain); 2313 DEFINE_SVCSOCK_EVENT(tcp_recv_err); 2314 DEFINE_SVCSOCK_EVENT(data_ready); 2315 DEFINE_SVCSOCK_EVENT(write_space); 2316 2317 TRACE_EVENT(svcsock_tcp_recv_short, 2318 TP_PROTO( 2319 const struct svc_xprt *xprt, 2320 u32 expected, 2321 u32 received 2322 ), 2323 2324 TP_ARGS(xprt, expected, received), 2325 2326 TP_STRUCT__entry( 2327 __field(u32, expected) 2328 __field(u32, received) 2329 __field(unsigned long, flags) 2330 __string(addr, xprt->xpt_remotebuf) 2331 ), 2332 2333 TP_fast_assign( 2334 __entry->expected = expected; 2335 __entry->received = received; 2336 __entry->flags = xprt->xpt_flags; 2337 __assign_str(addr); 2338 ), 2339 2340 TP_printk("addr=%s flags=%s expected=%u received=%u", 2341 __get_str(addr), show_svc_xprt_flags(__entry->flags), 2342 __entry->expected, __entry->received 2343 ) 2344 ); 2345 2346 TRACE_EVENT(svcsock_tcp_state, 2347 TP_PROTO( 2348 const struct svc_xprt *xprt, 2349 const struct socket *socket 2350 ), 2351 2352 TP_ARGS(xprt, socket), 2353 2354 TP_STRUCT__entry( 2355 __field(unsigned long, socket_state) 2356 __field(unsigned long, sock_state) 2357 __field(unsigned long, flags) 2358 __string(addr, xprt->xpt_remotebuf) 2359 ), 2360 2361 TP_fast_assign( 2362 __entry->socket_state = socket->state; 2363 __entry->sock_state = socket->sk->sk_state; 2364 __entry->flags = xprt->xpt_flags; 2365 __assign_str(addr); 2366 ), 2367 2368 TP_printk("addr=%s state=%s sk_state=%s flags=%s", __get_str(addr), 2369 rpc_show_socket_state(__entry->socket_state), 2370 rpc_show_sock_state(__entry->sock_state), 2371 show_svc_xprt_flags(__entry->flags) 2372 ) 2373 ); 2374 2375 DECLARE_EVENT_CLASS(svcsock_accept_class, 2376 TP_PROTO( 2377 const struct svc_xprt *xprt, 2378 const char *service, 2379 long status 2380 ), 2381 2382 TP_ARGS(xprt, service, status), 2383 2384 TP_STRUCT__entry( 2385 __field(long, status) 2386 __string(service, service) 2387 __field(unsigned int, netns_ino) 2388 ), 2389 2390 TP_fast_assign( 2391 __entry->status = status; 2392 __assign_str(service); 2393 __entry->netns_ino = xprt->xpt_net->ns.inum; 2394 ), 2395 2396 TP_printk("addr=listener service=%s status=%ld", 2397 __get_str(service), __entry->status 2398 ) 2399 ); 2400 2401 #define DEFINE_ACCEPT_EVENT(name) \ 2402 DEFINE_EVENT(svcsock_accept_class, svcsock_##name##_err, \ 2403 TP_PROTO( \ 2404 const struct svc_xprt *xprt, \ 2405 const char *service, \ 2406 long status \ 2407 ), \ 2408 TP_ARGS(xprt, service, status)) 2409 2410 DEFINE_ACCEPT_EVENT(accept); 2411 DEFINE_ACCEPT_EVENT(getpeername); 2412 2413 DECLARE_EVENT_CLASS(cache_event, 2414 TP_PROTO( 2415 const struct cache_detail *cd, 2416 const struct cache_head *h 2417 ), 2418 2419 TP_ARGS(cd, h), 2420 2421 TP_STRUCT__entry( 2422 __field(const struct cache_head *, h) 2423 __string(name, cd->name) 2424 ), 2425 2426 TP_fast_assign( 2427 __entry->h = h; 2428 __assign_str(name); 2429 ), 2430 2431 TP_printk("cache=%s entry=%p", __get_str(name), __entry->h) 2432 ); 2433 #define DEFINE_CACHE_EVENT(name) \ 2434 DEFINE_EVENT(cache_event, name, \ 2435 TP_PROTO( \ 2436 const struct cache_detail *cd, \ 2437 const struct cache_head *h \ 2438 ), \ 2439 TP_ARGS(cd, h)) 2440 DEFINE_CACHE_EVENT(cache_entry_expired); 2441 DEFINE_CACHE_EVENT(cache_entry_upcall); 2442 DEFINE_CACHE_EVENT(cache_entry_update); 2443 DEFINE_CACHE_EVENT(cache_entry_make_negative); 2444 DEFINE_CACHE_EVENT(cache_entry_no_listener); 2445 2446 DECLARE_EVENT_CLASS(register_class, 2447 TP_PROTO( 2448 const char *program, 2449 const u32 version, 2450 const int family, 2451 const unsigned short protocol, 2452 const unsigned short port, 2453 int error 2454 ), 2455 2456 TP_ARGS(program, version, family, protocol, port, error), 2457 2458 TP_STRUCT__entry( 2459 __field(u32, version) 2460 __field(unsigned long, family) 2461 __field(unsigned short, protocol) 2462 __field(unsigned short, port) 2463 __field(int, error) 2464 __string(program, program) 2465 ), 2466 2467 TP_fast_assign( 2468 __entry->version = version; 2469 __entry->family = family; 2470 __entry->protocol = protocol; 2471 __entry->port = port; 2472 __entry->error = error; 2473 __assign_str(program); 2474 ), 2475 2476 TP_printk("program=%sv%u proto=%s port=%u family=%s error=%d", 2477 __get_str(program), __entry->version, 2478 __entry->protocol == IPPROTO_UDP ? "udp" : "tcp", 2479 __entry->port, rpc_show_address_family(__entry->family), 2480 __entry->error 2481 ) 2482 ); 2483 2484 #define DEFINE_REGISTER_EVENT(name) \ 2485 DEFINE_EVENT(register_class, svc_##name, \ 2486 TP_PROTO( \ 2487 const char *program, \ 2488 const u32 version, \ 2489 const int family, \ 2490 const unsigned short protocol, \ 2491 const unsigned short port, \ 2492 int error \ 2493 ), \ 2494 TP_ARGS(program, version, family, protocol, \ 2495 port, error)) 2496 2497 DEFINE_REGISTER_EVENT(register); 2498 DEFINE_REGISTER_EVENT(noregister); 2499 2500 TRACE_EVENT(svc_unregister, 2501 TP_PROTO( 2502 const char *program, 2503 const u32 version, 2504 int error 2505 ), 2506 2507 TP_ARGS(program, version, error), 2508 2509 TP_STRUCT__entry( 2510 __field(u32, version) 2511 __field(int, error) 2512 __string(program, program) 2513 ), 2514 2515 TP_fast_assign( 2516 __entry->version = version; 2517 __entry->error = error; 2518 __assign_str(program); 2519 ), 2520 2521 TP_printk("program=%sv%u error=%d", 2522 __get_str(program), __entry->version, __entry->error 2523 ) 2524 ); 2525 2526 #endif /* _TRACE_SUNRPC_H */ 2527 2528 #include <trace/define_trace.h> 2529