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, clnt->cl_program->name); 192 __assign_str(server, xprt->servername); 193 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]); 194 __assign_str(port, xprt->address_strings[RPC_DISPLAY_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, program); 224 __assign_str(server, 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, task->tk_client->cl_program->name); 329 __assign_str(procname, rpc_proc_name(task)); 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 { (1UL << RPC_TASK_SIGNALLED), "SIGNALLED" }) 365 366 DECLARE_EVENT_CLASS(rpc_task_running, 367 368 TP_PROTO(const struct rpc_task *task, const void *action), 369 370 TP_ARGS(task, action), 371 372 TP_STRUCT__entry( 373 __field(unsigned int, task_id) 374 __field(unsigned int, client_id) 375 __field(const void *, action) 376 __field(unsigned long, runstate) 377 __field(int, status) 378 __field(unsigned short, flags) 379 ), 380 381 TP_fast_assign( 382 __entry->client_id = task->tk_client ? 383 task->tk_client->cl_clid : -1; 384 __entry->task_id = task->tk_pid; 385 __entry->action = action; 386 __entry->runstate = task->tk_runstate; 387 __entry->status = task->tk_status; 388 __entry->flags = task->tk_flags; 389 ), 390 391 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 392 " flags=%s runstate=%s status=%d action=%ps", 393 __entry->task_id, __entry->client_id, 394 rpc_show_task_flags(__entry->flags), 395 rpc_show_runstate(__entry->runstate), 396 __entry->status, 397 __entry->action 398 ) 399 ); 400 #define DEFINE_RPC_RUNNING_EVENT(name) \ 401 DEFINE_EVENT(rpc_task_running, rpc_task_##name, \ 402 TP_PROTO( \ 403 const struct rpc_task *task, \ 404 const void *action \ 405 ), \ 406 TP_ARGS(task, action)) 407 408 DEFINE_RPC_RUNNING_EVENT(begin); 409 DEFINE_RPC_RUNNING_EVENT(run_action); 410 DEFINE_RPC_RUNNING_EVENT(sync_sleep); 411 DEFINE_RPC_RUNNING_EVENT(sync_wake); 412 DEFINE_RPC_RUNNING_EVENT(complete); 413 DEFINE_RPC_RUNNING_EVENT(timeout); 414 DEFINE_RPC_RUNNING_EVENT(signalled); 415 DEFINE_RPC_RUNNING_EVENT(end); 416 DEFINE_RPC_RUNNING_EVENT(call_done); 417 418 DECLARE_EVENT_CLASS(rpc_task_queued, 419 420 TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q), 421 422 TP_ARGS(task, q), 423 424 TP_STRUCT__entry( 425 __field(unsigned int, task_id) 426 __field(unsigned int, client_id) 427 __field(unsigned long, timeout) 428 __field(unsigned long, runstate) 429 __field(int, status) 430 __field(unsigned short, flags) 431 __string(q_name, rpc_qname(q)) 432 ), 433 434 TP_fast_assign( 435 __entry->client_id = task->tk_client ? 436 task->tk_client->cl_clid : -1; 437 __entry->task_id = task->tk_pid; 438 __entry->timeout = rpc_task_timeout(task); 439 __entry->runstate = task->tk_runstate; 440 __entry->status = task->tk_status; 441 __entry->flags = task->tk_flags; 442 __assign_str(q_name, rpc_qname(q)); 443 ), 444 445 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 446 " flags=%s runstate=%s status=%d timeout=%lu queue=%s", 447 __entry->task_id, __entry->client_id, 448 rpc_show_task_flags(__entry->flags), 449 rpc_show_runstate(__entry->runstate), 450 __entry->status, 451 __entry->timeout, 452 __get_str(q_name) 453 ) 454 ); 455 #define DEFINE_RPC_QUEUED_EVENT(name) \ 456 DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \ 457 TP_PROTO( \ 458 const struct rpc_task *task, \ 459 const struct rpc_wait_queue *q \ 460 ), \ 461 TP_ARGS(task, q)) 462 463 DEFINE_RPC_QUEUED_EVENT(sleep); 464 DEFINE_RPC_QUEUED_EVENT(wakeup); 465 466 DECLARE_EVENT_CLASS(rpc_failure, 467 468 TP_PROTO(const struct rpc_task *task), 469 470 TP_ARGS(task), 471 472 TP_STRUCT__entry( 473 __field(unsigned int, task_id) 474 __field(unsigned int, client_id) 475 ), 476 477 TP_fast_assign( 478 __entry->task_id = task->tk_pid; 479 __entry->client_id = task->tk_client->cl_clid; 480 ), 481 482 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER, 483 __entry->task_id, __entry->client_id) 484 ); 485 486 #define DEFINE_RPC_FAILURE(name) \ 487 DEFINE_EVENT(rpc_failure, rpc_bad_##name, \ 488 TP_PROTO( \ 489 const struct rpc_task *task \ 490 ), \ 491 TP_ARGS(task)) 492 493 DEFINE_RPC_FAILURE(callhdr); 494 DEFINE_RPC_FAILURE(verifier); 495 496 DECLARE_EVENT_CLASS(rpc_reply_event, 497 498 TP_PROTO( 499 const struct rpc_task *task 500 ), 501 502 TP_ARGS(task), 503 504 TP_STRUCT__entry( 505 __field(unsigned int, task_id) 506 __field(unsigned int, client_id) 507 __field(u32, xid) 508 __string(progname, task->tk_client->cl_program->name) 509 __field(u32, version) 510 __string(procname, rpc_proc_name(task)) 511 __string(servername, task->tk_xprt->servername) 512 ), 513 514 TP_fast_assign( 515 __entry->task_id = task->tk_pid; 516 __entry->client_id = task->tk_client->cl_clid; 517 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 518 __assign_str(progname, task->tk_client->cl_program->name); 519 __entry->version = task->tk_client->cl_vers; 520 __assign_str(procname, rpc_proc_name(task)); 521 __assign_str(servername, task->tk_xprt->servername); 522 ), 523 524 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 525 " server=%s xid=0x%08x %sv%d %s", 526 __entry->task_id, __entry->client_id, __get_str(servername), 527 __entry->xid, __get_str(progname), __entry->version, 528 __get_str(procname)) 529 ) 530 531 #define DEFINE_RPC_REPLY_EVENT(name) \ 532 DEFINE_EVENT(rpc_reply_event, rpc__##name, \ 533 TP_PROTO( \ 534 const struct rpc_task *task \ 535 ), \ 536 TP_ARGS(task)) 537 538 DEFINE_RPC_REPLY_EVENT(prog_unavail); 539 DEFINE_RPC_REPLY_EVENT(prog_mismatch); 540 DEFINE_RPC_REPLY_EVENT(proc_unavail); 541 DEFINE_RPC_REPLY_EVENT(garbage_args); 542 DEFINE_RPC_REPLY_EVENT(unparsable); 543 DEFINE_RPC_REPLY_EVENT(mismatch); 544 DEFINE_RPC_REPLY_EVENT(stale_creds); 545 DEFINE_RPC_REPLY_EVENT(bad_creds); 546 DEFINE_RPC_REPLY_EVENT(auth_tooweak); 547 548 #define DEFINE_RPCB_ERROR_EVENT(name) \ 549 DEFINE_EVENT(rpc_reply_event, rpcb_##name##_err, \ 550 TP_PROTO( \ 551 const struct rpc_task *task \ 552 ), \ 553 TP_ARGS(task)) 554 555 DEFINE_RPCB_ERROR_EVENT(prog_unavail); 556 DEFINE_RPCB_ERROR_EVENT(timeout); 557 DEFINE_RPCB_ERROR_EVENT(bind_version); 558 DEFINE_RPCB_ERROR_EVENT(unreachable); 559 DEFINE_RPCB_ERROR_EVENT(unrecognized); 560 561 TRACE_EVENT(rpc_buf_alloc, 562 TP_PROTO( 563 const struct rpc_task *task, 564 int status 565 ), 566 567 TP_ARGS(task, status), 568 569 TP_STRUCT__entry( 570 __field(unsigned int, task_id) 571 __field(unsigned int, client_id) 572 __field(size_t, callsize) 573 __field(size_t, recvsize) 574 __field(int, status) 575 ), 576 577 TP_fast_assign( 578 __entry->task_id = task->tk_pid; 579 __entry->client_id = task->tk_client->cl_clid; 580 __entry->callsize = task->tk_rqstp->rq_callsize; 581 __entry->recvsize = task->tk_rqstp->rq_rcvsize; 582 __entry->status = status; 583 ), 584 585 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 586 " callsize=%zu recvsize=%zu status=%d", 587 __entry->task_id, __entry->client_id, 588 __entry->callsize, __entry->recvsize, __entry->status 589 ) 590 ); 591 592 TRACE_EVENT(rpc_call_rpcerror, 593 TP_PROTO( 594 const struct rpc_task *task, 595 int tk_status, 596 int rpc_status 597 ), 598 599 TP_ARGS(task, tk_status, rpc_status), 600 601 TP_STRUCT__entry( 602 __field(unsigned int, task_id) 603 __field(unsigned int, client_id) 604 __field(int, tk_status) 605 __field(int, rpc_status) 606 ), 607 608 TP_fast_assign( 609 __entry->client_id = task->tk_client->cl_clid; 610 __entry->task_id = task->tk_pid; 611 __entry->tk_status = tk_status; 612 __entry->rpc_status = rpc_status; 613 ), 614 615 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 616 " tk_status=%d rpc_status=%d", 617 __entry->task_id, __entry->client_id, 618 __entry->tk_status, __entry->rpc_status) 619 ); 620 621 TRACE_EVENT(rpc_stats_latency, 622 623 TP_PROTO( 624 const struct rpc_task *task, 625 ktime_t backlog, 626 ktime_t rtt, 627 ktime_t execute 628 ), 629 630 TP_ARGS(task, backlog, rtt, execute), 631 632 TP_STRUCT__entry( 633 __field(unsigned int, task_id) 634 __field(unsigned int, client_id) 635 __field(u32, xid) 636 __field(int, version) 637 __string(progname, task->tk_client->cl_program->name) 638 __string(procname, rpc_proc_name(task)) 639 __field(unsigned long, backlog) 640 __field(unsigned long, rtt) 641 __field(unsigned long, execute) 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, task->tk_client->cl_program->name); 650 __assign_str(procname, rpc_proc_name(task)); 651 __entry->backlog = ktime_to_us(backlog); 652 __entry->rtt = ktime_to_us(rtt); 653 __entry->execute = ktime_to_us(execute); 654 ), 655 656 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 657 " xid=0x%08x %sv%d %s backlog=%lu rtt=%lu execute=%lu", 658 __entry->task_id, __entry->client_id, __entry->xid, 659 __get_str(progname), __entry->version, __get_str(procname), 660 __entry->backlog, __entry->rtt, __entry->execute) 661 ); 662 663 TRACE_EVENT(rpc_xdr_overflow, 664 TP_PROTO( 665 const struct xdr_stream *xdr, 666 size_t requested 667 ), 668 669 TP_ARGS(xdr, requested), 670 671 TP_STRUCT__entry( 672 __field(unsigned int, task_id) 673 __field(unsigned int, client_id) 674 __field(int, version) 675 __field(size_t, requested) 676 __field(const void *, end) 677 __field(const void *, p) 678 __field(const void *, head_base) 679 __field(size_t, head_len) 680 __field(const void *, tail_base) 681 __field(size_t, tail_len) 682 __field(unsigned int, page_len) 683 __field(unsigned int, len) 684 __string(progname, xdr->rqst ? 685 xdr->rqst->rq_task->tk_client->cl_program->name : "unknown") 686 __string(procedure, xdr->rqst ? 687 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name : "unknown") 688 ), 689 690 TP_fast_assign( 691 if (xdr->rqst) { 692 const struct rpc_task *task = xdr->rqst->rq_task; 693 694 __entry->task_id = task->tk_pid; 695 __entry->client_id = task->tk_client->cl_clid; 696 __assign_str(progname, 697 task->tk_client->cl_program->name); 698 __entry->version = task->tk_client->cl_vers; 699 __assign_str(procedure, task->tk_msg.rpc_proc->p_name); 700 } else { 701 __entry->task_id = -1; 702 __entry->client_id = -1; 703 __assign_str(progname, "unknown"); 704 __entry->version = 0; 705 __assign_str(procedure, "unknown"); 706 } 707 __entry->requested = requested; 708 __entry->end = xdr->end; 709 __entry->p = xdr->p; 710 __entry->head_base = xdr->buf->head[0].iov_base, 711 __entry->head_len = xdr->buf->head[0].iov_len, 712 __entry->page_len = xdr->buf->page_len, 713 __entry->tail_base = xdr->buf->tail[0].iov_base, 714 __entry->tail_len = xdr->buf->tail[0].iov_len, 715 __entry->len = xdr->buf->len; 716 ), 717 718 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 719 " %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u\n", 720 __entry->task_id, __entry->client_id, 721 __get_str(progname), __entry->version, __get_str(procedure), 722 __entry->requested, __entry->p, __entry->end, 723 __entry->head_base, __entry->head_len, 724 __entry->page_len, 725 __entry->tail_base, __entry->tail_len, 726 __entry->len 727 ) 728 ); 729 730 TRACE_EVENT(rpc_xdr_alignment, 731 TP_PROTO( 732 const struct xdr_stream *xdr, 733 size_t offset, 734 unsigned int copied 735 ), 736 737 TP_ARGS(xdr, offset, copied), 738 739 TP_STRUCT__entry( 740 __field(unsigned int, task_id) 741 __field(unsigned int, client_id) 742 __field(int, version) 743 __field(size_t, offset) 744 __field(unsigned int, copied) 745 __field(const void *, head_base) 746 __field(size_t, head_len) 747 __field(const void *, tail_base) 748 __field(size_t, tail_len) 749 __field(unsigned int, page_len) 750 __field(unsigned int, len) 751 __string(progname, 752 xdr->rqst->rq_task->tk_client->cl_program->name) 753 __string(procedure, 754 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name) 755 ), 756 757 TP_fast_assign( 758 const struct rpc_task *task = xdr->rqst->rq_task; 759 760 __entry->task_id = task->tk_pid; 761 __entry->client_id = task->tk_client->cl_clid; 762 __assign_str(progname, 763 task->tk_client->cl_program->name); 764 __entry->version = task->tk_client->cl_vers; 765 __assign_str(procedure, task->tk_msg.rpc_proc->p_name); 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\n", 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, xprt->address_strings[RPC_DISPLAY_ADDR]); 1018 __assign_str(port, xprt->address_strings[RPC_DISPLAY_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, xprt->address_strings[RPC_DISPLAY_ADDR]); 1061 __assign_str(port, xprt->address_strings[RPC_DISPLAY_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 task->tk_client->cl_program->name); 1141 __entry->version = task->tk_client->cl_vers; 1142 __assign_str(procname, rpc_proc_name(task)); 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, xprt->address_strings[RPC_DISPLAY_ADDR]); 1167 __assign_str(port, xprt->address_strings[RPC_DISPLAY_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, xprt->address_strings[RPC_DISPLAY_ADDR]); 1315 __assign_str(port, xprt->address_strings[RPC_DISPLAY_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 "(null)") 1331 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] : 1332 "(null)") 1333 ), 1334 1335 TP_fast_assign( 1336 __entry->err = err; 1337 __entry->total = total; 1338 __assign_str(addr, xprt ? 1339 xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)"); 1340 __assign_str(port, xprt ? 1341 xprt->address_strings[RPC_DISPLAY_PORT] : "(null)"); 1342 ), 1343 1344 TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr), 1345 __get_str(port), __entry->err, __entry->total) 1346 ); 1347 1348 TRACE_EVENT(xs_stream_read_request, 1349 TP_PROTO(struct sock_xprt *xs), 1350 1351 TP_ARGS(xs), 1352 1353 TP_STRUCT__entry( 1354 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]) 1355 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]) 1356 __field(u32, xid) 1357 __field(unsigned long, copied) 1358 __field(unsigned int, reclen) 1359 __field(unsigned int, offset) 1360 ), 1361 1362 TP_fast_assign( 1363 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]); 1364 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]); 1365 __entry->xid = be32_to_cpu(xs->recv.xid); 1366 __entry->copied = xs->recv.copied; 1367 __entry->reclen = xs->recv.len; 1368 __entry->offset = xs->recv.offset; 1369 ), 1370 1371 TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u", 1372 __get_str(addr), __get_str(port), __entry->xid, 1373 __entry->copied, __entry->reclen, __entry->offset) 1374 ); 1375 1376 TRACE_EVENT(rpcb_getport, 1377 TP_PROTO( 1378 const struct rpc_clnt *clnt, 1379 const struct rpc_task *task, 1380 unsigned int bind_version 1381 ), 1382 1383 TP_ARGS(clnt, task, bind_version), 1384 1385 TP_STRUCT__entry( 1386 __field(unsigned int, task_id) 1387 __field(unsigned int, client_id) 1388 __field(unsigned int, program) 1389 __field(unsigned int, version) 1390 __field(int, protocol) 1391 __field(unsigned int, bind_version) 1392 __string(servername, task->tk_xprt->servername) 1393 ), 1394 1395 TP_fast_assign( 1396 __entry->task_id = task->tk_pid; 1397 __entry->client_id = clnt->cl_clid; 1398 __entry->program = clnt->cl_prog; 1399 __entry->version = clnt->cl_vers; 1400 __entry->protocol = task->tk_xprt->prot; 1401 __entry->bind_version = bind_version; 1402 __assign_str(servername, task->tk_xprt->servername); 1403 ), 1404 1405 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER 1406 " server=%s program=%u version=%u protocol=%d bind_version=%u", 1407 __entry->task_id, __entry->client_id, __get_str(servername), 1408 __entry->program, __entry->version, __entry->protocol, 1409 __entry->bind_version 1410 ) 1411 ); 1412 1413 TRACE_EVENT(rpcb_setport, 1414 TP_PROTO( 1415 const struct rpc_task *task, 1416 int status, 1417 unsigned short port 1418 ), 1419 1420 TP_ARGS(task, status, port), 1421 1422 TP_STRUCT__entry( 1423 __field(unsigned int, task_id) 1424 __field(unsigned int, client_id) 1425 __field(int, status) 1426 __field(unsigned short, port) 1427 ), 1428 1429 TP_fast_assign( 1430 __entry->task_id = task->tk_pid; 1431 __entry->client_id = task->tk_client->cl_clid; 1432 __entry->status = status; 1433 __entry->port = port; 1434 ), 1435 1436 TP_printk(SUNRPC_TRACE_TASK_SPECIFIER " status=%d port=%u", 1437 __entry->task_id, __entry->client_id, 1438 __entry->status, __entry->port 1439 ) 1440 ); 1441 1442 TRACE_EVENT(pmap_register, 1443 TP_PROTO( 1444 u32 program, 1445 u32 version, 1446 int protocol, 1447 unsigned short port 1448 ), 1449 1450 TP_ARGS(program, version, protocol, port), 1451 1452 TP_STRUCT__entry( 1453 __field(unsigned int, program) 1454 __field(unsigned int, version) 1455 __field(int, protocol) 1456 __field(unsigned int, port) 1457 ), 1458 1459 TP_fast_assign( 1460 __entry->program = program; 1461 __entry->version = version; 1462 __entry->protocol = protocol; 1463 __entry->port = port; 1464 ), 1465 1466 TP_printk("program=%u version=%u protocol=%d port=%u", 1467 __entry->program, __entry->version, 1468 __entry->protocol, __entry->port 1469 ) 1470 ); 1471 1472 TRACE_EVENT(rpcb_register, 1473 TP_PROTO( 1474 u32 program, 1475 u32 version, 1476 const char *addr, 1477 const char *netid 1478 ), 1479 1480 TP_ARGS(program, version, addr, netid), 1481 1482 TP_STRUCT__entry( 1483 __field(unsigned int, program) 1484 __field(unsigned int, version) 1485 __string(addr, addr) 1486 __string(netid, netid) 1487 ), 1488 1489 TP_fast_assign( 1490 __entry->program = program; 1491 __entry->version = version; 1492 __assign_str(addr, addr); 1493 __assign_str(netid, netid); 1494 ), 1495 1496 TP_printk("program=%u version=%u addr=%s netid=%s", 1497 __entry->program, __entry->version, 1498 __get_str(addr), __get_str(netid) 1499 ) 1500 ); 1501 1502 TRACE_EVENT(rpcb_unregister, 1503 TP_PROTO( 1504 u32 program, 1505 u32 version, 1506 const char *netid 1507 ), 1508 1509 TP_ARGS(program, version, netid), 1510 1511 TP_STRUCT__entry( 1512 __field(unsigned int, program) 1513 __field(unsigned int, version) 1514 __string(netid, netid) 1515 ), 1516 1517 TP_fast_assign( 1518 __entry->program = program; 1519 __entry->version = version; 1520 __assign_str(netid, netid); 1521 ), 1522 1523 TP_printk("program=%u version=%u netid=%s", 1524 __entry->program, __entry->version, __get_str(netid) 1525 ) 1526 ); 1527 1528 /** 1529 ** RPC-over-TLS tracepoints 1530 **/ 1531 1532 DECLARE_EVENT_CLASS(rpc_tls_class, 1533 TP_PROTO( 1534 const struct rpc_clnt *clnt, 1535 const struct rpc_xprt *xprt 1536 ), 1537 1538 TP_ARGS(clnt, xprt), 1539 1540 TP_STRUCT__entry( 1541 __field(unsigned long, requested_policy) 1542 __field(u32, version) 1543 __string(servername, xprt->servername) 1544 __string(progname, clnt->cl_program->name) 1545 ), 1546 1547 TP_fast_assign( 1548 __entry->requested_policy = clnt->cl_xprtsec.policy; 1549 __entry->version = clnt->cl_vers; 1550 __assign_str(servername, xprt->servername); 1551 __assign_str(progname, clnt->cl_program->name) 1552 ), 1553 1554 TP_printk("server=%s %sv%u requested_policy=%s", 1555 __get_str(servername), __get_str(progname), __entry->version, 1556 rpc_show_xprtsec_policy(__entry->requested_policy) 1557 ) 1558 ); 1559 1560 #define DEFINE_RPC_TLS_EVENT(name) \ 1561 DEFINE_EVENT(rpc_tls_class, rpc_tls_##name, \ 1562 TP_PROTO( \ 1563 const struct rpc_clnt *clnt, \ 1564 const struct rpc_xprt *xprt \ 1565 ), \ 1566 TP_ARGS(clnt, xprt)) 1567 1568 DEFINE_RPC_TLS_EVENT(unavailable); 1569 DEFINE_RPC_TLS_EVENT(not_started); 1570 1571 1572 /* Record an xdr_buf containing a fully-formed RPC message */ 1573 DECLARE_EVENT_CLASS(svc_xdr_msg_class, 1574 TP_PROTO( 1575 const struct xdr_buf *xdr 1576 ), 1577 1578 TP_ARGS(xdr), 1579 1580 TP_STRUCT__entry( 1581 __field(u32, xid) 1582 __field(const void *, head_base) 1583 __field(size_t, head_len) 1584 __field(const void *, tail_base) 1585 __field(size_t, tail_len) 1586 __field(unsigned int, page_len) 1587 __field(unsigned int, msg_len) 1588 ), 1589 1590 TP_fast_assign( 1591 __be32 *p = (__be32 *)xdr->head[0].iov_base; 1592 1593 __entry->xid = be32_to_cpu(*p); 1594 __entry->head_base = p; 1595 __entry->head_len = xdr->head[0].iov_len; 1596 __entry->tail_base = xdr->tail[0].iov_base; 1597 __entry->tail_len = xdr->tail[0].iov_len; 1598 __entry->page_len = xdr->page_len; 1599 __entry->msg_len = xdr->len; 1600 ), 1601 1602 TP_printk("xid=0x%08x head=[%p,%zu] page=%u tail=[%p,%zu] len=%u", 1603 __entry->xid, 1604 __entry->head_base, __entry->head_len, __entry->page_len, 1605 __entry->tail_base, __entry->tail_len, __entry->msg_len 1606 ) 1607 ); 1608 1609 #define DEFINE_SVCXDRMSG_EVENT(name) \ 1610 DEFINE_EVENT(svc_xdr_msg_class, \ 1611 svc_xdr_##name, \ 1612 TP_PROTO( \ 1613 const struct xdr_buf *xdr \ 1614 ), \ 1615 TP_ARGS(xdr)) 1616 1617 DEFINE_SVCXDRMSG_EVENT(recvfrom); 1618 1619 /* Record an xdr_buf containing arbitrary data, tagged with an XID */ 1620 DECLARE_EVENT_CLASS(svc_xdr_buf_class, 1621 TP_PROTO( 1622 __be32 xid, 1623 const struct xdr_buf *xdr 1624 ), 1625 1626 TP_ARGS(xid, xdr), 1627 1628 TP_STRUCT__entry( 1629 __field(u32, xid) 1630 __field(const void *, head_base) 1631 __field(size_t, head_len) 1632 __field(const void *, tail_base) 1633 __field(size_t, tail_len) 1634 __field(unsigned int, page_base) 1635 __field(unsigned int, page_len) 1636 __field(unsigned int, msg_len) 1637 ), 1638 1639 TP_fast_assign( 1640 __entry->xid = be32_to_cpu(xid); 1641 __entry->head_base = xdr->head[0].iov_base; 1642 __entry->head_len = xdr->head[0].iov_len; 1643 __entry->tail_base = xdr->tail[0].iov_base; 1644 __entry->tail_len = xdr->tail[0].iov_len; 1645 __entry->page_base = xdr->page_base; 1646 __entry->page_len = xdr->page_len; 1647 __entry->msg_len = xdr->len; 1648 ), 1649 1650 TP_printk("xid=0x%08x head=[%p,%zu] page=%u(%u) tail=[%p,%zu] len=%u", 1651 __entry->xid, 1652 __entry->head_base, __entry->head_len, 1653 __entry->page_len, __entry->page_base, 1654 __entry->tail_base, __entry->tail_len, 1655 __entry->msg_len 1656 ) 1657 ); 1658 1659 #define DEFINE_SVCXDRBUF_EVENT(name) \ 1660 DEFINE_EVENT(svc_xdr_buf_class, \ 1661 svc_xdr_##name, \ 1662 TP_PROTO( \ 1663 __be32 xid, \ 1664 const struct xdr_buf *xdr \ 1665 ), \ 1666 TP_ARGS(xid, xdr)) 1667 1668 DEFINE_SVCXDRBUF_EVENT(sendto); 1669 1670 /* 1671 * from include/linux/sunrpc/svc.h 1672 */ 1673 #define SVC_RQST_FLAG_LIST \ 1674 svc_rqst_flag(SECURE) \ 1675 svc_rqst_flag(LOCAL) \ 1676 svc_rqst_flag(USEDEFERRAL) \ 1677 svc_rqst_flag(DROPME) \ 1678 svc_rqst_flag(SPLICE_OK) \ 1679 svc_rqst_flag(VICTIM) \ 1680 svc_rqst_flag(BUSY) \ 1681 svc_rqst_flag_end(DATA) 1682 1683 #undef svc_rqst_flag 1684 #undef svc_rqst_flag_end 1685 #define svc_rqst_flag(x) TRACE_DEFINE_ENUM(RQ_##x); 1686 #define svc_rqst_flag_end(x) TRACE_DEFINE_ENUM(RQ_##x); 1687 1688 SVC_RQST_FLAG_LIST 1689 1690 #undef svc_rqst_flag 1691 #undef svc_rqst_flag_end 1692 #define svc_rqst_flag(x) { BIT(RQ_##x), #x }, 1693 #define svc_rqst_flag_end(x) { BIT(RQ_##x), #x } 1694 1695 #define show_rqstp_flags(flags) \ 1696 __print_flags(flags, "|", SVC_RQST_FLAG_LIST) 1697 1698 TRACE_DEFINE_ENUM(SVC_GARBAGE); 1699 TRACE_DEFINE_ENUM(SVC_SYSERR); 1700 TRACE_DEFINE_ENUM(SVC_VALID); 1701 TRACE_DEFINE_ENUM(SVC_NEGATIVE); 1702 TRACE_DEFINE_ENUM(SVC_OK); 1703 TRACE_DEFINE_ENUM(SVC_DROP); 1704 TRACE_DEFINE_ENUM(SVC_CLOSE); 1705 TRACE_DEFINE_ENUM(SVC_DENIED); 1706 TRACE_DEFINE_ENUM(SVC_PENDING); 1707 TRACE_DEFINE_ENUM(SVC_COMPLETE); 1708 1709 #define svc_show_status(status) \ 1710 __print_symbolic(status, \ 1711 { SVC_GARBAGE, "SVC_GARBAGE" }, \ 1712 { SVC_SYSERR, "SVC_SYSERR" }, \ 1713 { SVC_VALID, "SVC_VALID" }, \ 1714 { SVC_NEGATIVE, "SVC_NEGATIVE" }, \ 1715 { SVC_OK, "SVC_OK" }, \ 1716 { SVC_DROP, "SVC_DROP" }, \ 1717 { SVC_CLOSE, "SVC_CLOSE" }, \ 1718 { SVC_DENIED, "SVC_DENIED" }, \ 1719 { SVC_PENDING, "SVC_PENDING" }, \ 1720 { SVC_COMPLETE, "SVC_COMPLETE" }) 1721 1722 #define SVC_RQST_ENDPOINT_FIELDS(r) \ 1723 __sockaddr(server, (r)->rq_xprt->xpt_locallen) \ 1724 __sockaddr(client, (r)->rq_xprt->xpt_remotelen) \ 1725 __field(unsigned int, netns_ino) \ 1726 __field(u32, xid) 1727 1728 #define SVC_RQST_ENDPOINT_ASSIGNMENTS(r) \ 1729 do { \ 1730 struct svc_xprt *xprt = (r)->rq_xprt; \ 1731 __assign_sockaddr(server, &xprt->xpt_local, \ 1732 xprt->xpt_locallen); \ 1733 __assign_sockaddr(client, &xprt->xpt_remote, \ 1734 xprt->xpt_remotelen); \ 1735 __entry->netns_ino = xprt->xpt_net->ns.inum; \ 1736 __entry->xid = be32_to_cpu((r)->rq_xid); \ 1737 } while (0) 1738 1739 #define SVC_RQST_ENDPOINT_FORMAT \ 1740 "xid=0x%08x server=%pISpc client=%pISpc" 1741 1742 #define SVC_RQST_ENDPOINT_VARARGS \ 1743 __entry->xid, __get_sockaddr(server), __get_sockaddr(client) 1744 1745 TRACE_EVENT_CONDITION(svc_authenticate, 1746 TP_PROTO(const struct svc_rqst *rqst, int auth_res), 1747 1748 TP_ARGS(rqst, auth_res), 1749 1750 TP_CONDITION(auth_res != SVC_OK && auth_res != SVC_COMPLETE), 1751 1752 TP_STRUCT__entry( 1753 SVC_RQST_ENDPOINT_FIELDS(rqst) 1754 1755 __field(unsigned long, svc_status) 1756 __field(unsigned long, auth_stat) 1757 ), 1758 1759 TP_fast_assign( 1760 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1761 1762 __entry->svc_status = auth_res; 1763 __entry->auth_stat = be32_to_cpu(rqst->rq_auth_stat); 1764 ), 1765 1766 TP_printk(SVC_RQST_ENDPOINT_FORMAT 1767 " auth_res=%s auth_stat=%s", 1768 SVC_RQST_ENDPOINT_VARARGS, 1769 svc_show_status(__entry->svc_status), 1770 rpc_show_auth_stat(__entry->auth_stat)) 1771 ); 1772 1773 TRACE_EVENT(svc_process, 1774 TP_PROTO(const struct svc_rqst *rqst, const char *name), 1775 1776 TP_ARGS(rqst, name), 1777 1778 TP_STRUCT__entry( 1779 __field(u32, xid) 1780 __field(u32, vers) 1781 __field(u32, proc) 1782 __string(service, name) 1783 __string(procedure, svc_proc_name(rqst)) 1784 __string(addr, rqst->rq_xprt ? 1785 rqst->rq_xprt->xpt_remotebuf : "(null)") 1786 ), 1787 1788 TP_fast_assign( 1789 __entry->xid = be32_to_cpu(rqst->rq_xid); 1790 __entry->vers = rqst->rq_vers; 1791 __entry->proc = rqst->rq_proc; 1792 __assign_str(service, name); 1793 __assign_str(procedure, svc_proc_name(rqst)); 1794 __assign_str(addr, rqst->rq_xprt ? 1795 rqst->rq_xprt->xpt_remotebuf : "(null)"); 1796 ), 1797 1798 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%s", 1799 __get_str(addr), __entry->xid, 1800 __get_str(service), __entry->vers, 1801 __get_str(procedure) 1802 ) 1803 ); 1804 1805 DECLARE_EVENT_CLASS(svc_rqst_event, 1806 TP_PROTO( 1807 const struct svc_rqst *rqst 1808 ), 1809 1810 TP_ARGS(rqst), 1811 1812 TP_STRUCT__entry( 1813 SVC_RQST_ENDPOINT_FIELDS(rqst) 1814 1815 __field(unsigned long, flags) 1816 ), 1817 1818 TP_fast_assign( 1819 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1820 1821 __entry->flags = rqst->rq_flags; 1822 ), 1823 1824 TP_printk(SVC_RQST_ENDPOINT_FORMAT " flags=%s", 1825 SVC_RQST_ENDPOINT_VARARGS, 1826 show_rqstp_flags(__entry->flags)) 1827 ); 1828 #define DEFINE_SVC_RQST_EVENT(name) \ 1829 DEFINE_EVENT(svc_rqst_event, svc_##name, \ 1830 TP_PROTO( \ 1831 const struct svc_rqst *rqst \ 1832 ), \ 1833 TP_ARGS(rqst)) 1834 1835 DEFINE_SVC_RQST_EVENT(defer); 1836 DEFINE_SVC_RQST_EVENT(drop); 1837 1838 DECLARE_EVENT_CLASS(svc_rqst_status, 1839 TP_PROTO( 1840 const struct svc_rqst *rqst, 1841 int status 1842 ), 1843 1844 TP_ARGS(rqst, status), 1845 1846 TP_STRUCT__entry( 1847 SVC_RQST_ENDPOINT_FIELDS(rqst) 1848 1849 __field(int, status) 1850 __field(unsigned long, flags) 1851 ), 1852 1853 TP_fast_assign( 1854 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1855 1856 __entry->status = status; 1857 __entry->flags = rqst->rq_flags; 1858 ), 1859 1860 TP_printk(SVC_RQST_ENDPOINT_FORMAT " status=%d flags=%s", 1861 SVC_RQST_ENDPOINT_VARARGS, 1862 __entry->status, show_rqstp_flags(__entry->flags)) 1863 ); 1864 1865 DEFINE_EVENT(svc_rqst_status, svc_send, 1866 TP_PROTO(const struct svc_rqst *rqst, int status), 1867 TP_ARGS(rqst, status)); 1868 1869 TRACE_EVENT(svc_replace_page_err, 1870 TP_PROTO(const struct svc_rqst *rqst), 1871 1872 TP_ARGS(rqst), 1873 TP_STRUCT__entry( 1874 SVC_RQST_ENDPOINT_FIELDS(rqst) 1875 1876 __field(const void *, begin) 1877 __field(const void *, respages) 1878 __field(const void *, nextpage) 1879 ), 1880 1881 TP_fast_assign( 1882 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1883 1884 __entry->begin = rqst->rq_pages; 1885 __entry->respages = rqst->rq_respages; 1886 __entry->nextpage = rqst->rq_next_page; 1887 ), 1888 1889 TP_printk(SVC_RQST_ENDPOINT_FORMAT " begin=%p respages=%p nextpage=%p", 1890 SVC_RQST_ENDPOINT_VARARGS, 1891 __entry->begin, __entry->respages, __entry->nextpage) 1892 ); 1893 1894 TRACE_EVENT(svc_stats_latency, 1895 TP_PROTO( 1896 const struct svc_rqst *rqst 1897 ), 1898 1899 TP_ARGS(rqst), 1900 1901 TP_STRUCT__entry( 1902 SVC_RQST_ENDPOINT_FIELDS(rqst) 1903 1904 __field(unsigned long, execute) 1905 __string(procedure, svc_proc_name(rqst)) 1906 ), 1907 1908 TP_fast_assign( 1909 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1910 1911 __entry->execute = ktime_to_us(ktime_sub(ktime_get(), 1912 rqst->rq_stime)); 1913 __assign_str(procedure, svc_proc_name(rqst)); 1914 ), 1915 1916 TP_printk(SVC_RQST_ENDPOINT_FORMAT " proc=%s execute-us=%lu", 1917 SVC_RQST_ENDPOINT_VARARGS, 1918 __get_str(procedure), __entry->execute) 1919 ); 1920 1921 #define show_svc_xprt_flags(flags) \ 1922 __print_flags(flags, "|", \ 1923 { BIT(XPT_BUSY), "BUSY" }, \ 1924 { BIT(XPT_CONN), "CONN" }, \ 1925 { BIT(XPT_CLOSE), "CLOSE" }, \ 1926 { BIT(XPT_DATA), "DATA" }, \ 1927 { BIT(XPT_TEMP), "TEMP" }, \ 1928 { BIT(XPT_DEAD), "DEAD" }, \ 1929 { BIT(XPT_CHNGBUF), "CHNGBUF" }, \ 1930 { BIT(XPT_DEFERRED), "DEFERRED" }, \ 1931 { BIT(XPT_OLD), "OLD" }, \ 1932 { BIT(XPT_LISTENER), "LISTENER" }, \ 1933 { BIT(XPT_CACHE_AUTH), "CACHE_AUTH" }, \ 1934 { BIT(XPT_LOCAL), "LOCAL" }, \ 1935 { BIT(XPT_KILL_TEMP), "KILL_TEMP" }, \ 1936 { BIT(XPT_CONG_CTRL), "CONG_CTRL" }, \ 1937 { BIT(XPT_HANDSHAKE), "HANDSHAKE" }, \ 1938 { BIT(XPT_TLS_SESSION), "TLS_SESSION" }, \ 1939 { BIT(XPT_PEER_AUTH), "PEER_AUTH" }) 1940 1941 TRACE_EVENT(svc_xprt_create_err, 1942 TP_PROTO( 1943 const char *program, 1944 const char *protocol, 1945 struct sockaddr *sap, 1946 size_t salen, 1947 const struct svc_xprt *xprt 1948 ), 1949 1950 TP_ARGS(program, protocol, sap, salen, xprt), 1951 1952 TP_STRUCT__entry( 1953 __field(long, error) 1954 __string(program, program) 1955 __string(protocol, protocol) 1956 __sockaddr(addr, salen) 1957 ), 1958 1959 TP_fast_assign( 1960 __entry->error = PTR_ERR(xprt); 1961 __assign_str(program, program); 1962 __assign_str(protocol, protocol); 1963 __assign_sockaddr(addr, sap, salen); 1964 ), 1965 1966 TP_printk("addr=%pISpc program=%s protocol=%s error=%ld", 1967 __get_sockaddr(addr), __get_str(program), __get_str(protocol), 1968 __entry->error) 1969 ); 1970 1971 #define SVC_XPRT_ENDPOINT_FIELDS(x) \ 1972 __sockaddr(server, (x)->xpt_locallen) \ 1973 __sockaddr(client, (x)->xpt_remotelen) \ 1974 __field(unsigned long, flags) \ 1975 __field(unsigned int, netns_ino) 1976 1977 #define SVC_XPRT_ENDPOINT_ASSIGNMENTS(x) \ 1978 do { \ 1979 __assign_sockaddr(server, &(x)->xpt_local, \ 1980 (x)->xpt_locallen); \ 1981 __assign_sockaddr(client, &(x)->xpt_remote, \ 1982 (x)->xpt_remotelen); \ 1983 __entry->flags = (x)->xpt_flags; \ 1984 __entry->netns_ino = (x)->xpt_net->ns.inum; \ 1985 } while (0) 1986 1987 #define SVC_XPRT_ENDPOINT_FORMAT \ 1988 "server=%pISpc client=%pISpc flags=%s" 1989 1990 #define SVC_XPRT_ENDPOINT_VARARGS \ 1991 __get_sockaddr(server), __get_sockaddr(client), \ 1992 show_svc_xprt_flags(__entry->flags) 1993 1994 TRACE_EVENT(svc_xprt_enqueue, 1995 TP_PROTO( 1996 const struct svc_xprt *xprt, 1997 const struct svc_rqst *rqst 1998 ), 1999 2000 TP_ARGS(xprt, rqst), 2001 2002 TP_STRUCT__entry( 2003 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2004 2005 __field(int, pid) 2006 ), 2007 2008 TP_fast_assign( 2009 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2010 2011 __entry->pid = rqst? rqst->rq_task->pid : 0; 2012 ), 2013 2014 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " pid=%d", 2015 SVC_XPRT_ENDPOINT_VARARGS, __entry->pid) 2016 ); 2017 2018 TRACE_EVENT(svc_xprt_dequeue, 2019 TP_PROTO( 2020 const struct svc_rqst *rqst 2021 ), 2022 2023 TP_ARGS(rqst), 2024 2025 TP_STRUCT__entry( 2026 SVC_XPRT_ENDPOINT_FIELDS(rqst->rq_xprt) 2027 2028 __field(unsigned long, wakeup) 2029 ), 2030 2031 TP_fast_assign( 2032 SVC_XPRT_ENDPOINT_ASSIGNMENTS(rqst->rq_xprt); 2033 2034 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(), 2035 rqst->rq_qtime)); 2036 ), 2037 2038 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " wakeup-us=%lu", 2039 SVC_XPRT_ENDPOINT_VARARGS, __entry->wakeup) 2040 ); 2041 2042 DECLARE_EVENT_CLASS(svc_xprt_event, 2043 TP_PROTO( 2044 const struct svc_xprt *xprt 2045 ), 2046 2047 TP_ARGS(xprt), 2048 2049 TP_STRUCT__entry( 2050 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2051 ), 2052 2053 TP_fast_assign( 2054 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2055 ), 2056 2057 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2058 ); 2059 2060 #define DEFINE_SVC_XPRT_EVENT(name) \ 2061 DEFINE_EVENT(svc_xprt_event, svc_xprt_##name, \ 2062 TP_PROTO( \ 2063 const struct svc_xprt *xprt \ 2064 ), \ 2065 TP_ARGS(xprt)) 2066 2067 DEFINE_SVC_XPRT_EVENT(no_write_space); 2068 DEFINE_SVC_XPRT_EVENT(close); 2069 DEFINE_SVC_XPRT_EVENT(detach); 2070 DEFINE_SVC_XPRT_EVENT(free); 2071 2072 #define DEFINE_SVC_TLS_EVENT(name) \ 2073 DEFINE_EVENT(svc_xprt_event, svc_tls_##name, \ 2074 TP_PROTO(const struct svc_xprt *xprt), \ 2075 TP_ARGS(xprt)) 2076 2077 DEFINE_SVC_TLS_EVENT(start); 2078 DEFINE_SVC_TLS_EVENT(upcall); 2079 DEFINE_SVC_TLS_EVENT(unavailable); 2080 DEFINE_SVC_TLS_EVENT(not_started); 2081 DEFINE_SVC_TLS_EVENT(timed_out); 2082 2083 TRACE_EVENT(svc_xprt_accept, 2084 TP_PROTO( 2085 const struct svc_xprt *xprt, 2086 const char *service 2087 ), 2088 2089 TP_ARGS(xprt, service), 2090 2091 TP_STRUCT__entry( 2092 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2093 2094 __string(protocol, xprt->xpt_class->xcl_name) 2095 __string(service, service) 2096 ), 2097 2098 TP_fast_assign( 2099 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2100 2101 __assign_str(protocol, xprt->xpt_class->xcl_name); 2102 __assign_str(service, service); 2103 ), 2104 2105 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " protocol=%s service=%s", 2106 SVC_XPRT_ENDPOINT_VARARGS, 2107 __get_str(protocol), __get_str(service) 2108 ) 2109 ); 2110 2111 TRACE_EVENT(svc_wake_up, 2112 TP_PROTO(int pid), 2113 2114 TP_ARGS(pid), 2115 2116 TP_STRUCT__entry( 2117 __field(int, pid) 2118 ), 2119 2120 TP_fast_assign( 2121 __entry->pid = pid; 2122 ), 2123 2124 TP_printk("pid=%d", __entry->pid) 2125 ); 2126 2127 TRACE_EVENT(svc_alloc_arg_err, 2128 TP_PROTO( 2129 unsigned int requested, 2130 unsigned int allocated 2131 ), 2132 2133 TP_ARGS(requested, allocated), 2134 2135 TP_STRUCT__entry( 2136 __field(unsigned int, requested) 2137 __field(unsigned int, allocated) 2138 ), 2139 2140 TP_fast_assign( 2141 __entry->requested = requested; 2142 __entry->allocated = allocated; 2143 ), 2144 2145 TP_printk("requested=%u allocated=%u", 2146 __entry->requested, __entry->allocated) 2147 ); 2148 2149 DECLARE_EVENT_CLASS(svc_deferred_event, 2150 TP_PROTO( 2151 const struct svc_deferred_req *dr 2152 ), 2153 2154 TP_ARGS(dr), 2155 2156 TP_STRUCT__entry( 2157 __field(const void *, dr) 2158 __field(u32, xid) 2159 __sockaddr(addr, dr->addrlen) 2160 ), 2161 2162 TP_fast_assign( 2163 __entry->dr = dr; 2164 __entry->xid = be32_to_cpu(*(__be32 *)dr->args); 2165 __assign_sockaddr(addr, &dr->addr, dr->addrlen); 2166 ), 2167 2168 TP_printk("addr=%pISpc dr=%p xid=0x%08x", __get_sockaddr(addr), 2169 __entry->dr, __entry->xid) 2170 ); 2171 2172 #define DEFINE_SVC_DEFERRED_EVENT(name) \ 2173 DEFINE_EVENT(svc_deferred_event, svc_defer_##name, \ 2174 TP_PROTO( \ 2175 const struct svc_deferred_req *dr \ 2176 ), \ 2177 TP_ARGS(dr)) 2178 2179 DEFINE_SVC_DEFERRED_EVENT(drop); 2180 DEFINE_SVC_DEFERRED_EVENT(queue); 2181 DEFINE_SVC_DEFERRED_EVENT(recv); 2182 2183 DECLARE_EVENT_CLASS(svcsock_lifetime_class, 2184 TP_PROTO( 2185 const void *svsk, 2186 const struct socket *socket 2187 ), 2188 TP_ARGS(svsk, socket), 2189 TP_STRUCT__entry( 2190 __field(unsigned int, netns_ino) 2191 __field(const void *, svsk) 2192 __field(const void *, sk) 2193 __field(unsigned long, type) 2194 __field(unsigned long, family) 2195 __field(unsigned long, state) 2196 ), 2197 TP_fast_assign( 2198 struct sock *sk = socket->sk; 2199 2200 __entry->netns_ino = sock_net(sk)->ns.inum; 2201 __entry->svsk = svsk; 2202 __entry->sk = sk; 2203 __entry->type = socket->type; 2204 __entry->family = sk->sk_family; 2205 __entry->state = sk->sk_state; 2206 ), 2207 TP_printk("svsk=%p type=%s family=%s%s", 2208 __entry->svsk, show_socket_type(__entry->type), 2209 rpc_show_address_family(__entry->family), 2210 __entry->state == TCP_LISTEN ? " (listener)" : "" 2211 ) 2212 ); 2213 #define DEFINE_SVCSOCK_LIFETIME_EVENT(name) \ 2214 DEFINE_EVENT(svcsock_lifetime_class, name, \ 2215 TP_PROTO( \ 2216 const void *svsk, \ 2217 const struct socket *socket \ 2218 ), \ 2219 TP_ARGS(svsk, socket)) 2220 2221 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_new); 2222 DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_free); 2223 2224 TRACE_EVENT(svcsock_marker, 2225 TP_PROTO( 2226 const struct svc_xprt *xprt, 2227 __be32 marker 2228 ), 2229 2230 TP_ARGS(xprt, marker), 2231 2232 TP_STRUCT__entry( 2233 __field(unsigned int, length) 2234 __field(bool, last) 2235 __string(addr, xprt->xpt_remotebuf) 2236 ), 2237 2238 TP_fast_assign( 2239 __entry->length = be32_to_cpu(marker) & RPC_FRAGMENT_SIZE_MASK; 2240 __entry->last = be32_to_cpu(marker) & RPC_LAST_STREAM_FRAGMENT; 2241 __assign_str(addr, xprt->xpt_remotebuf); 2242 ), 2243 2244 TP_printk("addr=%s length=%u%s", __get_str(addr), 2245 __entry->length, __entry->last ? " (last)" : "") 2246 ); 2247 2248 DECLARE_EVENT_CLASS(svcsock_class, 2249 TP_PROTO( 2250 const struct svc_xprt *xprt, 2251 ssize_t result 2252 ), 2253 2254 TP_ARGS(xprt, result), 2255 2256 TP_STRUCT__entry( 2257 __field(ssize_t, result) 2258 __field(unsigned long, flags) 2259 __string(addr, xprt->xpt_remotebuf) 2260 ), 2261 2262 TP_fast_assign( 2263 __entry->result = result; 2264 __entry->flags = xprt->xpt_flags; 2265 __assign_str(addr, xprt->xpt_remotebuf); 2266 ), 2267 2268 TP_printk("addr=%s result=%zd flags=%s", __get_str(addr), 2269 __entry->result, show_svc_xprt_flags(__entry->flags) 2270 ) 2271 ); 2272 2273 #define DEFINE_SVCSOCK_EVENT(name) \ 2274 DEFINE_EVENT(svcsock_class, svcsock_##name, \ 2275 TP_PROTO( \ 2276 const struct svc_xprt *xprt, \ 2277 ssize_t result \ 2278 ), \ 2279 TP_ARGS(xprt, result)) 2280 2281 DEFINE_SVCSOCK_EVENT(udp_send); 2282 DEFINE_SVCSOCK_EVENT(udp_recv); 2283 DEFINE_SVCSOCK_EVENT(udp_recv_err); 2284 DEFINE_SVCSOCK_EVENT(tcp_send); 2285 DEFINE_SVCSOCK_EVENT(tcp_recv); 2286 DEFINE_SVCSOCK_EVENT(tcp_recv_eagain); 2287 DEFINE_SVCSOCK_EVENT(tcp_recv_err); 2288 DEFINE_SVCSOCK_EVENT(data_ready); 2289 DEFINE_SVCSOCK_EVENT(write_space); 2290 2291 TRACE_EVENT(svcsock_tcp_recv_short, 2292 TP_PROTO( 2293 const struct svc_xprt *xprt, 2294 u32 expected, 2295 u32 received 2296 ), 2297 2298 TP_ARGS(xprt, expected, received), 2299 2300 TP_STRUCT__entry( 2301 __field(u32, expected) 2302 __field(u32, received) 2303 __field(unsigned long, flags) 2304 __string(addr, xprt->xpt_remotebuf) 2305 ), 2306 2307 TP_fast_assign( 2308 __entry->expected = expected; 2309 __entry->received = received; 2310 __entry->flags = xprt->xpt_flags; 2311 __assign_str(addr, xprt->xpt_remotebuf); 2312 ), 2313 2314 TP_printk("addr=%s flags=%s expected=%u received=%u", 2315 __get_str(addr), show_svc_xprt_flags(__entry->flags), 2316 __entry->expected, __entry->received 2317 ) 2318 ); 2319 2320 TRACE_EVENT(svcsock_tcp_state, 2321 TP_PROTO( 2322 const struct svc_xprt *xprt, 2323 const struct socket *socket 2324 ), 2325 2326 TP_ARGS(xprt, socket), 2327 2328 TP_STRUCT__entry( 2329 __field(unsigned long, socket_state) 2330 __field(unsigned long, sock_state) 2331 __field(unsigned long, flags) 2332 __string(addr, xprt->xpt_remotebuf) 2333 ), 2334 2335 TP_fast_assign( 2336 __entry->socket_state = socket->state; 2337 __entry->sock_state = socket->sk->sk_state; 2338 __entry->flags = xprt->xpt_flags; 2339 __assign_str(addr, xprt->xpt_remotebuf); 2340 ), 2341 2342 TP_printk("addr=%s state=%s sk_state=%s flags=%s", __get_str(addr), 2343 rpc_show_socket_state(__entry->socket_state), 2344 rpc_show_sock_state(__entry->sock_state), 2345 show_svc_xprt_flags(__entry->flags) 2346 ) 2347 ); 2348 2349 DECLARE_EVENT_CLASS(svcsock_accept_class, 2350 TP_PROTO( 2351 const struct svc_xprt *xprt, 2352 const char *service, 2353 long status 2354 ), 2355 2356 TP_ARGS(xprt, service, status), 2357 2358 TP_STRUCT__entry( 2359 __field(long, status) 2360 __string(service, service) 2361 __field(unsigned int, netns_ino) 2362 ), 2363 2364 TP_fast_assign( 2365 __entry->status = status; 2366 __assign_str(service, service); 2367 __entry->netns_ino = xprt->xpt_net->ns.inum; 2368 ), 2369 2370 TP_printk("addr=listener service=%s status=%ld", 2371 __get_str(service), __entry->status 2372 ) 2373 ); 2374 2375 #define DEFINE_ACCEPT_EVENT(name) \ 2376 DEFINE_EVENT(svcsock_accept_class, svcsock_##name##_err, \ 2377 TP_PROTO( \ 2378 const struct svc_xprt *xprt, \ 2379 const char *service, \ 2380 long status \ 2381 ), \ 2382 TP_ARGS(xprt, service, status)) 2383 2384 DEFINE_ACCEPT_EVENT(accept); 2385 DEFINE_ACCEPT_EVENT(getpeername); 2386 2387 DECLARE_EVENT_CLASS(cache_event, 2388 TP_PROTO( 2389 const struct cache_detail *cd, 2390 const struct cache_head *h 2391 ), 2392 2393 TP_ARGS(cd, h), 2394 2395 TP_STRUCT__entry( 2396 __field(const struct cache_head *, h) 2397 __string(name, cd->name) 2398 ), 2399 2400 TP_fast_assign( 2401 __entry->h = h; 2402 __assign_str(name, cd->name); 2403 ), 2404 2405 TP_printk("cache=%s entry=%p", __get_str(name), __entry->h) 2406 ); 2407 #define DEFINE_CACHE_EVENT(name) \ 2408 DEFINE_EVENT(cache_event, name, \ 2409 TP_PROTO( \ 2410 const struct cache_detail *cd, \ 2411 const struct cache_head *h \ 2412 ), \ 2413 TP_ARGS(cd, h)) 2414 DEFINE_CACHE_EVENT(cache_entry_expired); 2415 DEFINE_CACHE_EVENT(cache_entry_upcall); 2416 DEFINE_CACHE_EVENT(cache_entry_update); 2417 DEFINE_CACHE_EVENT(cache_entry_make_negative); 2418 DEFINE_CACHE_EVENT(cache_entry_no_listener); 2419 2420 DECLARE_EVENT_CLASS(register_class, 2421 TP_PROTO( 2422 const char *program, 2423 const u32 version, 2424 const int family, 2425 const unsigned short protocol, 2426 const unsigned short port, 2427 int error 2428 ), 2429 2430 TP_ARGS(program, version, family, protocol, port, error), 2431 2432 TP_STRUCT__entry( 2433 __field(u32, version) 2434 __field(unsigned long, family) 2435 __field(unsigned short, protocol) 2436 __field(unsigned short, port) 2437 __field(int, error) 2438 __string(program, program) 2439 ), 2440 2441 TP_fast_assign( 2442 __entry->version = version; 2443 __entry->family = family; 2444 __entry->protocol = protocol; 2445 __entry->port = port; 2446 __entry->error = error; 2447 __assign_str(program, program); 2448 ), 2449 2450 TP_printk("program=%sv%u proto=%s port=%u family=%s error=%d", 2451 __get_str(program), __entry->version, 2452 __entry->protocol == IPPROTO_UDP ? "udp" : "tcp", 2453 __entry->port, rpc_show_address_family(__entry->family), 2454 __entry->error 2455 ) 2456 ); 2457 2458 #define DEFINE_REGISTER_EVENT(name) \ 2459 DEFINE_EVENT(register_class, svc_##name, \ 2460 TP_PROTO( \ 2461 const char *program, \ 2462 const u32 version, \ 2463 const int family, \ 2464 const unsigned short protocol, \ 2465 const unsigned short port, \ 2466 int error \ 2467 ), \ 2468 TP_ARGS(program, version, family, protocol, \ 2469 port, error)) 2470 2471 DEFINE_REGISTER_EVENT(register); 2472 DEFINE_REGISTER_EVENT(noregister); 2473 2474 TRACE_EVENT(svc_unregister, 2475 TP_PROTO( 2476 const char *program, 2477 const u32 version, 2478 int error 2479 ), 2480 2481 TP_ARGS(program, version, error), 2482 2483 TP_STRUCT__entry( 2484 __field(u32, version) 2485 __field(int, error) 2486 __string(program, program) 2487 ), 2488 2489 TP_fast_assign( 2490 __entry->version = version; 2491 __entry->error = error; 2492 __assign_str(program, program); 2493 ), 2494 2495 TP_printk("program=%sv%u error=%d", 2496 __get_str(program), __entry->version, __entry->error 2497 ) 2498 ); 2499 2500 #endif /* _TRACE_SUNRPC_H */ 2501 2502 #include <trace/define_trace.h> 2503