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_seqno; 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_SYSERR); 1695 TRACE_DEFINE_ENUM(SVC_VALID); 1696 TRACE_DEFINE_ENUM(SVC_NEGATIVE); 1697 TRACE_DEFINE_ENUM(SVC_OK); 1698 TRACE_DEFINE_ENUM(SVC_DROP); 1699 TRACE_DEFINE_ENUM(SVC_CLOSE); 1700 TRACE_DEFINE_ENUM(SVC_DENIED); 1701 TRACE_DEFINE_ENUM(SVC_PENDING); 1702 TRACE_DEFINE_ENUM(SVC_COMPLETE); 1703 1704 #define show_svc_auth_status(status) \ 1705 __print_symbolic(status, \ 1706 { SVC_GARBAGE, "SVC_GARBAGE" }, \ 1707 { SVC_SYSERR, "SVC_SYSERR" }, \ 1708 { SVC_VALID, "SVC_VALID" }, \ 1709 { SVC_NEGATIVE, "SVC_NEGATIVE" }, \ 1710 { SVC_OK, "SVC_OK" }, \ 1711 { SVC_DROP, "SVC_DROP" }, \ 1712 { SVC_CLOSE, "SVC_CLOSE" }, \ 1713 { SVC_DENIED, "SVC_DENIED" }, \ 1714 { SVC_PENDING, "SVC_PENDING" }, \ 1715 { SVC_COMPLETE, "SVC_COMPLETE" }) 1716 1717 #define SVC_RQST_ENDPOINT_FIELDS(r) \ 1718 __sockaddr(server, (r)->rq_xprt->xpt_locallen) \ 1719 __sockaddr(client, (r)->rq_xprt->xpt_remotelen) \ 1720 __field(unsigned int, netns_ino) \ 1721 __field(u32, xid) 1722 1723 #define SVC_RQST_ENDPOINT_ASSIGNMENTS(r) \ 1724 do { \ 1725 struct svc_xprt *xprt = (r)->rq_xprt; \ 1726 __assign_sockaddr(server, &xprt->xpt_local, \ 1727 xprt->xpt_locallen); \ 1728 __assign_sockaddr(client, &xprt->xpt_remote, \ 1729 xprt->xpt_remotelen); \ 1730 __entry->netns_ino = xprt->xpt_net->ns.inum; \ 1731 __entry->xid = be32_to_cpu((r)->rq_xid); \ 1732 } while (0) 1733 1734 #define SVC_RQST_ENDPOINT_FORMAT \ 1735 "xid=0x%08x server=%pISpc client=%pISpc" 1736 1737 #define SVC_RQST_ENDPOINT_VARARGS \ 1738 __entry->xid, __get_sockaddr(server), __get_sockaddr(client) 1739 1740 TRACE_EVENT_CONDITION(svc_authenticate, 1741 TP_PROTO( 1742 const struct svc_rqst *rqst, 1743 enum svc_auth_status auth_res 1744 ), 1745 1746 TP_ARGS(rqst, auth_res), 1747 1748 TP_CONDITION(auth_res != SVC_OK && auth_res != SVC_COMPLETE), 1749 1750 TP_STRUCT__entry( 1751 SVC_RQST_ENDPOINT_FIELDS(rqst) 1752 1753 __field(unsigned long, svc_status) 1754 __field(unsigned long, auth_stat) 1755 ), 1756 1757 TP_fast_assign( 1758 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1759 1760 __entry->svc_status = auth_res; 1761 __entry->auth_stat = be32_to_cpu(rqst->rq_auth_stat); 1762 ), 1763 1764 TP_printk(SVC_RQST_ENDPOINT_FORMAT 1765 " auth_res=%s auth_stat=%s", 1766 SVC_RQST_ENDPOINT_VARARGS, 1767 show_svc_auth_status(__entry->svc_status), 1768 rpc_show_auth_stat(__entry->auth_stat)) 1769 ); 1770 1771 TRACE_EVENT(svc_process, 1772 TP_PROTO(const struct svc_rqst *rqst, const char *name), 1773 1774 TP_ARGS(rqst, name), 1775 1776 TP_STRUCT__entry( 1777 __field(u32, xid) 1778 __field(u32, vers) 1779 __field(u32, proc) 1780 __string(service, name) 1781 __string(procedure, svc_proc_name(rqst)) 1782 __string(addr, rqst->rq_xprt ? 1783 rqst->rq_xprt->xpt_remotebuf : EVENT_NULL_STR) 1784 ), 1785 1786 TP_fast_assign( 1787 __entry->xid = be32_to_cpu(rqst->rq_xid); 1788 __entry->vers = rqst->rq_vers; 1789 __entry->proc = rqst->rq_proc; 1790 __assign_str(service); 1791 __assign_str(procedure); 1792 __assign_str(addr); 1793 ), 1794 1795 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%s", 1796 __get_str(addr), __entry->xid, 1797 __get_str(service), __entry->vers, 1798 __get_str(procedure) 1799 ) 1800 ); 1801 1802 DECLARE_EVENT_CLASS(svc_rqst_event, 1803 TP_PROTO( 1804 const struct svc_rqst *rqst 1805 ), 1806 1807 TP_ARGS(rqst), 1808 1809 TP_STRUCT__entry( 1810 SVC_RQST_ENDPOINT_FIELDS(rqst) 1811 1812 __field(unsigned long, flags) 1813 ), 1814 1815 TP_fast_assign( 1816 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1817 1818 __entry->flags = rqst->rq_flags; 1819 ), 1820 1821 TP_printk(SVC_RQST_ENDPOINT_FORMAT " flags=%s", 1822 SVC_RQST_ENDPOINT_VARARGS, 1823 show_rqstp_flags(__entry->flags)) 1824 ); 1825 #define DEFINE_SVC_RQST_EVENT(name) \ 1826 DEFINE_EVENT(svc_rqst_event, svc_##name, \ 1827 TP_PROTO( \ 1828 const struct svc_rqst *rqst \ 1829 ), \ 1830 TP_ARGS(rqst)) 1831 1832 DEFINE_SVC_RQST_EVENT(defer); 1833 DEFINE_SVC_RQST_EVENT(drop); 1834 1835 DECLARE_EVENT_CLASS(svc_rqst_status, 1836 TP_PROTO( 1837 const struct svc_rqst *rqst, 1838 int status 1839 ), 1840 1841 TP_ARGS(rqst, status), 1842 1843 TP_STRUCT__entry( 1844 SVC_RQST_ENDPOINT_FIELDS(rqst) 1845 1846 __field(int, status) 1847 __field(unsigned long, flags) 1848 ), 1849 1850 TP_fast_assign( 1851 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1852 1853 __entry->status = status; 1854 __entry->flags = rqst->rq_flags; 1855 ), 1856 1857 TP_printk(SVC_RQST_ENDPOINT_FORMAT " status=%d flags=%s", 1858 SVC_RQST_ENDPOINT_VARARGS, 1859 __entry->status, show_rqstp_flags(__entry->flags)) 1860 ); 1861 1862 DEFINE_EVENT(svc_rqst_status, svc_send, 1863 TP_PROTO(const struct svc_rqst *rqst, int status), 1864 TP_ARGS(rqst, status)); 1865 1866 TRACE_EVENT(svc_replace_page_err, 1867 TP_PROTO(const struct svc_rqst *rqst), 1868 1869 TP_ARGS(rqst), 1870 TP_STRUCT__entry( 1871 SVC_RQST_ENDPOINT_FIELDS(rqst) 1872 1873 __field(const void *, begin) 1874 __field(const void *, respages) 1875 __field(const void *, nextpage) 1876 ), 1877 1878 TP_fast_assign( 1879 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1880 1881 __entry->begin = rqst->rq_pages; 1882 __entry->respages = rqst->rq_respages; 1883 __entry->nextpage = rqst->rq_next_page; 1884 ), 1885 1886 TP_printk(SVC_RQST_ENDPOINT_FORMAT " begin=%p respages=%p nextpage=%p", 1887 SVC_RQST_ENDPOINT_VARARGS, 1888 __entry->begin, __entry->respages, __entry->nextpage) 1889 ); 1890 1891 TRACE_EVENT(svc_stats_latency, 1892 TP_PROTO( 1893 const struct svc_rqst *rqst 1894 ), 1895 1896 TP_ARGS(rqst), 1897 1898 TP_STRUCT__entry( 1899 SVC_RQST_ENDPOINT_FIELDS(rqst) 1900 1901 __field(unsigned long, execute) 1902 __string(procedure, svc_proc_name(rqst)) 1903 ), 1904 1905 TP_fast_assign( 1906 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1907 1908 __entry->execute = ktime_to_us(ktime_sub(ktime_get(), 1909 rqst->rq_stime)); 1910 __assign_str(procedure); 1911 ), 1912 1913 TP_printk(SVC_RQST_ENDPOINT_FORMAT " proc=%s execute-us=%lu", 1914 SVC_RQST_ENDPOINT_VARARGS, 1915 __get_str(procedure), __entry->execute) 1916 ); 1917 1918 /* 1919 * from include/linux/sunrpc/svc_xprt.h 1920 */ 1921 #define SVC_XPRT_FLAG_LIST \ 1922 svc_xprt_flag(BUSY) \ 1923 svc_xprt_flag(CONN) \ 1924 svc_xprt_flag(CLOSE) \ 1925 svc_xprt_flag(DATA) \ 1926 svc_xprt_flag(TEMP) \ 1927 svc_xprt_flag(DEAD) \ 1928 svc_xprt_flag(CHNGBUF) \ 1929 svc_xprt_flag(DEFERRED) \ 1930 svc_xprt_flag(OLD) \ 1931 svc_xprt_flag(LISTENER) \ 1932 svc_xprt_flag(CACHE_AUTH) \ 1933 svc_xprt_flag(LOCAL) \ 1934 svc_xprt_flag(KILL_TEMP) \ 1935 svc_xprt_flag(CONG_CTRL) \ 1936 svc_xprt_flag(HANDSHAKE) \ 1937 svc_xprt_flag(TLS_SESSION) \ 1938 svc_xprt_flag_end(PEER_AUTH) 1939 1940 #undef svc_xprt_flag 1941 #undef svc_xprt_flag_end 1942 #define svc_xprt_flag(x) TRACE_DEFINE_ENUM(XPT_##x); 1943 #define svc_xprt_flag_end(x) TRACE_DEFINE_ENUM(XPT_##x); 1944 1945 SVC_XPRT_FLAG_LIST 1946 1947 #undef svc_xprt_flag 1948 #undef svc_xprt_flag_end 1949 #define svc_xprt_flag(x) { BIT(XPT_##x), #x }, 1950 #define svc_xprt_flag_end(x) { BIT(XPT_##x), #x } 1951 1952 #define show_svc_xprt_flags(flags) \ 1953 __print_flags(flags, "|", SVC_XPRT_FLAG_LIST) 1954 1955 TRACE_EVENT(svc_xprt_create_err, 1956 TP_PROTO( 1957 const char *program, 1958 const char *protocol, 1959 struct sockaddr *sap, 1960 size_t salen, 1961 const struct svc_xprt *xprt 1962 ), 1963 1964 TP_ARGS(program, protocol, sap, salen, xprt), 1965 1966 TP_STRUCT__entry( 1967 __field(long, error) 1968 __string(program, program) 1969 __string(protocol, protocol) 1970 __sockaddr(addr, salen) 1971 ), 1972 1973 TP_fast_assign( 1974 __entry->error = PTR_ERR(xprt); 1975 __assign_str(program); 1976 __assign_str(protocol); 1977 __assign_sockaddr(addr, sap, salen); 1978 ), 1979 1980 TP_printk("addr=%pISpc program=%s protocol=%s error=%ld", 1981 __get_sockaddr(addr), __get_str(program), __get_str(protocol), 1982 __entry->error) 1983 ); 1984 1985 #define SVC_XPRT_ENDPOINT_FIELDS(x) \ 1986 __sockaddr(server, (x)->xpt_locallen) \ 1987 __sockaddr(client, (x)->xpt_remotelen) \ 1988 __field(unsigned long, flags) \ 1989 __field(unsigned int, netns_ino) 1990 1991 #define SVC_XPRT_ENDPOINT_ASSIGNMENTS(x) \ 1992 do { \ 1993 __assign_sockaddr(server, &(x)->xpt_local, \ 1994 (x)->xpt_locallen); \ 1995 __assign_sockaddr(client, &(x)->xpt_remote, \ 1996 (x)->xpt_remotelen); \ 1997 __entry->flags = (x)->xpt_flags; \ 1998 __entry->netns_ino = (x)->xpt_net->ns.inum; \ 1999 } while (0) 2000 2001 #define SVC_XPRT_ENDPOINT_FORMAT \ 2002 "server=%pISpc client=%pISpc flags=%s" 2003 2004 #define SVC_XPRT_ENDPOINT_VARARGS \ 2005 __get_sockaddr(server), __get_sockaddr(client), \ 2006 show_svc_xprt_flags(__entry->flags) 2007 2008 TRACE_EVENT(svc_xprt_enqueue, 2009 TP_PROTO( 2010 const struct svc_xprt *xprt, 2011 unsigned long flags 2012 ), 2013 2014 TP_ARGS(xprt, flags), 2015 2016 TP_STRUCT__entry( 2017 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2018 ), 2019 2020 TP_fast_assign( 2021 __assign_sockaddr(server, &xprt->xpt_local, 2022 xprt->xpt_locallen); 2023 __assign_sockaddr(client, &xprt->xpt_remote, 2024 xprt->xpt_remotelen); 2025 __entry->flags = flags; 2026 __entry->netns_ino = xprt->xpt_net->ns.inum; 2027 ), 2028 2029 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2030 ); 2031 2032 TRACE_EVENT(svc_xprt_dequeue, 2033 TP_PROTO( 2034 const struct svc_rqst *rqst 2035 ), 2036 2037 TP_ARGS(rqst), 2038 2039 TP_STRUCT__entry( 2040 SVC_XPRT_ENDPOINT_FIELDS(rqst->rq_xprt) 2041 2042 __field(unsigned long, wakeup) 2043 ), 2044 2045 TP_fast_assign( 2046 SVC_XPRT_ENDPOINT_ASSIGNMENTS(rqst->rq_xprt); 2047 2048 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(), 2049 rqst->rq_qtime)); 2050 ), 2051 2052 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " wakeup-us=%lu", 2053 SVC_XPRT_ENDPOINT_VARARGS, __entry->wakeup) 2054 ); 2055 2056 DECLARE_EVENT_CLASS(svc_xprt_event, 2057 TP_PROTO( 2058 const struct svc_xprt *xprt 2059 ), 2060 2061 TP_ARGS(xprt), 2062 2063 TP_STRUCT__entry( 2064 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2065 ), 2066 2067 TP_fast_assign( 2068 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2069 ), 2070 2071 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2072 ); 2073 2074 #define DEFINE_SVC_XPRT_EVENT(name) \ 2075 DEFINE_EVENT(svc_xprt_event, svc_xprt_##name, \ 2076 TP_PROTO( \ 2077 const struct svc_xprt *xprt \ 2078 ), \ 2079 TP_ARGS(xprt)) 2080 2081 DEFINE_SVC_XPRT_EVENT(no_write_space); 2082 DEFINE_SVC_XPRT_EVENT(close); 2083 DEFINE_SVC_XPRT_EVENT(detach); 2084 DEFINE_SVC_XPRT_EVENT(free); 2085 2086 #define DEFINE_SVC_TLS_EVENT(name) \ 2087 DEFINE_EVENT(svc_xprt_event, svc_tls_##name, \ 2088 TP_PROTO(const struct svc_xprt *xprt), \ 2089 TP_ARGS(xprt)) 2090 2091 DEFINE_SVC_TLS_EVENT(start); 2092 DEFINE_SVC_TLS_EVENT(upcall); 2093 DEFINE_SVC_TLS_EVENT(unavailable); 2094 DEFINE_SVC_TLS_EVENT(not_started); 2095 DEFINE_SVC_TLS_EVENT(timed_out); 2096 2097 TRACE_EVENT(svc_xprt_accept, 2098 TP_PROTO( 2099 const struct svc_xprt *xprt, 2100 const char *service 2101 ), 2102 2103 TP_ARGS(xprt, service), 2104 2105 TP_STRUCT__entry( 2106 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2107 2108 __string(protocol, xprt->xpt_class->xcl_name) 2109 __string(service, service) 2110 ), 2111 2112 TP_fast_assign( 2113 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2114 2115 __assign_str(protocol); 2116 __assign_str(service); 2117 ), 2118 2119 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " protocol=%s service=%s", 2120 SVC_XPRT_ENDPOINT_VARARGS, 2121 __get_str(protocol), __get_str(service) 2122 ) 2123 ); 2124 2125 TRACE_EVENT(svc_wake_up, 2126 TP_PROTO(int pid), 2127 2128 TP_ARGS(pid), 2129 2130 TP_STRUCT__entry( 2131 __field(int, pid) 2132 ), 2133 2134 TP_fast_assign( 2135 __entry->pid = pid; 2136 ), 2137 2138 TP_printk("pid=%d", __entry->pid) 2139 ); 2140 2141 TRACE_EVENT(svc_alloc_arg_err, 2142 TP_PROTO( 2143 unsigned int requested, 2144 unsigned int allocated 2145 ), 2146 2147 TP_ARGS(requested, allocated), 2148 2149 TP_STRUCT__entry( 2150 __field(unsigned int, requested) 2151 __field(unsigned int, allocated) 2152 ), 2153 2154 TP_fast_assign( 2155 __entry->requested = requested; 2156 __entry->allocated = allocated; 2157 ), 2158 2159 TP_printk("requested=%u allocated=%u", 2160 __entry->requested, __entry->allocated) 2161 ); 2162 2163 DECLARE_EVENT_CLASS(svc_deferred_event, 2164 TP_PROTO( 2165 const struct svc_deferred_req *dr 2166 ), 2167 2168 TP_ARGS(dr), 2169 2170 TP_STRUCT__entry( 2171 __field(const void *, dr) 2172 __field(u32, xid) 2173 __sockaddr(addr, dr->addrlen) 2174 ), 2175 2176 TP_fast_assign( 2177 __entry->dr = dr; 2178 __entry->xid = be32_to_cpu(*(__be32 *)dr->args); 2179 __assign_sockaddr(addr, &dr->addr, dr->addrlen); 2180 ), 2181 2182 TP_printk("addr=%pISpc dr=%p xid=0x%08x", __get_sockaddr(addr), 2183 __entry->dr, __entry->xid) 2184 ); 2185 2186 #define DEFINE_SVC_DEFERRED_EVENT(name) \ 2187 DEFINE_EVENT(svc_deferred_event, svc_defer_##name, \ 2188 TP_PROTO( \ 2189 const struct svc_deferred_req *dr \ 2190 ), \ 2191 TP_ARGS(dr)) 2192 2193 DEFINE_SVC_DEFERRED_EVENT(drop); 2194 DEFINE_SVC_DEFERRED_EVENT(queue); 2195 DEFINE_SVC_DEFERRED_EVENT(recv); 2196 2197 DECLARE_EVENT_CLASS(svcsock_lifetime_class, 2198 TP_PROTO( 2199 const void *svsk, 2200 const struct socket *socket 2201 ), 2202 TP_ARGS(svsk, socket), 2203 TP_STRUCT__entry( 2204 __field(unsigned int, netns_ino) 2205 __field(const void *, svsk) 2206 __field(const void *, sk) 2207 __field(unsigned long, type) 2208 __field(unsigned long, family) 2209 __field(unsigned long, state) 2210 ), 2211 TP_fast_assign( 2212 struct sock *sk = socket->sk; 2213 2214 __entry->netns_ino = sock_net(sk)->ns.inum; 2215 __entry->svsk = svsk; 2216 __entry->sk = sk; 2217 __entry->type = socket->type; 2218 __entry->family = sk->sk_family; 2219 __entry->state = sk->sk_state; 2220 ), 2221 TP_printk("svsk=%p type=%s family=%s%s", 2222 __entry->svsk, show_socket_type(__entry->type), 2223 rpc_show_address_family(__entry->family), 2224 __entry->state == TCP_LISTEN ? " (listener)" : "" 2225 ) 2226 ); 2227 #define DEFINE_SVCSOCK_LIFETIME_EVENT(name) \ 2228 DEFINE_EVENT(svcsock_lifetime_class, name, \ 2229 TP_PROTO( \ 2230 const void *svsk, \ 2231 const struct socket *socket \ 2232 ), \ 2233 TP_ARGS(svsk, socket)) 2234 2235 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_new); 2236 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_free); 2237 2238 TRACE_EVENT(svcsock_marker, 2239 TP_PROTO( 2240 const struct svc_xprt *xprt, 2241 __be32 marker 2242 ), 2243 2244 TP_ARGS(xprt, marker), 2245 2246 TP_STRUCT__entry( 2247 __field(unsigned int, length) 2248 __field(bool, last) 2249 __string(addr, xprt->xpt_remotebuf) 2250 ), 2251 2252 TP_fast_assign( 2253 __entry->length = be32_to_cpu(marker) & RPC_FRAGMENT_SIZE_MASK; 2254 __entry->last = be32_to_cpu(marker) & RPC_LAST_STREAM_FRAGMENT; 2255 __assign_str(addr); 2256 ), 2257 2258 TP_printk("addr=%s length=%u%s", __get_str(addr), 2259 __entry->length, __entry->last ? " (last)" : "") 2260 ); 2261 2262 DECLARE_EVENT_CLASS(svcsock_class, 2263 TP_PROTO( 2264 const struct svc_xprt *xprt, 2265 ssize_t result 2266 ), 2267 2268 TP_ARGS(xprt, result), 2269 2270 TP_STRUCT__entry( 2271 __field(ssize_t, result) 2272 __field(unsigned long, flags) 2273 __string(addr, xprt->xpt_remotebuf) 2274 ), 2275 2276 TP_fast_assign( 2277 __entry->result = result; 2278 __entry->flags = xprt->xpt_flags; 2279 __assign_str(addr); 2280 ), 2281 2282 TP_printk("addr=%s result=%zd flags=%s", __get_str(addr), 2283 __entry->result, show_svc_xprt_flags(__entry->flags) 2284 ) 2285 ); 2286 2287 #define DEFINE_SVCSOCK_EVENT(name) \ 2288 DEFINE_EVENT(svcsock_class, svcsock_##name, \ 2289 TP_PROTO( \ 2290 const struct svc_xprt *xprt, \ 2291 ssize_t result \ 2292 ), \ 2293 TP_ARGS(xprt, result)) 2294 2295 DEFINE_SVCSOCK_EVENT(udp_send); 2296 DEFINE_SVCSOCK_EVENT(udp_recv); 2297 DEFINE_SVCSOCK_EVENT(udp_recv_err); 2298 DEFINE_SVCSOCK_EVENT(tcp_send); 2299 DEFINE_SVCSOCK_EVENT(tcp_recv); 2300 DEFINE_SVCSOCK_EVENT(tcp_recv_eagain); 2301 DEFINE_SVCSOCK_EVENT(tcp_recv_err); 2302 DEFINE_SVCSOCK_EVENT(data_ready); 2303 DEFINE_SVCSOCK_EVENT(write_space); 2304 2305 TRACE_EVENT(svcsock_tcp_recv_short, 2306 TP_PROTO( 2307 const struct svc_xprt *xprt, 2308 u32 expected, 2309 u32 received 2310 ), 2311 2312 TP_ARGS(xprt, expected, received), 2313 2314 TP_STRUCT__entry( 2315 __field(u32, expected) 2316 __field(u32, received) 2317 __field(unsigned long, flags) 2318 __string(addr, xprt->xpt_remotebuf) 2319 ), 2320 2321 TP_fast_assign( 2322 __entry->expected = expected; 2323 __entry->received = received; 2324 __entry->flags = xprt->xpt_flags; 2325 __assign_str(addr); 2326 ), 2327 2328 TP_printk("addr=%s flags=%s expected=%u received=%u", 2329 __get_str(addr), show_svc_xprt_flags(__entry->flags), 2330 __entry->expected, __entry->received 2331 ) 2332 ); 2333 2334 TRACE_EVENT(svcsock_tcp_state, 2335 TP_PROTO( 2336 const struct svc_xprt *xprt, 2337 const struct socket *socket 2338 ), 2339 2340 TP_ARGS(xprt, socket), 2341 2342 TP_STRUCT__entry( 2343 __field(unsigned long, socket_state) 2344 __field(unsigned long, sock_state) 2345 __field(unsigned long, flags) 2346 __string(addr, xprt->xpt_remotebuf) 2347 ), 2348 2349 TP_fast_assign( 2350 __entry->socket_state = socket->state; 2351 __entry->sock_state = socket->sk->sk_state; 2352 __entry->flags = xprt->xpt_flags; 2353 __assign_str(addr); 2354 ), 2355 2356 TP_printk("addr=%s state=%s sk_state=%s flags=%s", __get_str(addr), 2357 rpc_show_socket_state(__entry->socket_state), 2358 rpc_show_sock_state(__entry->sock_state), 2359 show_svc_xprt_flags(__entry->flags) 2360 ) 2361 ); 2362 2363 DECLARE_EVENT_CLASS(svcsock_accept_class, 2364 TP_PROTO( 2365 const struct svc_xprt *xprt, 2366 const char *service, 2367 long status 2368 ), 2369 2370 TP_ARGS(xprt, service, status), 2371 2372 TP_STRUCT__entry( 2373 __field(long, status) 2374 __string(service, service) 2375 __field(unsigned int, netns_ino) 2376 ), 2377 2378 TP_fast_assign( 2379 __entry->status = status; 2380 __assign_str(service); 2381 __entry->netns_ino = xprt->xpt_net->ns.inum; 2382 ), 2383 2384 TP_printk("addr=listener service=%s status=%ld", 2385 __get_str(service), __entry->status 2386 ) 2387 ); 2388 2389 #define DEFINE_ACCEPT_EVENT(name) \ 2390 DEFINE_EVENT(svcsock_accept_class, svcsock_##name##_err, \ 2391 TP_PROTO( \ 2392 const struct svc_xprt *xprt, \ 2393 const char *service, \ 2394 long status \ 2395 ), \ 2396 TP_ARGS(xprt, service, status)) 2397 2398 DEFINE_ACCEPT_EVENT(accept); 2399 DEFINE_ACCEPT_EVENT(getpeername); 2400 2401 DECLARE_EVENT_CLASS(cache_event, 2402 TP_PROTO( 2403 const struct cache_detail *cd, 2404 const struct cache_head *h 2405 ), 2406 2407 TP_ARGS(cd, h), 2408 2409 TP_STRUCT__entry( 2410 __field(const struct cache_head *, h) 2411 __string(name, cd->name) 2412 ), 2413 2414 TP_fast_assign( 2415 __entry->h = h; 2416 __assign_str(name); 2417 ), 2418 2419 TP_printk("cache=%s entry=%p", __get_str(name), __entry->h) 2420 ); 2421 #define DEFINE_CACHE_EVENT(name) \ 2422 DEFINE_EVENT(cache_event, name, \ 2423 TP_PROTO( \ 2424 const struct cache_detail *cd, \ 2425 const struct cache_head *h \ 2426 ), \ 2427 TP_ARGS(cd, h)) 2428 DEFINE_CACHE_EVENT(cache_entry_expired); 2429 DEFINE_CACHE_EVENT(cache_entry_upcall); 2430 DEFINE_CACHE_EVENT(cache_entry_update); 2431 DEFINE_CACHE_EVENT(cache_entry_make_negative); 2432 DEFINE_CACHE_EVENT(cache_entry_no_listener); 2433 2434 DECLARE_EVENT_CLASS(register_class, 2435 TP_PROTO( 2436 const char *program, 2437 const u32 version, 2438 const int family, 2439 const unsigned short protocol, 2440 const unsigned short port, 2441 int error 2442 ), 2443 2444 TP_ARGS(program, version, family, protocol, port, error), 2445 2446 TP_STRUCT__entry( 2447 __field(u32, version) 2448 __field(unsigned long, family) 2449 __field(unsigned short, protocol) 2450 __field(unsigned short, port) 2451 __field(int, error) 2452 __string(program, program) 2453 ), 2454 2455 TP_fast_assign( 2456 __entry->version = version; 2457 __entry->family = family; 2458 __entry->protocol = protocol; 2459 __entry->port = port; 2460 __entry->error = error; 2461 __assign_str(program); 2462 ), 2463 2464 TP_printk("program=%sv%u proto=%s port=%u family=%s error=%d", 2465 __get_str(program), __entry->version, 2466 __entry->protocol == IPPROTO_UDP ? "udp" : "tcp", 2467 __entry->port, rpc_show_address_family(__entry->family), 2468 __entry->error 2469 ) 2470 ); 2471 2472 #define DEFINE_REGISTER_EVENT(name) \ 2473 DEFINE_EVENT(register_class, svc_##name, \ 2474 TP_PROTO( \ 2475 const char *program, \ 2476 const u32 version, \ 2477 const int family, \ 2478 const unsigned short protocol, \ 2479 const unsigned short port, \ 2480 int error \ 2481 ), \ 2482 TP_ARGS(program, version, family, protocol, \ 2483 port, error)) 2484 2485 DEFINE_REGISTER_EVENT(register); 2486 DEFINE_REGISTER_EVENT(noregister); 2487 2488 TRACE_EVENT(svc_unregister, 2489 TP_PROTO( 2490 const char *program, 2491 const u32 version, 2492 int error 2493 ), 2494 2495 TP_ARGS(program, version, error), 2496 2497 TP_STRUCT__entry( 2498 __field(u32, version) 2499 __field(int, error) 2500 __string(program, program) 2501 ), 2502 2503 TP_fast_assign( 2504 __entry->version = version; 2505 __entry->error = error; 2506 __assign_str(program); 2507 ), 2508 2509 TP_printk("program=%sv%u error=%d", 2510 __get_str(program), __entry->version, __entry->error 2511 ) 2512 ); 2513 2514 #endif /* _TRACE_SUNRPC_H */ 2515 2516 #include <trace/define_trace.h> 2517