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 DECLARE_EVENT_CLASS(rpc_task_status, 18 19 TP_PROTO(const struct rpc_task *task), 20 21 TP_ARGS(task), 22 23 TP_STRUCT__entry( 24 __field(unsigned int, task_id) 25 __field(unsigned int, client_id) 26 __field(int, status) 27 ), 28 29 TP_fast_assign( 30 __entry->task_id = task->tk_pid; 31 __entry->client_id = task->tk_client->cl_clid; 32 __entry->status = task->tk_status; 33 ), 34 35 TP_printk("task:%u@%u status=%d", 36 __entry->task_id, __entry->client_id, 37 __entry->status) 38 ); 39 #define DEFINE_RPC_STATUS_EVENT(name) \ 40 DEFINE_EVENT(rpc_task_status, rpc_##name##_status, \ 41 TP_PROTO( \ 42 const struct rpc_task *task \ 43 ), \ 44 TP_ARGS(task)) 45 46 DEFINE_RPC_STATUS_EVENT(call); 47 DEFINE_RPC_STATUS_EVENT(bind); 48 DEFINE_RPC_STATUS_EVENT(connect); 49 50 TRACE_EVENT(rpc_request, 51 TP_PROTO(const struct rpc_task *task), 52 53 TP_ARGS(task), 54 55 TP_STRUCT__entry( 56 __field(unsigned int, task_id) 57 __field(unsigned int, client_id) 58 __field(int, version) 59 __field(bool, async) 60 __string(progname, task->tk_client->cl_program->name) 61 __string(procname, rpc_proc_name(task)) 62 ), 63 64 TP_fast_assign( 65 __entry->task_id = task->tk_pid; 66 __entry->client_id = task->tk_client->cl_clid; 67 __entry->version = task->tk_client->cl_vers; 68 __entry->async = RPC_IS_ASYNC(task); 69 __assign_str(progname, task->tk_client->cl_program->name) 70 __assign_str(procname, rpc_proc_name(task)) 71 ), 72 73 TP_printk("task:%u@%u %sv%d %s (%ssync)", 74 __entry->task_id, __entry->client_id, 75 __get_str(progname), __entry->version, 76 __get_str(procname), __entry->async ? "a": "" 77 ) 78 ); 79 80 TRACE_DEFINE_ENUM(RPC_TASK_ASYNC); 81 TRACE_DEFINE_ENUM(RPC_TASK_SWAPPER); 82 TRACE_DEFINE_ENUM(RPC_CALL_MAJORSEEN); 83 TRACE_DEFINE_ENUM(RPC_TASK_ROOTCREDS); 84 TRACE_DEFINE_ENUM(RPC_TASK_DYNAMIC); 85 TRACE_DEFINE_ENUM(RPC_TASK_KILLED); 86 TRACE_DEFINE_ENUM(RPC_TASK_SOFT); 87 TRACE_DEFINE_ENUM(RPC_TASK_SOFTCONN); 88 TRACE_DEFINE_ENUM(RPC_TASK_SENT); 89 TRACE_DEFINE_ENUM(RPC_TASK_TIMEOUT); 90 TRACE_DEFINE_ENUM(RPC_TASK_NOCONNECT); 91 TRACE_DEFINE_ENUM(RPC_TASK_NO_RETRANS_TIMEOUT); 92 93 #define rpc_show_task_flags(flags) \ 94 __print_flags(flags, "|", \ 95 { RPC_TASK_ASYNC, "ASYNC" }, \ 96 { RPC_TASK_SWAPPER, "SWAPPER" }, \ 97 { RPC_CALL_MAJORSEEN, "MAJORSEEN" }, \ 98 { RPC_TASK_ROOTCREDS, "ROOTCREDS" }, \ 99 { RPC_TASK_DYNAMIC, "DYNAMIC" }, \ 100 { RPC_TASK_KILLED, "KILLED" }, \ 101 { RPC_TASK_SOFT, "SOFT" }, \ 102 { RPC_TASK_SOFTCONN, "SOFTCONN" }, \ 103 { RPC_TASK_SENT, "SENT" }, \ 104 { RPC_TASK_TIMEOUT, "TIMEOUT" }, \ 105 { RPC_TASK_NOCONNECT, "NOCONNECT" }, \ 106 { RPC_TASK_NO_RETRANS_TIMEOUT, "NORTO" }) 107 108 TRACE_DEFINE_ENUM(RPC_TASK_RUNNING); 109 TRACE_DEFINE_ENUM(RPC_TASK_QUEUED); 110 TRACE_DEFINE_ENUM(RPC_TASK_ACTIVE); 111 TRACE_DEFINE_ENUM(RPC_TASK_NEED_XMIT); 112 TRACE_DEFINE_ENUM(RPC_TASK_NEED_RECV); 113 TRACE_DEFINE_ENUM(RPC_TASK_MSG_PIN_WAIT); 114 115 #define rpc_show_runstate(flags) \ 116 __print_flags(flags, "|", \ 117 { (1UL << RPC_TASK_RUNNING), "RUNNING" }, \ 118 { (1UL << RPC_TASK_QUEUED), "QUEUED" }, \ 119 { (1UL << RPC_TASK_ACTIVE), "ACTIVE" }, \ 120 { (1UL << RPC_TASK_NEED_XMIT), "NEED_XMIT" }, \ 121 { (1UL << RPC_TASK_NEED_RECV), "NEED_RECV" }, \ 122 { (1UL << RPC_TASK_MSG_PIN_WAIT), "MSG_PIN_WAIT" }) 123 124 DECLARE_EVENT_CLASS(rpc_task_running, 125 126 TP_PROTO(const struct rpc_task *task, const void *action), 127 128 TP_ARGS(task, action), 129 130 TP_STRUCT__entry( 131 __field(unsigned int, task_id) 132 __field(unsigned int, client_id) 133 __field(const void *, action) 134 __field(unsigned long, runstate) 135 __field(int, status) 136 __field(unsigned short, flags) 137 ), 138 139 TP_fast_assign( 140 __entry->client_id = task->tk_client ? 141 task->tk_client->cl_clid : -1; 142 __entry->task_id = task->tk_pid; 143 __entry->action = action; 144 __entry->runstate = task->tk_runstate; 145 __entry->status = task->tk_status; 146 __entry->flags = task->tk_flags; 147 ), 148 149 TP_printk("task:%u@%d flags=%s runstate=%s status=%d action=%pf", 150 __entry->task_id, __entry->client_id, 151 rpc_show_task_flags(__entry->flags), 152 rpc_show_runstate(__entry->runstate), 153 __entry->status, 154 __entry->action 155 ) 156 ); 157 #define DEFINE_RPC_RUNNING_EVENT(name) \ 158 DEFINE_EVENT(rpc_task_running, rpc_task_##name, \ 159 TP_PROTO( \ 160 const struct rpc_task *task, \ 161 const void *action \ 162 ), \ 163 TP_ARGS(task, action)) 164 165 DEFINE_RPC_RUNNING_EVENT(begin); 166 DEFINE_RPC_RUNNING_EVENT(run_action); 167 DEFINE_RPC_RUNNING_EVENT(complete); 168 169 DECLARE_EVENT_CLASS(rpc_task_queued, 170 171 TP_PROTO(const struct rpc_task *task, const struct rpc_wait_queue *q), 172 173 TP_ARGS(task, q), 174 175 TP_STRUCT__entry( 176 __field(unsigned int, task_id) 177 __field(unsigned int, client_id) 178 __field(unsigned long, timeout) 179 __field(unsigned long, runstate) 180 __field(int, status) 181 __field(unsigned short, flags) 182 __string(q_name, rpc_qname(q)) 183 ), 184 185 TP_fast_assign( 186 __entry->client_id = task->tk_client ? 187 task->tk_client->cl_clid : -1; 188 __entry->task_id = task->tk_pid; 189 __entry->timeout = task->tk_timeout; 190 __entry->runstate = task->tk_runstate; 191 __entry->status = task->tk_status; 192 __entry->flags = task->tk_flags; 193 __assign_str(q_name, rpc_qname(q)); 194 ), 195 196 TP_printk("task:%u@%d flags=%s runstate=%s status=%d timeout=%lu queue=%s", 197 __entry->task_id, __entry->client_id, 198 rpc_show_task_flags(__entry->flags), 199 rpc_show_runstate(__entry->runstate), 200 __entry->status, 201 __entry->timeout, 202 __get_str(q_name) 203 ) 204 ); 205 #define DEFINE_RPC_QUEUED_EVENT(name) \ 206 DEFINE_EVENT(rpc_task_queued, rpc_task_##name, \ 207 TP_PROTO( \ 208 const struct rpc_task *task, \ 209 const struct rpc_wait_queue *q \ 210 ), \ 211 TP_ARGS(task, q)) 212 213 DEFINE_RPC_QUEUED_EVENT(sleep); 214 DEFINE_RPC_QUEUED_EVENT(wakeup); 215 216 DECLARE_EVENT_CLASS(rpc_failure, 217 218 TP_PROTO(const struct rpc_task *task), 219 220 TP_ARGS(task), 221 222 TP_STRUCT__entry( 223 __field(unsigned int, task_id) 224 __field(unsigned int, client_id) 225 ), 226 227 TP_fast_assign( 228 __entry->task_id = task->tk_pid; 229 __entry->client_id = task->tk_client->cl_clid; 230 ), 231 232 TP_printk("task:%u@%u", 233 __entry->task_id, __entry->client_id) 234 ); 235 236 #define DEFINE_RPC_FAILURE(name) \ 237 DEFINE_EVENT(rpc_failure, rpc_bad_##name, \ 238 TP_PROTO( \ 239 const struct rpc_task *task \ 240 ), \ 241 TP_ARGS(task)) 242 243 DEFINE_RPC_FAILURE(callhdr); 244 DEFINE_RPC_FAILURE(verifier); 245 246 DECLARE_EVENT_CLASS(rpc_reply_event, 247 248 TP_PROTO( 249 const struct rpc_task *task 250 ), 251 252 TP_ARGS(task), 253 254 TP_STRUCT__entry( 255 __field(unsigned int, task_id) 256 __field(unsigned int, client_id) 257 __field(u32, xid) 258 __string(progname, task->tk_client->cl_program->name) 259 __field(u32, version) 260 __string(procname, rpc_proc_name(task)) 261 __string(servername, task->tk_xprt->servername) 262 ), 263 264 TP_fast_assign( 265 __entry->task_id = task->tk_pid; 266 __entry->client_id = task->tk_client->cl_clid; 267 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 268 __assign_str(progname, task->tk_client->cl_program->name) 269 __entry->version = task->tk_client->cl_vers; 270 __assign_str(procname, rpc_proc_name(task)) 271 __assign_str(servername, task->tk_xprt->servername) 272 ), 273 274 TP_printk("task:%u@%d server=%s xid=0x%08x %sv%d %s", 275 __entry->task_id, __entry->client_id, __get_str(servername), 276 __entry->xid, __get_str(progname), __entry->version, 277 __get_str(procname)) 278 ) 279 280 #define DEFINE_RPC_REPLY_EVENT(name) \ 281 DEFINE_EVENT(rpc_reply_event, rpc__##name, \ 282 TP_PROTO( \ 283 const struct rpc_task *task \ 284 ), \ 285 TP_ARGS(task)) 286 287 DEFINE_RPC_REPLY_EVENT(prog_unavail); 288 DEFINE_RPC_REPLY_EVENT(prog_mismatch); 289 DEFINE_RPC_REPLY_EVENT(proc_unavail); 290 DEFINE_RPC_REPLY_EVENT(garbage_args); 291 DEFINE_RPC_REPLY_EVENT(unparsable); 292 DEFINE_RPC_REPLY_EVENT(mismatch); 293 DEFINE_RPC_REPLY_EVENT(stale_creds); 294 DEFINE_RPC_REPLY_EVENT(bad_creds); 295 DEFINE_RPC_REPLY_EVENT(auth_tooweak); 296 297 TRACE_EVENT(rpc_stats_latency, 298 299 TP_PROTO( 300 const struct rpc_task *task, 301 ktime_t backlog, 302 ktime_t rtt, 303 ktime_t execute 304 ), 305 306 TP_ARGS(task, backlog, rtt, execute), 307 308 TP_STRUCT__entry( 309 __field(unsigned int, task_id) 310 __field(unsigned int, client_id) 311 __field(u32, xid) 312 __field(int, version) 313 __string(progname, task->tk_client->cl_program->name) 314 __string(procname, rpc_proc_name(task)) 315 __field(unsigned long, backlog) 316 __field(unsigned long, rtt) 317 __field(unsigned long, execute) 318 ), 319 320 TP_fast_assign( 321 __entry->client_id = task->tk_client->cl_clid; 322 __entry->task_id = task->tk_pid; 323 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 324 __entry->version = task->tk_client->cl_vers; 325 __assign_str(progname, task->tk_client->cl_program->name) 326 __assign_str(procname, rpc_proc_name(task)) 327 __entry->backlog = ktime_to_us(backlog); 328 __entry->rtt = ktime_to_us(rtt); 329 __entry->execute = ktime_to_us(execute); 330 ), 331 332 TP_printk("task:%u@%d xid=0x%08x %sv%d %s backlog=%lu rtt=%lu execute=%lu", 333 __entry->task_id, __entry->client_id, __entry->xid, 334 __get_str(progname), __entry->version, __get_str(procname), 335 __entry->backlog, __entry->rtt, __entry->execute) 336 ); 337 338 TRACE_EVENT(rpc_xdr_overflow, 339 TP_PROTO( 340 const struct xdr_stream *xdr, 341 size_t requested 342 ), 343 344 TP_ARGS(xdr, requested), 345 346 TP_STRUCT__entry( 347 __field(unsigned int, task_id) 348 __field(unsigned int, client_id) 349 __field(int, version) 350 __field(size_t, requested) 351 __field(const void *, end) 352 __field(const void *, p) 353 __field(const void *, head_base) 354 __field(size_t, head_len) 355 __field(const void *, tail_base) 356 __field(size_t, tail_len) 357 __field(unsigned int, page_len) 358 __field(unsigned int, len) 359 __string(progname, 360 xdr->rqst->rq_task->tk_client->cl_program->name) 361 __string(procedure, 362 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name) 363 ), 364 365 TP_fast_assign( 366 if (xdr->rqst) { 367 const struct rpc_task *task = xdr->rqst->rq_task; 368 369 __entry->task_id = task->tk_pid; 370 __entry->client_id = task->tk_client->cl_clid; 371 __assign_str(progname, 372 task->tk_client->cl_program->name) 373 __entry->version = task->tk_client->cl_vers; 374 __assign_str(procedure, task->tk_msg.rpc_proc->p_name) 375 } else { 376 __entry->task_id = 0; 377 __entry->client_id = 0; 378 __assign_str(progname, "unknown") 379 __entry->version = 0; 380 __assign_str(procedure, "unknown") 381 } 382 __entry->requested = requested; 383 __entry->end = xdr->end; 384 __entry->p = xdr->p; 385 __entry->head_base = xdr->buf->head[0].iov_base, 386 __entry->head_len = xdr->buf->head[0].iov_len, 387 __entry->page_len = xdr->buf->page_len, 388 __entry->tail_base = xdr->buf->tail[0].iov_base, 389 __entry->tail_len = xdr->buf->tail[0].iov_len, 390 __entry->len = xdr->buf->len; 391 ), 392 393 TP_printk( 394 "task:%u@%u %sv%d %s requested=%zu p=%p end=%p xdr=[%p,%zu]/%u/[%p,%zu]/%u\n", 395 __entry->task_id, __entry->client_id, 396 __get_str(progname), __entry->version, __get_str(procedure), 397 __entry->requested, __entry->p, __entry->end, 398 __entry->head_base, __entry->head_len, 399 __entry->page_len, 400 __entry->tail_base, __entry->tail_len, 401 __entry->len 402 ) 403 ); 404 405 TRACE_EVENT(rpc_xdr_alignment, 406 TP_PROTO( 407 const struct xdr_stream *xdr, 408 size_t offset, 409 unsigned int copied 410 ), 411 412 TP_ARGS(xdr, offset, copied), 413 414 TP_STRUCT__entry( 415 __field(unsigned int, task_id) 416 __field(unsigned int, client_id) 417 __field(int, version) 418 __field(size_t, offset) 419 __field(unsigned int, copied) 420 __field(const void *, head_base) 421 __field(size_t, head_len) 422 __field(const void *, tail_base) 423 __field(size_t, tail_len) 424 __field(unsigned int, page_len) 425 __field(unsigned int, len) 426 __string(progname, 427 xdr->rqst->rq_task->tk_client->cl_program->name) 428 __string(procedure, 429 xdr->rqst->rq_task->tk_msg.rpc_proc->p_name) 430 ), 431 432 TP_fast_assign( 433 const struct rpc_task *task = xdr->rqst->rq_task; 434 435 __entry->task_id = task->tk_pid; 436 __entry->client_id = task->tk_client->cl_clid; 437 __assign_str(progname, 438 task->tk_client->cl_program->name) 439 __entry->version = task->tk_client->cl_vers; 440 __assign_str(procedure, task->tk_msg.rpc_proc->p_name) 441 442 __entry->offset = offset; 443 __entry->copied = copied; 444 __entry->head_base = xdr->buf->head[0].iov_base, 445 __entry->head_len = xdr->buf->head[0].iov_len, 446 __entry->page_len = xdr->buf->page_len, 447 __entry->tail_base = xdr->buf->tail[0].iov_base, 448 __entry->tail_len = xdr->buf->tail[0].iov_len, 449 __entry->len = xdr->buf->len; 450 ), 451 452 TP_printk( 453 "task:%u@%u %sv%d %s offset=%zu copied=%u xdr=[%p,%zu]/%u/[%p,%zu]/%u\n", 454 __entry->task_id, __entry->client_id, 455 __get_str(progname), __entry->version, __get_str(procedure), 456 __entry->offset, __entry->copied, 457 __entry->head_base, __entry->head_len, 458 __entry->page_len, 459 __entry->tail_base, __entry->tail_len, 460 __entry->len 461 ) 462 ); 463 464 TRACE_EVENT(rpc_reply_pages, 465 TP_PROTO( 466 const struct rpc_rqst *req 467 ), 468 469 TP_ARGS(req), 470 471 TP_STRUCT__entry( 472 __field(unsigned int, task_id) 473 __field(unsigned int, client_id) 474 __field(const void *, head_base) 475 __field(size_t, head_len) 476 __field(const void *, tail_base) 477 __field(size_t, tail_len) 478 __field(unsigned int, page_len) 479 ), 480 481 TP_fast_assign( 482 __entry->task_id = req->rq_task->tk_pid; 483 __entry->client_id = req->rq_task->tk_client->cl_clid; 484 485 __entry->head_base = req->rq_rcv_buf.head[0].iov_base; 486 __entry->head_len = req->rq_rcv_buf.head[0].iov_len; 487 __entry->page_len = req->rq_rcv_buf.page_len; 488 __entry->tail_base = req->rq_rcv_buf.tail[0].iov_base; 489 __entry->tail_len = req->rq_rcv_buf.tail[0].iov_len; 490 ), 491 492 TP_printk( 493 "task:%u@%u xdr=[%p,%zu]/%u/[%p,%zu]\n", 494 __entry->task_id, __entry->client_id, 495 __entry->head_base, __entry->head_len, 496 __entry->page_len, 497 __entry->tail_base, __entry->tail_len 498 ) 499 ); 500 501 /* 502 * First define the enums in the below macros to be exported to userspace 503 * via TRACE_DEFINE_ENUM(). 504 */ 505 #undef EM 506 #undef EMe 507 #define EM(a, b) TRACE_DEFINE_ENUM(a); 508 #define EMe(a, b) TRACE_DEFINE_ENUM(a); 509 510 #define RPC_SHOW_SOCKET \ 511 EM( SS_FREE, "FREE" ) \ 512 EM( SS_UNCONNECTED, "UNCONNECTED" ) \ 513 EM( SS_CONNECTING, "CONNECTING," ) \ 514 EM( SS_CONNECTED, "CONNECTED," ) \ 515 EMe(SS_DISCONNECTING, "DISCONNECTING" ) 516 517 #define rpc_show_socket_state(state) \ 518 __print_symbolic(state, RPC_SHOW_SOCKET) 519 520 RPC_SHOW_SOCKET 521 522 #define RPC_SHOW_SOCK \ 523 EM( TCP_ESTABLISHED, "ESTABLISHED" ) \ 524 EM( TCP_SYN_SENT, "SYN_SENT" ) \ 525 EM( TCP_SYN_RECV, "SYN_RECV" ) \ 526 EM( TCP_FIN_WAIT1, "FIN_WAIT1" ) \ 527 EM( TCP_FIN_WAIT2, "FIN_WAIT2" ) \ 528 EM( TCP_TIME_WAIT, "TIME_WAIT" ) \ 529 EM( TCP_CLOSE, "CLOSE" ) \ 530 EM( TCP_CLOSE_WAIT, "CLOSE_WAIT" ) \ 531 EM( TCP_LAST_ACK, "LAST_ACK" ) \ 532 EM( TCP_LISTEN, "LISTEN" ) \ 533 EMe( TCP_CLOSING, "CLOSING" ) 534 535 #define rpc_show_sock_state(state) \ 536 __print_symbolic(state, RPC_SHOW_SOCK) 537 538 RPC_SHOW_SOCK 539 540 /* 541 * Now redefine the EM() and EMe() macros to map the enums to the strings 542 * that will be printed in the output. 543 */ 544 #undef EM 545 #undef EMe 546 #define EM(a, b) {a, b}, 547 #define EMe(a, b) {a, b} 548 549 DECLARE_EVENT_CLASS(xs_socket_event, 550 551 TP_PROTO( 552 struct rpc_xprt *xprt, 553 struct socket *socket 554 ), 555 556 TP_ARGS(xprt, socket), 557 558 TP_STRUCT__entry( 559 __field(unsigned int, socket_state) 560 __field(unsigned int, sock_state) 561 __field(unsigned long long, ino) 562 __string(dstaddr, 563 xprt->address_strings[RPC_DISPLAY_ADDR]) 564 __string(dstport, 565 xprt->address_strings[RPC_DISPLAY_PORT]) 566 ), 567 568 TP_fast_assign( 569 struct inode *inode = SOCK_INODE(socket); 570 __entry->socket_state = socket->state; 571 __entry->sock_state = socket->sk->sk_state; 572 __entry->ino = (unsigned long long)inode->i_ino; 573 __assign_str(dstaddr, 574 xprt->address_strings[RPC_DISPLAY_ADDR]); 575 __assign_str(dstport, 576 xprt->address_strings[RPC_DISPLAY_PORT]); 577 ), 578 579 TP_printk( 580 "socket:[%llu] dstaddr=%s/%s " 581 "state=%u (%s) sk_state=%u (%s)", 582 __entry->ino, __get_str(dstaddr), __get_str(dstport), 583 __entry->socket_state, 584 rpc_show_socket_state(__entry->socket_state), 585 __entry->sock_state, 586 rpc_show_sock_state(__entry->sock_state) 587 ) 588 ); 589 #define DEFINE_RPC_SOCKET_EVENT(name) \ 590 DEFINE_EVENT(xs_socket_event, name, \ 591 TP_PROTO( \ 592 struct rpc_xprt *xprt, \ 593 struct socket *socket \ 594 ), \ 595 TP_ARGS(xprt, socket)) 596 597 DECLARE_EVENT_CLASS(xs_socket_event_done, 598 599 TP_PROTO( 600 struct rpc_xprt *xprt, 601 struct socket *socket, 602 int error 603 ), 604 605 TP_ARGS(xprt, socket, error), 606 607 TP_STRUCT__entry( 608 __field(int, error) 609 __field(unsigned int, socket_state) 610 __field(unsigned int, sock_state) 611 __field(unsigned long long, ino) 612 __string(dstaddr, 613 xprt->address_strings[RPC_DISPLAY_ADDR]) 614 __string(dstport, 615 xprt->address_strings[RPC_DISPLAY_PORT]) 616 ), 617 618 TP_fast_assign( 619 struct inode *inode = SOCK_INODE(socket); 620 __entry->socket_state = socket->state; 621 __entry->sock_state = socket->sk->sk_state; 622 __entry->ino = (unsigned long long)inode->i_ino; 623 __entry->error = error; 624 __assign_str(dstaddr, 625 xprt->address_strings[RPC_DISPLAY_ADDR]); 626 __assign_str(dstport, 627 xprt->address_strings[RPC_DISPLAY_PORT]); 628 ), 629 630 TP_printk( 631 "error=%d socket:[%llu] dstaddr=%s/%s " 632 "state=%u (%s) sk_state=%u (%s)", 633 __entry->error, 634 __entry->ino, __get_str(dstaddr), __get_str(dstport), 635 __entry->socket_state, 636 rpc_show_socket_state(__entry->socket_state), 637 __entry->sock_state, 638 rpc_show_sock_state(__entry->sock_state) 639 ) 640 ); 641 #define DEFINE_RPC_SOCKET_EVENT_DONE(name) \ 642 DEFINE_EVENT(xs_socket_event_done, name, \ 643 TP_PROTO( \ 644 struct rpc_xprt *xprt, \ 645 struct socket *socket, \ 646 int error \ 647 ), \ 648 TP_ARGS(xprt, socket, error)) 649 650 DEFINE_RPC_SOCKET_EVENT(rpc_socket_state_change); 651 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_connect); 652 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_error); 653 DEFINE_RPC_SOCKET_EVENT_DONE(rpc_socket_reset_connection); 654 DEFINE_RPC_SOCKET_EVENT(rpc_socket_close); 655 DEFINE_RPC_SOCKET_EVENT(rpc_socket_shutdown); 656 657 DECLARE_EVENT_CLASS(rpc_xprt_event, 658 TP_PROTO( 659 const struct rpc_xprt *xprt, 660 __be32 xid, 661 int status 662 ), 663 664 TP_ARGS(xprt, xid, status), 665 666 TP_STRUCT__entry( 667 __field(u32, xid) 668 __field(int, status) 669 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 670 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 671 ), 672 673 TP_fast_assign( 674 __entry->xid = be32_to_cpu(xid); 675 __entry->status = status; 676 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]); 677 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]); 678 ), 679 680 TP_printk("peer=[%s]:%s xid=0x%08x status=%d", __get_str(addr), 681 __get_str(port), __entry->xid, 682 __entry->status) 683 ); 684 #define DEFINE_RPC_XPRT_EVENT(name) \ 685 DEFINE_EVENT(rpc_xprt_event, xprt_##name, \ 686 TP_PROTO( \ 687 const struct rpc_xprt *xprt, \ 688 __be32 xid, \ 689 int status \ 690 ), \ 691 TP_ARGS(xprt, xid, status)) 692 693 DEFINE_RPC_XPRT_EVENT(timer); 694 DEFINE_RPC_XPRT_EVENT(lookup_rqst); 695 DEFINE_RPC_XPRT_EVENT(complete_rqst); 696 697 TRACE_EVENT(xprt_transmit, 698 TP_PROTO( 699 const struct rpc_rqst *rqst, 700 int status 701 ), 702 703 TP_ARGS(rqst, status), 704 705 TP_STRUCT__entry( 706 __field(unsigned int, task_id) 707 __field(unsigned int, client_id) 708 __field(u32, xid) 709 __field(u32, seqno) 710 __field(int, status) 711 ), 712 713 TP_fast_assign( 714 __entry->task_id = rqst->rq_task->tk_pid; 715 __entry->client_id = rqst->rq_task->tk_client ? 716 rqst->rq_task->tk_client->cl_clid : -1; 717 __entry->xid = be32_to_cpu(rqst->rq_xid); 718 __entry->seqno = rqst->rq_seqno; 719 __entry->status = status; 720 ), 721 722 TP_printk( 723 "task:%u@%u xid=0x%08x seqno=%u status=%d", 724 __entry->task_id, __entry->client_id, __entry->xid, 725 __entry->seqno, __entry->status) 726 ); 727 728 TRACE_EVENT(xprt_enq_xmit, 729 TP_PROTO( 730 const struct rpc_task *task, 731 int stage 732 ), 733 734 TP_ARGS(task, stage), 735 736 TP_STRUCT__entry( 737 __field(unsigned int, task_id) 738 __field(unsigned int, client_id) 739 __field(u32, xid) 740 __field(u32, seqno) 741 __field(int, stage) 742 ), 743 744 TP_fast_assign( 745 __entry->task_id = task->tk_pid; 746 __entry->client_id = task->tk_client ? 747 task->tk_client->cl_clid : -1; 748 __entry->xid = be32_to_cpu(task->tk_rqstp->rq_xid); 749 __entry->seqno = task->tk_rqstp->rq_seqno; 750 __entry->stage = stage; 751 ), 752 753 TP_printk( 754 "task:%u@%u xid=0x%08x seqno=%u stage=%d", 755 __entry->task_id, __entry->client_id, __entry->xid, 756 __entry->seqno, __entry->stage) 757 ); 758 759 TRACE_EVENT(xprt_ping, 760 TP_PROTO(const struct rpc_xprt *xprt, int status), 761 762 TP_ARGS(xprt, status), 763 764 TP_STRUCT__entry( 765 __field(int, status) 766 __string(addr, xprt->address_strings[RPC_DISPLAY_ADDR]) 767 __string(port, xprt->address_strings[RPC_DISPLAY_PORT]) 768 ), 769 770 TP_fast_assign( 771 __entry->status = status; 772 __assign_str(addr, xprt->address_strings[RPC_DISPLAY_ADDR]); 773 __assign_str(port, xprt->address_strings[RPC_DISPLAY_PORT]); 774 ), 775 776 TP_printk("peer=[%s]:%s status=%d", 777 __get_str(addr), __get_str(port), __entry->status) 778 ); 779 780 TRACE_EVENT(xs_stream_read_data, 781 TP_PROTO(struct rpc_xprt *xprt, ssize_t err, size_t total), 782 783 TP_ARGS(xprt, err, total), 784 785 TP_STRUCT__entry( 786 __field(ssize_t, err) 787 __field(size_t, total) 788 __string(addr, xprt ? xprt->address_strings[RPC_DISPLAY_ADDR] : 789 "(null)") 790 __string(port, xprt ? xprt->address_strings[RPC_DISPLAY_PORT] : 791 "(null)") 792 ), 793 794 TP_fast_assign( 795 __entry->err = err; 796 __entry->total = total; 797 __assign_str(addr, xprt ? 798 xprt->address_strings[RPC_DISPLAY_ADDR] : "(null)"); 799 __assign_str(port, xprt ? 800 xprt->address_strings[RPC_DISPLAY_PORT] : "(null)"); 801 ), 802 803 TP_printk("peer=[%s]:%s err=%zd total=%zu", __get_str(addr), 804 __get_str(port), __entry->err, __entry->total) 805 ); 806 807 TRACE_EVENT(xs_stream_read_request, 808 TP_PROTO(struct sock_xprt *xs), 809 810 TP_ARGS(xs), 811 812 TP_STRUCT__entry( 813 __string(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]) 814 __string(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]) 815 __field(u32, xid) 816 __field(unsigned long, copied) 817 __field(unsigned int, reclen) 818 __field(unsigned int, offset) 819 ), 820 821 TP_fast_assign( 822 __assign_str(addr, xs->xprt.address_strings[RPC_DISPLAY_ADDR]); 823 __assign_str(port, xs->xprt.address_strings[RPC_DISPLAY_PORT]); 824 __entry->xid = be32_to_cpu(xs->recv.xid); 825 __entry->copied = xs->recv.copied; 826 __entry->reclen = xs->recv.len; 827 __entry->offset = xs->recv.offset; 828 ), 829 830 TP_printk("peer=[%s]:%s xid=0x%08x copied=%lu reclen=%u offset=%u", 831 __get_str(addr), __get_str(port), __entry->xid, 832 __entry->copied, __entry->reclen, __entry->offset) 833 ); 834 835 #define show_rqstp_flags(flags) \ 836 __print_flags(flags, "|", \ 837 { (1UL << RQ_SECURE), "RQ_SECURE"}, \ 838 { (1UL << RQ_LOCAL), "RQ_LOCAL"}, \ 839 { (1UL << RQ_USEDEFERRAL), "RQ_USEDEFERRAL"}, \ 840 { (1UL << RQ_DROPME), "RQ_DROPME"}, \ 841 { (1UL << RQ_SPLICE_OK), "RQ_SPLICE_OK"}, \ 842 { (1UL << RQ_VICTIM), "RQ_VICTIM"}, \ 843 { (1UL << RQ_BUSY), "RQ_BUSY"}) 844 845 TRACE_EVENT(svc_recv, 846 TP_PROTO(struct svc_rqst *rqst, int len), 847 848 TP_ARGS(rqst, len), 849 850 TP_STRUCT__entry( 851 __field(u32, xid) 852 __field(int, len) 853 __field(unsigned long, flags) 854 __string(addr, rqst->rq_xprt->xpt_remotebuf) 855 ), 856 857 TP_fast_assign( 858 __entry->xid = be32_to_cpu(rqst->rq_xid); 859 __entry->len = len; 860 __entry->flags = rqst->rq_flags; 861 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf); 862 ), 863 864 TP_printk("addr=%s xid=0x%08x len=%d flags=%s", 865 __get_str(addr), __entry->xid, __entry->len, 866 show_rqstp_flags(__entry->flags)) 867 ); 868 869 TRACE_EVENT(svc_process, 870 TP_PROTO(const struct svc_rqst *rqst, const char *name), 871 872 TP_ARGS(rqst, name), 873 874 TP_STRUCT__entry( 875 __field(u32, xid) 876 __field(u32, vers) 877 __field(u32, proc) 878 __string(service, name) 879 __string(addr, rqst->rq_xprt ? 880 rqst->rq_xprt->xpt_remotebuf : "(null)") 881 ), 882 883 TP_fast_assign( 884 __entry->xid = be32_to_cpu(rqst->rq_xid); 885 __entry->vers = rqst->rq_vers; 886 __entry->proc = rqst->rq_proc; 887 __assign_str(service, name); 888 __assign_str(addr, rqst->rq_xprt ? 889 rqst->rq_xprt->xpt_remotebuf : "(null)"); 890 ), 891 892 TP_printk("addr=%s xid=0x%08x service=%s vers=%u proc=%u", 893 __get_str(addr), __entry->xid, 894 __get_str(service), __entry->vers, __entry->proc) 895 ); 896 897 DECLARE_EVENT_CLASS(svc_rqst_event, 898 899 TP_PROTO( 900 const struct svc_rqst *rqst 901 ), 902 903 TP_ARGS(rqst), 904 905 TP_STRUCT__entry( 906 __field(u32, xid) 907 __field(unsigned long, flags) 908 __string(addr, rqst->rq_xprt->xpt_remotebuf) 909 ), 910 911 TP_fast_assign( 912 __entry->xid = be32_to_cpu(rqst->rq_xid); 913 __entry->flags = rqst->rq_flags; 914 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf); 915 ), 916 917 TP_printk("addr=%s xid=0x%08x flags=%s", 918 __get_str(addr), __entry->xid, 919 show_rqstp_flags(__entry->flags)) 920 ); 921 #define DEFINE_SVC_RQST_EVENT(name) \ 922 DEFINE_EVENT(svc_rqst_event, svc_##name, \ 923 TP_PROTO( \ 924 const struct svc_rqst *rqst \ 925 ), \ 926 TP_ARGS(rqst)) 927 928 DEFINE_SVC_RQST_EVENT(defer); 929 DEFINE_SVC_RQST_EVENT(drop); 930 931 DECLARE_EVENT_CLASS(svc_rqst_status, 932 933 TP_PROTO(struct svc_rqst *rqst, int status), 934 935 TP_ARGS(rqst, status), 936 937 TP_STRUCT__entry( 938 __field(u32, xid) 939 __field(int, status) 940 __field(unsigned long, flags) 941 __string(addr, rqst->rq_xprt->xpt_remotebuf) 942 ), 943 944 TP_fast_assign( 945 __entry->xid = be32_to_cpu(rqst->rq_xid); 946 __entry->status = status; 947 __entry->flags = rqst->rq_flags; 948 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf); 949 ), 950 951 TP_printk("addr=%s xid=0x%08x status=%d flags=%s", 952 __get_str(addr), __entry->xid, 953 __entry->status, show_rqstp_flags(__entry->flags)) 954 ); 955 956 DEFINE_EVENT(svc_rqst_status, svc_send, 957 TP_PROTO(struct svc_rqst *rqst, int status), 958 TP_ARGS(rqst, status)); 959 960 #define show_svc_xprt_flags(flags) \ 961 __print_flags(flags, "|", \ 962 { (1UL << XPT_BUSY), "XPT_BUSY"}, \ 963 { (1UL << XPT_CONN), "XPT_CONN"}, \ 964 { (1UL << XPT_CLOSE), "XPT_CLOSE"}, \ 965 { (1UL << XPT_DATA), "XPT_DATA"}, \ 966 { (1UL << XPT_TEMP), "XPT_TEMP"}, \ 967 { (1UL << XPT_DEAD), "XPT_DEAD"}, \ 968 { (1UL << XPT_CHNGBUF), "XPT_CHNGBUF"}, \ 969 { (1UL << XPT_DEFERRED), "XPT_DEFERRED"}, \ 970 { (1UL << XPT_OLD), "XPT_OLD"}, \ 971 { (1UL << XPT_LISTENER), "XPT_LISTENER"}, \ 972 { (1UL << XPT_CACHE_AUTH), "XPT_CACHE_AUTH"}, \ 973 { (1UL << XPT_LOCAL), "XPT_LOCAL"}, \ 974 { (1UL << XPT_KILL_TEMP), "XPT_KILL_TEMP"}, \ 975 { (1UL << XPT_CONG_CTRL), "XPT_CONG_CTRL"}) 976 977 TRACE_EVENT(svc_xprt_do_enqueue, 978 TP_PROTO(struct svc_xprt *xprt, struct svc_rqst *rqst), 979 980 TP_ARGS(xprt, rqst), 981 982 TP_STRUCT__entry( 983 __field(struct svc_xprt *, xprt) 984 __field(int, pid) 985 __field(unsigned long, flags) 986 __string(addr, xprt->xpt_remotebuf) 987 ), 988 989 TP_fast_assign( 990 __entry->xprt = xprt; 991 __entry->pid = rqst? rqst->rq_task->pid : 0; 992 __entry->flags = xprt->xpt_flags; 993 __assign_str(addr, xprt->xpt_remotebuf); 994 ), 995 996 TP_printk("xprt=%p addr=%s pid=%d flags=%s", 997 __entry->xprt, __get_str(addr), 998 __entry->pid, show_svc_xprt_flags(__entry->flags)) 999 ); 1000 1001 DECLARE_EVENT_CLASS(svc_xprt_event, 1002 TP_PROTO(struct svc_xprt *xprt), 1003 1004 TP_ARGS(xprt), 1005 1006 TP_STRUCT__entry( 1007 __field(struct svc_xprt *, xprt) 1008 __field(unsigned long, flags) 1009 __string(addr, xprt->xpt_remotebuf) 1010 ), 1011 1012 TP_fast_assign( 1013 __entry->xprt = xprt; 1014 __entry->flags = xprt->xpt_flags; 1015 __assign_str(addr, xprt->xpt_remotebuf); 1016 ), 1017 1018 TP_printk("xprt=%p addr=%s flags=%s", 1019 __entry->xprt, __get_str(addr), 1020 show_svc_xprt_flags(__entry->flags)) 1021 ); 1022 1023 DEFINE_EVENT(svc_xprt_event, svc_xprt_no_write_space, 1024 TP_PROTO(struct svc_xprt *xprt), 1025 TP_ARGS(xprt)); 1026 1027 TRACE_EVENT(svc_xprt_dequeue, 1028 TP_PROTO(struct svc_rqst *rqst), 1029 1030 TP_ARGS(rqst), 1031 1032 TP_STRUCT__entry( 1033 __field(struct svc_xprt *, xprt) 1034 __field(unsigned long, flags) 1035 __field(unsigned long, wakeup) 1036 __string(addr, rqst->rq_xprt->xpt_remotebuf) 1037 ), 1038 1039 TP_fast_assign( 1040 __entry->xprt = rqst->rq_xprt; 1041 __entry->flags = rqst->rq_xprt->xpt_flags; 1042 __entry->wakeup = ktime_to_us(ktime_sub(ktime_get(), 1043 rqst->rq_qtime)); 1044 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf); 1045 ), 1046 1047 TP_printk("xprt=%p addr=%s flags=%s wakeup-us=%lu", 1048 __entry->xprt, __get_str(addr), 1049 show_svc_xprt_flags(__entry->flags), 1050 __entry->wakeup) 1051 ); 1052 1053 TRACE_EVENT(svc_wake_up, 1054 TP_PROTO(int pid), 1055 1056 TP_ARGS(pid), 1057 1058 TP_STRUCT__entry( 1059 __field(int, pid) 1060 ), 1061 1062 TP_fast_assign( 1063 __entry->pid = pid; 1064 ), 1065 1066 TP_printk("pid=%d", __entry->pid) 1067 ); 1068 1069 TRACE_EVENT(svc_handle_xprt, 1070 TP_PROTO(struct svc_xprt *xprt, int len), 1071 1072 TP_ARGS(xprt, len), 1073 1074 TP_STRUCT__entry( 1075 __field(struct svc_xprt *, xprt) 1076 __field(int, len) 1077 __field(unsigned long, flags) 1078 __string(addr, xprt->xpt_remotebuf) 1079 ), 1080 1081 TP_fast_assign( 1082 __entry->xprt = xprt; 1083 __entry->len = len; 1084 __entry->flags = xprt->xpt_flags; 1085 __assign_str(addr, xprt->xpt_remotebuf); 1086 ), 1087 1088 TP_printk("xprt=%p addr=%s len=%d flags=%s", 1089 __entry->xprt, __get_str(addr), 1090 __entry->len, show_svc_xprt_flags(__entry->flags)) 1091 ); 1092 1093 TRACE_EVENT(svc_stats_latency, 1094 TP_PROTO(const struct svc_rqst *rqst), 1095 1096 TP_ARGS(rqst), 1097 1098 TP_STRUCT__entry( 1099 __field(u32, xid) 1100 __field(unsigned long, execute) 1101 __string(addr, rqst->rq_xprt->xpt_remotebuf) 1102 ), 1103 1104 TP_fast_assign( 1105 __entry->xid = be32_to_cpu(rqst->rq_xid); 1106 __entry->execute = ktime_to_us(ktime_sub(ktime_get(), 1107 rqst->rq_stime)); 1108 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf); 1109 ), 1110 1111 TP_printk("addr=%s xid=0x%08x execute-us=%lu", 1112 __get_str(addr), __entry->xid, __entry->execute) 1113 ); 1114 1115 DECLARE_EVENT_CLASS(svc_deferred_event, 1116 TP_PROTO( 1117 const struct svc_deferred_req *dr 1118 ), 1119 1120 TP_ARGS(dr), 1121 1122 TP_STRUCT__entry( 1123 __field(u32, xid) 1124 __string(addr, dr->xprt->xpt_remotebuf) 1125 ), 1126 1127 TP_fast_assign( 1128 __entry->xid = be32_to_cpu(*(__be32 *)(dr->args + 1129 (dr->xprt_hlen>>2))); 1130 __assign_str(addr, dr->xprt->xpt_remotebuf); 1131 ), 1132 1133 TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid) 1134 ); 1135 #define DEFINE_SVC_DEFERRED_EVENT(name) \ 1136 DEFINE_EVENT(svc_deferred_event, svc_##name##_deferred, \ 1137 TP_PROTO( \ 1138 const struct svc_deferred_req *dr \ 1139 ), \ 1140 TP_ARGS(dr)) 1141 1142 DEFINE_SVC_DEFERRED_EVENT(drop); 1143 DEFINE_SVC_DEFERRED_EVENT(revisit); 1144 1145 #endif /* _TRACE_SUNRPC_H */ 1146 1147 #include <trace/define_trace.h> 1148