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 19TRACE_DEFINE_ENUM(SOCK_STREAM); 20TRACE_DEFINE_ENUM(SOCK_DGRAM); 21TRACE_DEFINE_ENUM(SOCK_RAW); 22TRACE_DEFINE_ENUM(SOCK_RDM); 23TRACE_DEFINE_ENUM(SOCK_SEQPACKET); 24TRACE_DEFINE_ENUM(SOCK_DCCP); 25TRACE_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. */ 38TRACE_DEFINE_ENUM(AF_UNSPEC); 39TRACE_DEFINE_ENUM(AF_UNIX); 40TRACE_DEFINE_ENUM(AF_LOCAL); 41TRACE_DEFINE_ENUM(AF_INET); 42TRACE_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 52DECLARE_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 104DEFINE_RPCXDRBUF_EVENT(sendto); 105DEFINE_RPCXDRBUF_EVENT(recvfrom); 106DEFINE_RPCXDRBUF_EVENT(reply_pages); 107 108 109DECLARE_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 135DEFINE_RPC_CLNT_EVENT(free); 136DEFINE_RPC_CLNT_EVENT(killall); 137DEFINE_RPC_CLNT_EVENT(shutdown); 138DEFINE_RPC_CLNT_EVENT(release); 139DEFINE_RPC_CLNT_EVENT(replace_xprt); 140DEFINE_RPC_CLNT_EVENT(replace_xprt_err); 141 142TRACE_DEFINE_ENUM(RPC_XPRTSEC_NONE); 143TRACE_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 168TRACE_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 206TRACE_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 231TRACE_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 254TRACE_DEFINE_ENUM(RPC_AUTH_OK); 255TRACE_DEFINE_ENUM(RPC_AUTH_BADCRED); 256TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDCRED); 257TRACE_DEFINE_ENUM(RPC_AUTH_BADVERF); 258TRACE_DEFINE_ENUM(RPC_AUTH_REJECTEDVERF); 259TRACE_DEFINE_ENUM(RPC_AUTH_TOOWEAK); 260TRACE_DEFINE_ENUM(RPCSEC_GSS_CREDPROBLEM); 261TRACE_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 274DECLARE_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 303DEFINE_RPC_STATUS_EVENT(call); 304DEFINE_RPC_STATUS_EVENT(connect); 305DEFINE_RPC_STATUS_EVENT(timeout); 306DEFINE_RPC_STATUS_EVENT(retry_refresh); 307DEFINE_RPC_STATUS_EVENT(refresh); 308 309TRACE_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 366DECLARE_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 408DEFINE_RPC_RUNNING_EVENT(begin); 409DEFINE_RPC_RUNNING_EVENT(run_action); 410DEFINE_RPC_RUNNING_EVENT(sync_sleep); 411DEFINE_RPC_RUNNING_EVENT(sync_wake); 412DEFINE_RPC_RUNNING_EVENT(complete); 413DEFINE_RPC_RUNNING_EVENT(timeout); 414DEFINE_RPC_RUNNING_EVENT(signalled); 415DEFINE_RPC_RUNNING_EVENT(end); 416DEFINE_RPC_RUNNING_EVENT(call_done); 417 418DECLARE_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 463DEFINE_RPC_QUEUED_EVENT(sleep); 464DEFINE_RPC_QUEUED_EVENT(wakeup); 465 466DECLARE_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 493DEFINE_RPC_FAILURE(callhdr); 494DEFINE_RPC_FAILURE(verifier); 495 496DECLARE_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 538DEFINE_RPC_REPLY_EVENT(prog_unavail); 539DEFINE_RPC_REPLY_EVENT(prog_mismatch); 540DEFINE_RPC_REPLY_EVENT(proc_unavail); 541DEFINE_RPC_REPLY_EVENT(garbage_args); 542DEFINE_RPC_REPLY_EVENT(unparsable); 543DEFINE_RPC_REPLY_EVENT(mismatch); 544DEFINE_RPC_REPLY_EVENT(stale_creds); 545DEFINE_RPC_REPLY_EVENT(bad_creds); 546DEFINE_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 555DEFINE_RPCB_ERROR_EVENT(prog_unavail); 556DEFINE_RPCB_ERROR_EVENT(timeout); 557DEFINE_RPCB_ERROR_EVENT(bind_version); 558DEFINE_RPCB_ERROR_EVENT(unreachable); 559DEFINE_RPCB_ERROR_EVENT(unrecognized); 560 561TRACE_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 592TRACE_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 621TRACE_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 663TRACE_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 730TRACE_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 808RPC_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 826RPC_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 840DECLARE_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 893DECLARE_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 950DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change); 951DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect); 952DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error); 953DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection); 954DEFINE_RPC_SOCKET_EVENT(rpc_socket_close); 955DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown); 956 957TRACE_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 1002DECLARE_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 1034DEFINE_RPC_XPRT_LIFETIME_EVENT(create); 1035DEFINE_RPC_XPRT_LIFETIME_EVENT(connect); 1036DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_auto); 1037DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_done); 1038DEFINE_RPC_XPRT_LIFETIME_EVENT(disconnect_force); 1039DEFINE_RPC_XPRT_LIFETIME_EVENT(destroy); 1040 1041DECLARE_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 1077DEFINE_RPC_XPRT_EVENT(timer); 1078DEFINE_RPC_XPRT_EVENT(lookup_rqst); 1079 1080TRACE_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 1111TRACE_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 1153TRACE_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 1174DECLARE_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 1217DEFINE_WRITELOCK_EVENT(reserve_xprt); 1218DEFINE_WRITELOCK_EVENT(release_xprt); 1219 1220DECLARE_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 1272DEFINE_CONG_EVENT(reserve_cong); 1273DEFINE_CONG_EVENT(release_cong); 1274DEFINE_CONG_EVENT(get_cong); 1275DEFINE_CONG_EVENT(put_cong); 1276 1277TRACE_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 1301TRACE_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 1321TRACE_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 1348TRACE_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 1376TRACE_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 1413TRACE_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 1442TRACE_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 1472TRACE_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 1502TRACE_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 1532DECLARE_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 1568DEFINE_RPC_TLS_EVENT(unavailable); 1569DEFINE_RPC_TLS_EVENT(not_started); 1570 1571 1572/* Record an xdr_buf containing a fully-formed RPC message */ 1573DECLARE_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 1617DEFINE_SVCXDRMSG_EVENT(recvfrom); 1618 1619/* Record an xdr_buf containing arbitrary data, tagged with an XID */ 1620DECLARE_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 1668DEFINE_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 1688SVC_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 1698TRACE_DEFINE_ENUM(SVC_GARBAGE); 1699TRACE_DEFINE_ENUM(SVC_SYSERR); 1700TRACE_DEFINE_ENUM(SVC_VALID); 1701TRACE_DEFINE_ENUM(SVC_NEGATIVE); 1702TRACE_DEFINE_ENUM(SVC_OK); 1703TRACE_DEFINE_ENUM(SVC_DROP); 1704TRACE_DEFINE_ENUM(SVC_CLOSE); 1705TRACE_DEFINE_ENUM(SVC_DENIED); 1706TRACE_DEFINE_ENUM(SVC_PENDING); 1707TRACE_DEFINE_ENUM(SVC_COMPLETE); 1708 1709#define show_svc_auth_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 1745TRACE_EVENT_CONDITION(svc_authenticate, 1746 TP_PROTO( 1747 const struct svc_rqst *rqst, 1748 enum svc_auth_status auth_res 1749 ), 1750 1751 TP_ARGS(rqst, auth_res), 1752 1753 TP_CONDITION(auth_res != SVC_OK && auth_res != SVC_COMPLETE), 1754 1755 TP_STRUCT__entry( 1756 SVC_RQST_ENDPOINT_FIELDS(rqst) 1757 1758 __field(unsigned long, svc_status) 1759 __field(unsigned long, auth_stat) 1760 ), 1761 1762 TP_fast_assign( 1763 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1764 1765 __entry->svc_status = auth_res; 1766 __entry->auth_stat = be32_to_cpu(rqst->rq_auth_stat); 1767 ), 1768 1769 TP_printk(SVC_RQST_ENDPOINT_FORMAT 1770 " auth_res=%s auth_stat=%s", 1771 SVC_RQST_ENDPOINT_VARARGS, 1772 show_svc_auth_status(__entry->svc_status), 1773 rpc_show_auth_stat(__entry->auth_stat)) 1774); 1775 1776TRACE_EVENT(svc_process, 1777 TP_PROTO(const struct svc_rqst *rqst, const char *name), 1778 1779 TP_ARGS(rqst, name), 1780 1781 TP_STRUCT__entry( 1782 __field(u32, xid) 1783 __field(u32, vers) 1784 __field(u32, proc) 1785 __string(service, name) 1786 __string(procedure, svc_proc_name(rqst)) 1787 __string(addr, rqst->rq_xprt ? 1788 rqst->rq_xprt->xpt_remotebuf : "(null)") 1789 ), 1790 1791 TP_fast_assign( 1792 __entry->xid = be32_to_cpu(rqst->rq_xid); 1793 __entry->vers = rqst->rq_vers; 1794 __entry->proc = rqst->rq_proc; 1795 __assign_str(service, name); 1796 __assign_str(procedure, svc_proc_name(rqst)); 1797 __assign_str(addr, rqst->rq_xprt ? 1798 rqst->rq_xprt->xpt_remotebuf : "(null)"); 1799 ), 1800 1801 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%s", 1802 __get_str(addr), __entry->xid, 1803 __get_str(service), __entry->vers, 1804 __get_str(procedure) 1805 ) 1806); 1807 1808DECLARE_EVENT_CLASS(svc_rqst_event, 1809 TP_PROTO( 1810 const struct svc_rqst *rqst 1811 ), 1812 1813 TP_ARGS(rqst), 1814 1815 TP_STRUCT__entry( 1816 SVC_RQST_ENDPOINT_FIELDS(rqst) 1817 1818 __field(unsigned long, flags) 1819 ), 1820 1821 TP_fast_assign( 1822 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1823 1824 __entry->flags = rqst->rq_flags; 1825 ), 1826 1827 TP_printk(SVC_RQST_ENDPOINT_FORMAT " flags=%s", 1828 SVC_RQST_ENDPOINT_VARARGS, 1829 show_rqstp_flags(__entry->flags)) 1830); 1831#define DEFINE_SVC_RQST_EVENT(name) \ 1832 DEFINE_EVENT(svc_rqst_event, svc_##name, \ 1833 TP_PROTO( \ 1834 const struct svc_rqst *rqst \ 1835 ), \ 1836 TP_ARGS(rqst)) 1837 1838DEFINE_SVC_RQST_EVENT(defer); 1839DEFINE_SVC_RQST_EVENT(drop); 1840 1841DECLARE_EVENT_CLASS(svc_rqst_status, 1842 TP_PROTO( 1843 const struct svc_rqst *rqst, 1844 int status 1845 ), 1846 1847 TP_ARGS(rqst, status), 1848 1849 TP_STRUCT__entry( 1850 SVC_RQST_ENDPOINT_FIELDS(rqst) 1851 1852 __field(int, status) 1853 __field(unsigned long, flags) 1854 ), 1855 1856 TP_fast_assign( 1857 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1858 1859 __entry->status = status; 1860 __entry->flags = rqst->rq_flags; 1861 ), 1862 1863 TP_printk(SVC_RQST_ENDPOINT_FORMAT " status=%d flags=%s", 1864 SVC_RQST_ENDPOINT_VARARGS, 1865 __entry->status, show_rqstp_flags(__entry->flags)) 1866); 1867 1868DEFINE_EVENT(svc_rqst_status, svc_send, 1869 TP_PROTO(const struct svc_rqst *rqst, int status), 1870 TP_ARGS(rqst, status)); 1871 1872TRACE_EVENT(svc_replace_page_err, 1873 TP_PROTO(const struct svc_rqst *rqst), 1874 1875 TP_ARGS(rqst), 1876 TP_STRUCT__entry( 1877 SVC_RQST_ENDPOINT_FIELDS(rqst) 1878 1879 __field(const void *, begin) 1880 __field(const void *, respages) 1881 __field(const void *, nextpage) 1882 ), 1883 1884 TP_fast_assign( 1885 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1886 1887 __entry->begin = rqst->rq_pages; 1888 __entry->respages = rqst->rq_respages; 1889 __entry->nextpage = rqst->rq_next_page; 1890 ), 1891 1892 TP_printk(SVC_RQST_ENDPOINT_FORMAT " begin=%p respages=%p nextpage=%p", 1893 SVC_RQST_ENDPOINT_VARARGS, 1894 __entry->begin, __entry->respages, __entry->nextpage) 1895); 1896 1897TRACE_EVENT(svc_stats_latency, 1898 TP_PROTO( 1899 const struct svc_rqst *rqst 1900 ), 1901 1902 TP_ARGS(rqst), 1903 1904 TP_STRUCT__entry( 1905 SVC_RQST_ENDPOINT_FIELDS(rqst) 1906 1907 __field(unsigned long, execute) 1908 __string(procedure, svc_proc_name(rqst)) 1909 ), 1910 1911 TP_fast_assign( 1912 SVC_RQST_ENDPOINT_ASSIGNMENTS(rqst); 1913 1914 __entry->execute = ktime_to_us(ktime_sub(ktime_get(), 1915 rqst->rq_stime)); 1916 __assign_str(procedure, svc_proc_name(rqst)); 1917 ), 1918 1919 TP_printk(SVC_RQST_ENDPOINT_FORMAT " proc=%s execute-us=%lu", 1920 SVC_RQST_ENDPOINT_VARARGS, 1921 __get_str(procedure), __entry->execute) 1922); 1923 1924/* 1925 * from include/linux/sunrpc/svc_xprt.h 1926 */ 1927#define SVC_XPRT_FLAG_LIST \ 1928 svc_xprt_flag(BUSY) \ 1929 svc_xprt_flag(CONN) \ 1930 svc_xprt_flag(CLOSE) \ 1931 svc_xprt_flag(DATA) \ 1932 svc_xprt_flag(TEMP) \ 1933 svc_xprt_flag(DEAD) \ 1934 svc_xprt_flag(CHNGBUF) \ 1935 svc_xprt_flag(DEFERRED) \ 1936 svc_xprt_flag(OLD) \ 1937 svc_xprt_flag(LISTENER) \ 1938 svc_xprt_flag(CACHE_AUTH) \ 1939 svc_xprt_flag(LOCAL) \ 1940 svc_xprt_flag(KILL_TEMP) \ 1941 svc_xprt_flag(CONG_CTRL) \ 1942 svc_xprt_flag(HANDSHAKE) \ 1943 svc_xprt_flag(TLS_SESSION) \ 1944 svc_xprt_flag_end(PEER_AUTH) 1945 1946#undef svc_xprt_flag 1947#undef svc_xprt_flag_end 1948#define svc_xprt_flag(x) TRACE_DEFINE_ENUM(XPT_##x); 1949#define svc_xprt_flag_end(x) TRACE_DEFINE_ENUM(XPT_##x); 1950 1951SVC_XPRT_FLAG_LIST 1952 1953#undef svc_xprt_flag 1954#undef svc_xprt_flag_end 1955#define svc_xprt_flag(x) { BIT(XPT_##x), #x }, 1956#define svc_xprt_flag_end(x) { BIT(XPT_##x), #x } 1957 1958#define show_svc_xprt_flags(flags) \ 1959 __print_flags(flags, "|", SVC_XPRT_FLAG_LIST) 1960 1961TRACE_EVENT(svc_xprt_create_err, 1962 TP_PROTO( 1963 const char *program, 1964 const char *protocol, 1965 struct sockaddr *sap, 1966 size_t salen, 1967 const struct svc_xprt *xprt 1968 ), 1969 1970 TP_ARGS(program, protocol, sap, salen, xprt), 1971 1972 TP_STRUCT__entry( 1973 __field(long, error) 1974 __string(program, program) 1975 __string(protocol, protocol) 1976 __sockaddr(addr, salen) 1977 ), 1978 1979 TP_fast_assign( 1980 __entry->error = PTR_ERR(xprt); 1981 __assign_str(program, program); 1982 __assign_str(protocol, protocol); 1983 __assign_sockaddr(addr, sap, salen); 1984 ), 1985 1986 TP_printk("addr=%pISpc program=%s protocol=%s error=%ld", 1987 __get_sockaddr(addr), __get_str(program), __get_str(protocol), 1988 __entry->error) 1989); 1990 1991#define SVC_XPRT_ENDPOINT_FIELDS(x) \ 1992 __sockaddr(server, (x)->xpt_locallen) \ 1993 __sockaddr(client, (x)->xpt_remotelen) \ 1994 __field(unsigned long, flags) \ 1995 __field(unsigned int, netns_ino) 1996 1997#define SVC_XPRT_ENDPOINT_ASSIGNMENTS(x) \ 1998 do { \ 1999 __assign_sockaddr(server, &(x)->xpt_local, \ 2000 (x)->xpt_locallen); \ 2001 __assign_sockaddr(client, &(x)->xpt_remote, \ 2002 (x)->xpt_remotelen); \ 2003 __entry->flags = (x)->xpt_flags; \ 2004 __entry->netns_ino = (x)->xpt_net->ns.inum; \ 2005 } while (0) 2006 2007#define SVC_XPRT_ENDPOINT_FORMAT \ 2008 "server=%pISpc client=%pISpc flags=%s" 2009 2010#define SVC_XPRT_ENDPOINT_VARARGS \ 2011 __get_sockaddr(server), __get_sockaddr(client), \ 2012 show_svc_xprt_flags(__entry->flags) 2013 2014TRACE_EVENT(svc_xprt_enqueue, 2015 TP_PROTO( 2016 const struct svc_xprt *xprt, 2017 unsigned long flags 2018 ), 2019 2020 TP_ARGS(xprt, flags), 2021 2022 TP_STRUCT__entry( 2023 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2024 ), 2025 2026 TP_fast_assign( 2027 __assign_sockaddr(server, &xprt->xpt_local, 2028 xprt->xpt_locallen); 2029 __assign_sockaddr(client, &xprt->xpt_remote, 2030 xprt->xpt_remotelen); 2031 __entry->flags = flags; 2032 __entry->netns_ino = xprt->xpt_net->ns.inum; 2033 ), 2034 2035 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2036); 2037 2038TRACE_EVENT(svc_xprt_dequeue, 2039 TP_PROTO( 2040 const struct svc_rqst *rqst 2041 ), 2042 2043 TP_ARGS(rqst), 2044 2045 TP_STRUCT__entry( 2046 SVC_XPRT_ENDPOINT_FIELDS(rqst->rq_xprt) 2047 2048 __field(unsigned long, wakeup) 2049 ), 2050 2051 TP_fast_assign( 2052 SVC_XPRT_ENDPOINT_ASSIGNMENTS(rqst->rq_xprt); 2053 2054 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(), 2055 rqst->rq_qtime)); 2056 ), 2057 2058 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " wakeup-us=%lu", 2059 SVC_XPRT_ENDPOINT_VARARGS, __entry->wakeup) 2060); 2061 2062DECLARE_EVENT_CLASS(svc_xprt_event, 2063 TP_PROTO( 2064 const struct svc_xprt *xprt 2065 ), 2066 2067 TP_ARGS(xprt), 2068 2069 TP_STRUCT__entry( 2070 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2071 ), 2072 2073 TP_fast_assign( 2074 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2075 ), 2076 2077 TP_printk(SVC_XPRT_ENDPOINT_FORMAT, SVC_XPRT_ENDPOINT_VARARGS) 2078); 2079 2080#define DEFINE_SVC_XPRT_EVENT(name) \ 2081 DEFINE_EVENT(svc_xprt_event, svc_xprt_##name, \ 2082 TP_PROTO( \ 2083 const struct svc_xprt *xprt \ 2084 ), \ 2085 TP_ARGS(xprt)) 2086 2087DEFINE_SVC_XPRT_EVENT(no_write_space); 2088DEFINE_SVC_XPRT_EVENT(close); 2089DEFINE_SVC_XPRT_EVENT(detach); 2090DEFINE_SVC_XPRT_EVENT(free); 2091 2092#define DEFINE_SVC_TLS_EVENT(name) \ 2093 DEFINE_EVENT(svc_xprt_event, svc_tls_##name, \ 2094 TP_PROTO(const struct svc_xprt *xprt), \ 2095 TP_ARGS(xprt)) 2096 2097DEFINE_SVC_TLS_EVENT(start); 2098DEFINE_SVC_TLS_EVENT(upcall); 2099DEFINE_SVC_TLS_EVENT(unavailable); 2100DEFINE_SVC_TLS_EVENT(not_started); 2101DEFINE_SVC_TLS_EVENT(timed_out); 2102 2103TRACE_EVENT(svc_xprt_accept, 2104 TP_PROTO( 2105 const struct svc_xprt *xprt, 2106 const char *service 2107 ), 2108 2109 TP_ARGS(xprt, service), 2110 2111 TP_STRUCT__entry( 2112 SVC_XPRT_ENDPOINT_FIELDS(xprt) 2113 2114 __string(protocol, xprt->xpt_class->xcl_name) 2115 __string(service, service) 2116 ), 2117 2118 TP_fast_assign( 2119 SVC_XPRT_ENDPOINT_ASSIGNMENTS(xprt); 2120 2121 __assign_str(protocol, xprt->xpt_class->xcl_name); 2122 __assign_str(service, service); 2123 ), 2124 2125 TP_printk(SVC_XPRT_ENDPOINT_FORMAT " protocol=%s service=%s", 2126 SVC_XPRT_ENDPOINT_VARARGS, 2127 __get_str(protocol), __get_str(service) 2128 ) 2129); 2130 2131TRACE_EVENT(svc_wake_up, 2132 TP_PROTO(int pid), 2133 2134 TP_ARGS(pid), 2135 2136 TP_STRUCT__entry( 2137 __field(int, pid) 2138 ), 2139 2140 TP_fast_assign( 2141 __entry->pid = pid; 2142 ), 2143 2144 TP_printk("pid=%d", __entry->pid) 2145); 2146 2147TRACE_EVENT(svc_alloc_arg_err, 2148 TP_PROTO( 2149 unsigned int requested, 2150 unsigned int allocated 2151 ), 2152 2153 TP_ARGS(requested, allocated), 2154 2155 TP_STRUCT__entry( 2156 __field(unsigned int, requested) 2157 __field(unsigned int, allocated) 2158 ), 2159 2160 TP_fast_assign( 2161 __entry->requested = requested; 2162 __entry->allocated = allocated; 2163 ), 2164 2165 TP_printk("requested=%u allocated=%u", 2166 __entry->requested, __entry->allocated) 2167); 2168 2169DECLARE_EVENT_CLASS(svc_deferred_event, 2170 TP_PROTO( 2171 const struct svc_deferred_req *dr 2172 ), 2173 2174 TP_ARGS(dr), 2175 2176 TP_STRUCT__entry( 2177 __field(const void *, dr) 2178 __field(u32, xid) 2179 __sockaddr(addr, dr->addrlen) 2180 ), 2181 2182 TP_fast_assign( 2183 __entry->dr = dr; 2184 __entry->xid = be32_to_cpu(*(__be32 *)dr->args); 2185 __assign_sockaddr(addr, &dr->addr, dr->addrlen); 2186 ), 2187 2188 TP_printk("addr=%pISpc dr=%p xid=0x%08x", __get_sockaddr(addr), 2189 __entry->dr, __entry->xid) 2190); 2191 2192#define DEFINE_SVC_DEFERRED_EVENT(name) \ 2193 DEFINE_EVENT(svc_deferred_event, svc_defer_##name, \ 2194 TP_PROTO( \ 2195 const struct svc_deferred_req *dr \ 2196 ), \ 2197 TP_ARGS(dr)) 2198 2199DEFINE_SVC_DEFERRED_EVENT(drop); 2200DEFINE_SVC_DEFERRED_EVENT(queue); 2201DEFINE_SVC_DEFERRED_EVENT(recv); 2202 2203DECLARE_EVENT_CLASS(svcsock_lifetime_class, 2204 TP_PROTO( 2205 const void *svsk, 2206 const struct socket *socket 2207 ), 2208 TP_ARGS(svsk, socket), 2209 TP_STRUCT__entry( 2210 __field(unsigned int, netns_ino) 2211 __field(const void *, svsk) 2212 __field(const void *, sk) 2213 __field(unsigned long, type) 2214 __field(unsigned long, family) 2215 __field(unsigned long, state) 2216 ), 2217 TP_fast_assign( 2218 struct sock *sk = socket->sk; 2219 2220 __entry->netns_ino = sock_net(sk)->ns.inum; 2221 __entry->svsk = svsk; 2222 __entry->sk = sk; 2223 __entry->type = socket->type; 2224 __entry->family = sk->sk_family; 2225 __entry->state = sk->sk_state; 2226 ), 2227 TP_printk("svsk=%p type=%s family=%s%s", 2228 __entry->svsk, show_socket_type(__entry->type), 2229 rpc_show_address_family(__entry->family), 2230 __entry->state == TCP_LISTEN ? " (listener)" : "" 2231 ) 2232); 2233#define DEFINE_SVCSOCK_LIFETIME_EVENT(name) \ 2234 DEFINE_EVENT(svcsock_lifetime_class, name, \ 2235 TP_PROTO( \ 2236 const void *svsk, \ 2237 const struct socket *socket \ 2238 ), \ 2239 TP_ARGS(svsk, socket)) 2240 2241DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_new); 2242DEFINE_SVCSOCK_LIFETIME_EVENT(svcsock_free); 2243 2244TRACE_EVENT(svcsock_marker, 2245 TP_PROTO( 2246 const struct svc_xprt *xprt, 2247 __be32 marker 2248 ), 2249 2250 TP_ARGS(xprt, marker), 2251 2252 TP_STRUCT__entry( 2253 __field(unsigned int, length) 2254 __field(bool, last) 2255 __string(addr, xprt->xpt_remotebuf) 2256 ), 2257 2258 TP_fast_assign( 2259 __entry->length = be32_to_cpu(marker) & RPC_FRAGMENT_SIZE_MASK; 2260 __entry->last = be32_to_cpu(marker) & RPC_LAST_STREAM_FRAGMENT; 2261 __assign_str(addr, xprt->xpt_remotebuf); 2262 ), 2263 2264 TP_printk("addr=%s length=%u%s", __get_str(addr), 2265 __entry->length, __entry->last ? " (last)" : "") 2266); 2267 2268DECLARE_EVENT_CLASS(svcsock_class, 2269 TP_PROTO( 2270 const struct svc_xprt *xprt, 2271 ssize_t result 2272 ), 2273 2274 TP_ARGS(xprt, result), 2275 2276 TP_STRUCT__entry( 2277 __field(ssize_t, result) 2278 __field(unsigned long, flags) 2279 __string(addr, xprt->xpt_remotebuf) 2280 ), 2281 2282 TP_fast_assign( 2283 __entry->result = result; 2284 __entry->flags = xprt->xpt_flags; 2285 __assign_str(addr, xprt->xpt_remotebuf); 2286 ), 2287 2288 TP_printk("addr=%s result=%zd flags=%s", __get_str(addr), 2289 __entry->result, show_svc_xprt_flags(__entry->flags) 2290 ) 2291); 2292 2293#define DEFINE_SVCSOCK_EVENT(name) \ 2294 DEFINE_EVENT(svcsock_class, svcsock_##name, \ 2295 TP_PROTO( \ 2296 const struct svc_xprt *xprt, \ 2297 ssize_t result \ 2298 ), \ 2299 TP_ARGS(xprt, result)) 2300 2301DEFINE_SVCSOCK_EVENT(udp_send); 2302DEFINE_SVCSOCK_EVENT(udp_recv); 2303DEFINE_SVCSOCK_EVENT(udp_recv_err); 2304DEFINE_SVCSOCK_EVENT(tcp_send); 2305DEFINE_SVCSOCK_EVENT(tcp_recv); 2306DEFINE_SVCSOCK_EVENT(tcp_recv_eagain); 2307DEFINE_SVCSOCK_EVENT(tcp_recv_err); 2308DEFINE_SVCSOCK_EVENT(data_ready); 2309DEFINE_SVCSOCK_EVENT(write_space); 2310 2311TRACE_EVENT(svcsock_tcp_recv_short, 2312 TP_PROTO( 2313 const struct svc_xprt *xprt, 2314 u32 expected, 2315 u32 received 2316 ), 2317 2318 TP_ARGS(xprt, expected, received), 2319 2320 TP_STRUCT__entry( 2321 __field(u32, expected) 2322 __field(u32, received) 2323 __field(unsigned long, flags) 2324 __string(addr, xprt->xpt_remotebuf) 2325 ), 2326 2327 TP_fast_assign( 2328 __entry->expected = expected; 2329 __entry->received = received; 2330 __entry->flags = xprt->xpt_flags; 2331 __assign_str(addr, xprt->xpt_remotebuf); 2332 ), 2333 2334 TP_printk("addr=%s flags=%s expected=%u received=%u", 2335 __get_str(addr), show_svc_xprt_flags(__entry->flags), 2336 __entry->expected, __entry->received 2337 ) 2338); 2339 2340TRACE_EVENT(svcsock_tcp_state, 2341 TP_PROTO( 2342 const struct svc_xprt *xprt, 2343 const struct socket *socket 2344 ), 2345 2346 TP_ARGS(xprt, socket), 2347 2348 TP_STRUCT__entry( 2349 __field(unsigned long, socket_state) 2350 __field(unsigned long, sock_state) 2351 __field(unsigned long, flags) 2352 __string(addr, xprt->xpt_remotebuf) 2353 ), 2354 2355 TP_fast_assign( 2356 __entry->socket_state = socket->state; 2357 __entry->sock_state = socket->sk->sk_state; 2358 __entry->flags = xprt->xpt_flags; 2359 __assign_str(addr, xprt->xpt_remotebuf); 2360 ), 2361 2362 TP_printk("addr=%s state=%s sk_state=%s flags=%s", __get_str(addr), 2363 rpc_show_socket_state(__entry->socket_state), 2364 rpc_show_sock_state(__entry->sock_state), 2365 show_svc_xprt_flags(__entry->flags) 2366 ) 2367); 2368 2369DECLARE_EVENT_CLASS(svcsock_accept_class, 2370 TP_PROTO( 2371 const struct svc_xprt *xprt, 2372 const char *service, 2373 long status 2374 ), 2375 2376 TP_ARGS(xprt, service, status), 2377 2378 TP_STRUCT__entry( 2379 __field(long, status) 2380 __string(service, service) 2381 __field(unsigned int, netns_ino) 2382 ), 2383 2384 TP_fast_assign( 2385 __entry->status = status; 2386 __assign_str(service, service); 2387 __entry->netns_ino = xprt->xpt_net->ns.inum; 2388 ), 2389 2390 TP_printk("addr=listener service=%s status=%ld", 2391 __get_str(service), __entry->status 2392 ) 2393); 2394 2395#define DEFINE_ACCEPT_EVENT(name) \ 2396 DEFINE_EVENT(svcsock_accept_class, svcsock_##name##_err, \ 2397 TP_PROTO( \ 2398 const struct svc_xprt *xprt, \ 2399 const char *service, \ 2400 long status \ 2401 ), \ 2402 TP_ARGS(xprt, service, status)) 2403 2404DEFINE_ACCEPT_EVENT(accept); 2405DEFINE_ACCEPT_EVENT(getpeername); 2406 2407DECLARE_EVENT_CLASS(cache_event, 2408 TP_PROTO( 2409 const struct cache_detail *cd, 2410 const struct cache_head *h 2411 ), 2412 2413 TP_ARGS(cd, h), 2414 2415 TP_STRUCT__entry( 2416 __field(const struct cache_head *, h) 2417 __string(name, cd->name) 2418 ), 2419 2420 TP_fast_assign( 2421 __entry->h = h; 2422 __assign_str(name, cd->name); 2423 ), 2424 2425 TP_printk("cache=%s entry=%p", __get_str(name), __entry->h) 2426); 2427#define DEFINE_CACHE_EVENT(name) \ 2428 DEFINE_EVENT(cache_event, name, \ 2429 TP_PROTO( \ 2430 const struct cache_detail *cd, \ 2431 const struct cache_head *h \ 2432 ), \ 2433 TP_ARGS(cd, h)) 2434DEFINE_CACHE_EVENT(cache_entry_expired); 2435DEFINE_CACHE_EVENT(cache_entry_upcall); 2436DEFINE_CACHE_EVENT(cache_entry_update); 2437DEFINE_CACHE_EVENT(cache_entry_make_negative); 2438DEFINE_CACHE_EVENT(cache_entry_no_listener); 2439 2440DECLARE_EVENT_CLASS(register_class, 2441 TP_PROTO( 2442 const char *program, 2443 const u32 version, 2444 const int family, 2445 const unsigned short protocol, 2446 const unsigned short port, 2447 int error 2448 ), 2449 2450 TP_ARGS(program, version, family, protocol, port, error), 2451 2452 TP_STRUCT__entry( 2453 __field(u32, version) 2454 __field(unsigned long, family) 2455 __field(unsigned short, protocol) 2456 __field(unsigned short, port) 2457 __field(int, error) 2458 __string(program, program) 2459 ), 2460 2461 TP_fast_assign( 2462 __entry->version = version; 2463 __entry->family = family; 2464 __entry->protocol = protocol; 2465 __entry->port = port; 2466 __entry->error = error; 2467 __assign_str(program, program); 2468 ), 2469 2470 TP_printk("program=%sv%u proto=%s port=%u family=%s error=%d", 2471 __get_str(program), __entry->version, 2472 __entry->protocol == IPPROTO_UDP ? "udp" : "tcp", 2473 __entry->port, rpc_show_address_family(__entry->family), 2474 __entry->error 2475 ) 2476); 2477 2478#define DEFINE_REGISTER_EVENT(name) \ 2479 DEFINE_EVENT(register_class, svc_##name, \ 2480 TP_PROTO( \ 2481 const char *program, \ 2482 const u32 version, \ 2483 const int family, \ 2484 const unsigned short protocol, \ 2485 const unsigned short port, \ 2486 int error \ 2487 ), \ 2488 TP_ARGS(program, version, family, protocol, \ 2489 port, error)) 2490 2491DEFINE_REGISTER_EVENT(register); 2492DEFINE_REGISTER_EVENT(noregister); 2493 2494TRACE_EVENT(svc_unregister, 2495 TP_PROTO( 2496 const char *program, 2497 const u32 version, 2498 int error 2499 ), 2500 2501 TP_ARGS(program, version, error), 2502 2503 TP_STRUCT__entry( 2504 __field(u32, version) 2505 __field(int, error) 2506 __string(program, program) 2507 ), 2508 2509 TP_fast_assign( 2510 __entry->version = version; 2511 __entry->error = error; 2512 __assign_str(program, program); 2513 ), 2514 2515 TP_printk("program=%sv%u error=%d", 2516 __get_str(program), __entry->version, __entry->error 2517 ) 2518); 2519 2520#endif /* _TRACE_SUNRPC_H */ 2521 2522#include <trace/define_trace.h> 2523