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