hc
2024-01-31 f9004dbfff8a3fbbd7e2a88c8a4327c7f2f8e5b2
kernel/include/trace/events/rpcrdma.h
....@@ -10,12 +10,55 @@
1010 #if !defined(_TRACE_RPCRDMA_H) || defined(TRACE_HEADER_MULTI_READ)
1111 #define _TRACE_RPCRDMA_H
1212
13
+#include <linux/scatterlist.h>
14
+#include <linux/sunrpc/rpc_rdma_cid.h>
1315 #include <linux/tracepoint.h>
16
+#include <rdma/ib_cm.h>
1417 #include <trace/events/rdma.h>
1518
1619 /**
1720 ** Event classes
1821 **/
22
+
23
+DECLARE_EVENT_CLASS(rpcrdma_completion_class,
24
+ TP_PROTO(
25
+ const struct ib_wc *wc,
26
+ const struct rpc_rdma_cid *cid
27
+ ),
28
+
29
+ TP_ARGS(wc, cid),
30
+
31
+ TP_STRUCT__entry(
32
+ __field(u32, cq_id)
33
+ __field(int, completion_id)
34
+ __field(unsigned long, status)
35
+ __field(unsigned int, vendor_err)
36
+ ),
37
+
38
+ TP_fast_assign(
39
+ __entry->cq_id = cid->ci_queue_id;
40
+ __entry->completion_id = cid->ci_completion_id;
41
+ __entry->status = wc->status;
42
+ if (wc->status)
43
+ __entry->vendor_err = wc->vendor_err;
44
+ else
45
+ __entry->vendor_err = 0;
46
+ ),
47
+
48
+ TP_printk("cq.id=%u cid=%d status=%s (%lu/0x%x)",
49
+ __entry->cq_id, __entry->completion_id,
50
+ rdma_show_wc_status(__entry->status),
51
+ __entry->status, __entry->vendor_err
52
+ )
53
+);
54
+
55
+#define DEFINE_COMPLETION_EVENT(name) \
56
+ DEFINE_EVENT(rpcrdma_completion_class, name, \
57
+ TP_PROTO( \
58
+ const struct ib_wc *wc, \
59
+ const struct rpc_rdma_cid *cid \
60
+ ), \
61
+ TP_ARGS(wc, cid))
1962
2063 DECLARE_EVENT_CLASS(xprtrdma_reply_event,
2164 TP_PROTO(
....@@ -84,6 +127,44 @@
84127 ), \
85128 TP_ARGS(r_xprt))
86129
130
+DECLARE_EVENT_CLASS(xprtrdma_connect_class,
131
+ TP_PROTO(
132
+ const struct rpcrdma_xprt *r_xprt,
133
+ int rc
134
+ ),
135
+
136
+ TP_ARGS(r_xprt, rc),
137
+
138
+ TP_STRUCT__entry(
139
+ __field(const void *, r_xprt)
140
+ __field(int, rc)
141
+ __field(int, connect_status)
142
+ __string(addr, rpcrdma_addrstr(r_xprt))
143
+ __string(port, rpcrdma_portstr(r_xprt))
144
+ ),
145
+
146
+ TP_fast_assign(
147
+ __entry->r_xprt = r_xprt;
148
+ __entry->rc = rc;
149
+ __entry->connect_status = r_xprt->rx_ep->re_connect_status;
150
+ __assign_str(addr, rpcrdma_addrstr(r_xprt));
151
+ __assign_str(port, rpcrdma_portstr(r_xprt));
152
+ ),
153
+
154
+ TP_printk("peer=[%s]:%s r_xprt=%p: rc=%d connection status=%d",
155
+ __get_str(addr), __get_str(port), __entry->r_xprt,
156
+ __entry->rc, __entry->connect_status
157
+ )
158
+);
159
+
160
+#define DEFINE_CONN_EVENT(name) \
161
+ DEFINE_EVENT(xprtrdma_connect_class, xprtrdma_##name, \
162
+ TP_PROTO( \
163
+ const struct rpcrdma_xprt *r_xprt, \
164
+ int rc \
165
+ ), \
166
+ TP_ARGS(r_xprt, rc))
167
+
87168 DECLARE_EVENT_CLASS(xprtrdma_rdch_event,
88169 TP_PROTO(
89170 const struct rpc_task *task,
....@@ -97,7 +178,6 @@
97178 TP_STRUCT__entry(
98179 __field(unsigned int, task_id)
99180 __field(unsigned int, client_id)
100
- __field(const void *, mr)
101181 __field(unsigned int, pos)
102182 __field(int, nents)
103183 __field(u32, handle)
....@@ -109,7 +189,6 @@
109189 TP_fast_assign(
110190 __entry->task_id = task->tk_pid;
111191 __entry->client_id = task->tk_client->cl_clid;
112
- __entry->mr = mr;
113192 __entry->pos = pos;
114193 __entry->nents = mr->mr_nents;
115194 __entry->handle = mr->mr_handle;
....@@ -118,8 +197,8 @@
118197 __entry->nsegs = nsegs;
119198 ),
120199
121
- TP_printk("task:%u@%u mr=%p pos=%u %u@0x%016llx:0x%08x (%s)",
122
- __entry->task_id, __entry->client_id, __entry->mr,
200
+ TP_printk("task:%u@%u pos=%u %u@0x%016llx:0x%08x (%s)",
201
+ __entry->task_id, __entry->client_id,
123202 __entry->pos, __entry->length,
124203 (unsigned long long)__entry->offset, __entry->handle,
125204 __entry->nents < __entry->nsegs ? "more" : "last"
....@@ -127,7 +206,7 @@
127206 );
128207
129208 #define DEFINE_RDCH_EVENT(name) \
130
- DEFINE_EVENT(xprtrdma_rdch_event, name, \
209
+ DEFINE_EVENT(xprtrdma_rdch_event, xprtrdma_chunk_##name,\
131210 TP_PROTO( \
132211 const struct rpc_task *task, \
133212 unsigned int pos, \
....@@ -148,7 +227,6 @@
148227 TP_STRUCT__entry(
149228 __field(unsigned int, task_id)
150229 __field(unsigned int, client_id)
151
- __field(const void *, mr)
152230 __field(int, nents)
153231 __field(u32, handle)
154232 __field(u32, length)
....@@ -159,7 +237,6 @@
159237 TP_fast_assign(
160238 __entry->task_id = task->tk_pid;
161239 __entry->client_id = task->tk_client->cl_clid;
162
- __entry->mr = mr;
163240 __entry->nents = mr->mr_nents;
164241 __entry->handle = mr->mr_handle;
165242 __entry->length = mr->mr_length;
....@@ -167,8 +244,8 @@
167244 __entry->nsegs = nsegs;
168245 ),
169246
170
- TP_printk("task:%u@%u mr=%p %u@0x%016llx:0x%08x (%s)",
171
- __entry->task_id, __entry->client_id, __entry->mr,
247
+ TP_printk("task:%u@%u %u@0x%016llx:0x%08x (%s)",
248
+ __entry->task_id, __entry->client_id,
172249 __entry->length, (unsigned long long)__entry->offset,
173250 __entry->handle,
174251 __entry->nents < __entry->nsegs ? "more" : "last"
....@@ -176,25 +253,13 @@
176253 );
177254
178255 #define DEFINE_WRCH_EVENT(name) \
179
- DEFINE_EVENT(xprtrdma_wrch_event, name, \
256
+ DEFINE_EVENT(xprtrdma_wrch_event, xprtrdma_chunk_##name,\
180257 TP_PROTO( \
181258 const struct rpc_task *task, \
182259 struct rpcrdma_mr *mr, \
183260 int nsegs \
184261 ), \
185262 TP_ARGS(task, mr, nsegs))
186
-
187
-TRACE_DEFINE_ENUM(FRWR_IS_INVALID);
188
-TRACE_DEFINE_ENUM(FRWR_IS_VALID);
189
-TRACE_DEFINE_ENUM(FRWR_FLUSHED_FR);
190
-TRACE_DEFINE_ENUM(FRWR_FLUSHED_LI);
191
-
192
-#define xprtrdma_show_frwr_state(x) \
193
- __print_symbolic(x, \
194
- { FRWR_IS_INVALID, "INVALID" }, \
195
- { FRWR_IS_VALID, "VALID" }, \
196
- { FRWR_FLUSHED_FR, "FLUSHED_FR" }, \
197
- { FRWR_FLUSHED_LI, "FLUSHED_LI" })
198263
199264 DECLARE_EVENT_CLASS(xprtrdma_frwr_done,
200265 TP_PROTO(
....@@ -205,23 +270,20 @@
205270 TP_ARGS(wc, frwr),
206271
207272 TP_STRUCT__entry(
208
- __field(const void *, mr)
209
- __field(unsigned int, state)
273
+ __field(u32, mr_id)
210274 __field(unsigned int, status)
211275 __field(unsigned int, vendor_err)
212276 ),
213277
214278 TP_fast_assign(
215
- __entry->mr = container_of(frwr, struct rpcrdma_mr, frwr);
216
- __entry->state = frwr->fr_state;
279
+ __entry->mr_id = frwr->fr_mr->res.id;
217280 __entry->status = wc->status;
218281 __entry->vendor_err = __entry->status ? wc->vendor_err : 0;
219282 ),
220283
221284 TP_printk(
222
- "mr=%p state=%s: %s (%u/0x%x)",
223
- __entry->mr, xprtrdma_show_frwr_state(__entry->state),
224
- rdma_show_wc_status(__entry->status),
285
+ "mr.id=%u: %s (%u/0x%x)",
286
+ __entry->mr_id, rdma_show_wc_status(__entry->status),
225287 __entry->status, __entry->vendor_err
226288 )
227289 );
....@@ -234,6 +296,18 @@
234296 ), \
235297 TP_ARGS(wc, frwr))
236298
299
+TRACE_DEFINE_ENUM(DMA_BIDIRECTIONAL);
300
+TRACE_DEFINE_ENUM(DMA_TO_DEVICE);
301
+TRACE_DEFINE_ENUM(DMA_FROM_DEVICE);
302
+TRACE_DEFINE_ENUM(DMA_NONE);
303
+
304
+#define xprtrdma_show_direction(x) \
305
+ __print_symbolic(x, \
306
+ { DMA_BIDIRECTIONAL, "BIDIR" }, \
307
+ { DMA_TO_DEVICE, "TO_DEVICE" }, \
308
+ { DMA_FROM_DEVICE, "FROM_DEVICE" }, \
309
+ { DMA_NONE, "NONE" })
310
+
237311 DECLARE_EVENT_CLASS(xprtrdma_mr,
238312 TP_PROTO(
239313 const struct rpcrdma_mr *mr
....@@ -242,28 +316,32 @@
242316 TP_ARGS(mr),
243317
244318 TP_STRUCT__entry(
245
- __field(const void *, mr)
319
+ __field(u32, mr_id)
320
+ __field(int, nents)
246321 __field(u32, handle)
247322 __field(u32, length)
248323 __field(u64, offset)
324
+ __field(u32, dir)
249325 ),
250326
251327 TP_fast_assign(
252
- __entry->mr = mr;
328
+ __entry->mr_id = mr->frwr.fr_mr->res.id;
329
+ __entry->nents = mr->mr_nents;
253330 __entry->handle = mr->mr_handle;
254331 __entry->length = mr->mr_length;
255332 __entry->offset = mr->mr_offset;
333
+ __entry->dir = mr->mr_dir;
256334 ),
257335
258
- TP_printk("mr=%p %u@0x%016llx:0x%08x",
259
- __entry->mr, __entry->length,
260
- (unsigned long long)__entry->offset,
261
- __entry->handle
336
+ TP_printk("mr.id=%u nents=%d %u@0x%016llx:0x%08x (%s)",
337
+ __entry->mr_id, __entry->nents, __entry->length,
338
+ (unsigned long long)__entry->offset, __entry->handle,
339
+ xprtrdma_show_direction(__entry->dir)
262340 )
263341 );
264342
265343 #define DEFINE_MR_EVENT(name) \
266
- DEFINE_EVENT(xprtrdma_mr, name, \
344
+ DEFINE_EVENT(xprtrdma_mr, xprtrdma_mr_##name, \
267345 TP_PROTO( \
268346 const struct rpcrdma_mr *mr \
269347 ), \
....@@ -306,105 +384,136 @@
306384 ** Connection events
307385 **/
308386
309
-TRACE_EVENT(xprtrdma_conn_upcall,
387
+TRACE_EVENT(xprtrdma_inline_thresh,
310388 TP_PROTO(
311
- const struct rpcrdma_xprt *r_xprt,
312
- struct rdma_cm_event *event
389
+ const struct rpcrdma_ep *ep
313390 ),
314391
315
- TP_ARGS(r_xprt, event),
392
+ TP_ARGS(ep),
393
+
394
+ TP_STRUCT__entry(
395
+ __field(unsigned int, inline_send)
396
+ __field(unsigned int, inline_recv)
397
+ __field(unsigned int, max_send)
398
+ __field(unsigned int, max_recv)
399
+ __array(unsigned char, srcaddr, sizeof(struct sockaddr_in6))
400
+ __array(unsigned char, dstaddr, sizeof(struct sockaddr_in6))
401
+ ),
402
+
403
+ TP_fast_assign(
404
+ const struct rdma_cm_id *id = ep->re_id;
405
+
406
+ __entry->inline_send = ep->re_inline_send;
407
+ __entry->inline_recv = ep->re_inline_recv;
408
+ __entry->max_send = ep->re_max_inline_send;
409
+ __entry->max_recv = ep->re_max_inline_recv;
410
+ memcpy(__entry->srcaddr, &id->route.addr.src_addr,
411
+ sizeof(struct sockaddr_in6));
412
+ memcpy(__entry->dstaddr, &id->route.addr.dst_addr,
413
+ sizeof(struct sockaddr_in6));
414
+ ),
415
+
416
+ TP_printk("%pISpc -> %pISpc neg send/recv=%u/%u, calc send/recv=%u/%u",
417
+ __entry->srcaddr, __entry->dstaddr,
418
+ __entry->inline_send, __entry->inline_recv,
419
+ __entry->max_send, __entry->max_recv
420
+ )
421
+);
422
+
423
+DEFINE_CONN_EVENT(connect);
424
+DEFINE_CONN_EVENT(disconnect);
425
+
426
+DEFINE_RXPRT_EVENT(xprtrdma_op_inject_dsc);
427
+
428
+TRACE_EVENT(xprtrdma_op_connect,
429
+ TP_PROTO(
430
+ const struct rpcrdma_xprt *r_xprt,
431
+ unsigned long delay
432
+ ),
433
+
434
+ TP_ARGS(r_xprt, delay),
316435
317436 TP_STRUCT__entry(
318437 __field(const void *, r_xprt)
319
- __field(unsigned int, event)
320
- __field(int, status)
438
+ __field(unsigned long, delay)
321439 __string(addr, rpcrdma_addrstr(r_xprt))
322440 __string(port, rpcrdma_portstr(r_xprt))
323441 ),
324442
325443 TP_fast_assign(
326444 __entry->r_xprt = r_xprt;
327
- __entry->event = event->event;
328
- __entry->status = event->status;
445
+ __entry->delay = delay;
329446 __assign_str(addr, rpcrdma_addrstr(r_xprt));
330447 __assign_str(port, rpcrdma_portstr(r_xprt));
331448 ),
332449
333
- TP_printk("peer=[%s]:%s r_xprt=%p: %s (%u/%d)",
334
- __get_str(addr), __get_str(port),
335
- __entry->r_xprt, rdma_show_cm_event(__entry->event),
336
- __entry->event, __entry->status
450
+ TP_printk("peer=[%s]:%s r_xprt=%p delay=%lu",
451
+ __get_str(addr), __get_str(port), __entry->r_xprt,
452
+ __entry->delay
337453 )
338454 );
339455
340
-TRACE_EVENT(xprtrdma_disconnect,
456
+
457
+TRACE_EVENT(xprtrdma_op_set_cto,
341458 TP_PROTO(
342459 const struct rpcrdma_xprt *r_xprt,
343
- int status
460
+ unsigned long connect,
461
+ unsigned long reconnect
344462 ),
345463
346
- TP_ARGS(r_xprt, status),
464
+ TP_ARGS(r_xprt, connect, reconnect),
347465
348466 TP_STRUCT__entry(
349467 __field(const void *, r_xprt)
350
- __field(int, status)
351
- __field(int, connected)
468
+ __field(unsigned long, connect)
469
+ __field(unsigned long, reconnect)
352470 __string(addr, rpcrdma_addrstr(r_xprt))
353471 __string(port, rpcrdma_portstr(r_xprt))
354472 ),
355473
356474 TP_fast_assign(
357475 __entry->r_xprt = r_xprt;
358
- __entry->status = status;
359
- __entry->connected = r_xprt->rx_ep.rep_connected;
476
+ __entry->connect = connect;
477
+ __entry->reconnect = reconnect;
360478 __assign_str(addr, rpcrdma_addrstr(r_xprt));
361479 __assign_str(port, rpcrdma_portstr(r_xprt));
362480 ),
363481
364
- TP_printk("peer=[%s]:%s r_xprt=%p: status=%d %sconnected",
365
- __get_str(addr), __get_str(port),
366
- __entry->r_xprt, __entry->status,
367
- __entry->connected == 1 ? "still " : "dis"
482
+ TP_printk("peer=[%s]:%s r_xprt=%p: connect=%lu reconnect=%lu",
483
+ __get_str(addr), __get_str(port), __entry->r_xprt,
484
+ __entry->connect / HZ, __entry->reconnect / HZ
368485 )
369486 );
370487
371
-DEFINE_RXPRT_EVENT(xprtrdma_conn_start);
372
-DEFINE_RXPRT_EVENT(xprtrdma_conn_tout);
373
-DEFINE_RXPRT_EVENT(xprtrdma_create);
374
-DEFINE_RXPRT_EVENT(xprtrdma_destroy);
375
-DEFINE_RXPRT_EVENT(xprtrdma_remove);
376
-DEFINE_RXPRT_EVENT(xprtrdma_reinsert);
377
-DEFINE_RXPRT_EVENT(xprtrdma_reconnect);
378
-DEFINE_RXPRT_EVENT(xprtrdma_inject_dsc);
379
-
380
-TRACE_EVENT(xprtrdma_qp_error,
488
+TRACE_EVENT(xprtrdma_qp_event,
381489 TP_PROTO(
382
- const struct rpcrdma_xprt *r_xprt,
490
+ const struct rpcrdma_ep *ep,
383491 const struct ib_event *event
384492 ),
385493
386
- TP_ARGS(r_xprt, event),
494
+ TP_ARGS(ep, event),
387495
388496 TP_STRUCT__entry(
389
- __field(const void *, r_xprt)
390
- __field(unsigned int, event)
497
+ __field(unsigned long, event)
391498 __string(name, event->device->name)
392
- __string(addr, rpcrdma_addrstr(r_xprt))
393
- __string(port, rpcrdma_portstr(r_xprt))
499
+ __array(unsigned char, srcaddr, sizeof(struct sockaddr_in6))
500
+ __array(unsigned char, dstaddr, sizeof(struct sockaddr_in6))
394501 ),
395502
396503 TP_fast_assign(
397
- __entry->r_xprt = r_xprt;
504
+ const struct rdma_cm_id *id = ep->re_id;
505
+
398506 __entry->event = event->event;
399507 __assign_str(name, event->device->name);
400
- __assign_str(addr, rpcrdma_addrstr(r_xprt));
401
- __assign_str(port, rpcrdma_portstr(r_xprt));
508
+ memcpy(__entry->srcaddr, &id->route.addr.src_addr,
509
+ sizeof(struct sockaddr_in6));
510
+ memcpy(__entry->dstaddr, &id->route.addr.dst_addr,
511
+ sizeof(struct sockaddr_in6));
402512 ),
403513
404
- TP_printk("peer=[%s]:%s r_xprt=%p: dev %s: %s (%u)",
405
- __get_str(addr), __get_str(port), __entry->r_xprt,
406
- __get_str(name), rdma_show_ib_event(__entry->event),
407
- __entry->event
514
+ TP_printk("%pISpc -> %pISpc device=%s %s (%lu)",
515
+ __entry->srcaddr, __entry->dstaddr, __get_str(name),
516
+ rdma_show_ib_event(__entry->event), __entry->event
408517 )
409518 );
410519
....@@ -422,26 +531,89 @@
422531
423532 TP_STRUCT__entry(
424533 __field(const void *, r_xprt)
534
+ __string(addr, rpcrdma_addrstr(r_xprt))
535
+ __string(port, rpcrdma_portstr(r_xprt))
425536 __field(unsigned int, count)
426537 ),
427538
428539 TP_fast_assign(
429540 __entry->r_xprt = r_xprt;
430541 __entry->count = count;
542
+ __assign_str(addr, rpcrdma_addrstr(r_xprt));
543
+ __assign_str(port, rpcrdma_portstr(r_xprt));
431544 ),
432545
433
- TP_printk("r_xprt=%p: created %u MRs",
434
- __entry->r_xprt, __entry->count
546
+ TP_printk("peer=[%s]:%s r_xprt=%p: created %u MRs",
547
+ __get_str(addr), __get_str(port), __entry->r_xprt,
548
+ __entry->count
435549 )
436550 );
437551
438
-DEFINE_RXPRT_EVENT(xprtrdma_nomrs);
552
+TRACE_EVENT(xprtrdma_mr_get,
553
+ TP_PROTO(
554
+ const struct rpcrdma_req *req
555
+ ),
439556
440
-DEFINE_RDCH_EVENT(xprtrdma_read_chunk);
441
-DEFINE_WRCH_EVENT(xprtrdma_write_chunk);
442
-DEFINE_WRCH_EVENT(xprtrdma_reply_chunk);
557
+ TP_ARGS(req),
558
+
559
+ TP_STRUCT__entry(
560
+ __field(const void *, req)
561
+ __field(unsigned int, task_id)
562
+ __field(unsigned int, client_id)
563
+ __field(u32, xid)
564
+ ),
565
+
566
+ TP_fast_assign(
567
+ const struct rpc_rqst *rqst = &req->rl_slot;
568
+
569
+ __entry->req = req;
570
+ __entry->task_id = rqst->rq_task->tk_pid;
571
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
572
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
573
+ ),
574
+
575
+ TP_printk("task:%u@%u xid=0x%08x req=%p",
576
+ __entry->task_id, __entry->client_id, __entry->xid,
577
+ __entry->req
578
+ )
579
+);
580
+
581
+TRACE_EVENT(xprtrdma_nomrs,
582
+ TP_PROTO(
583
+ const struct rpcrdma_req *req
584
+ ),
585
+
586
+ TP_ARGS(req),
587
+
588
+ TP_STRUCT__entry(
589
+ __field(const void *, req)
590
+ __field(unsigned int, task_id)
591
+ __field(unsigned int, client_id)
592
+ __field(u32, xid)
593
+ ),
594
+
595
+ TP_fast_assign(
596
+ const struct rpc_rqst *rqst = &req->rl_slot;
597
+
598
+ __entry->req = req;
599
+ __entry->task_id = rqst->rq_task->tk_pid;
600
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
601
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
602
+ ),
603
+
604
+ TP_printk("task:%u@%u xid=0x%08x req=%p",
605
+ __entry->task_id, __entry->client_id, __entry->xid,
606
+ __entry->req
607
+ )
608
+);
609
+
610
+DEFINE_RDCH_EVENT(read);
611
+DEFINE_WRCH_EVENT(write);
612
+DEFINE_WRCH_EVENT(reply);
443613
444614 TRACE_DEFINE_ENUM(rpcrdma_noch);
615
+TRACE_DEFINE_ENUM(rpcrdma_noch_pullup);
616
+TRACE_DEFINE_ENUM(rpcrdma_noch_mapped);
445617 TRACE_DEFINE_ENUM(rpcrdma_readch);
446618 TRACE_DEFINE_ENUM(rpcrdma_areadch);
447619 TRACE_DEFINE_ENUM(rpcrdma_writech);
....@@ -450,6 +622,8 @@
450622 #define xprtrdma_show_chunktype(x) \
451623 __print_symbolic(x, \
452624 { rpcrdma_noch, "inline" }, \
625
+ { rpcrdma_noch_pullup, "pullup" }, \
626
+ { rpcrdma_noch_mapped, "mapped" }, \
453627 { rpcrdma_readch, "read list" }, \
454628 { rpcrdma_areadch, "*read list" }, \
455629 { rpcrdma_writech, "write list" }, \
....@@ -457,13 +631,12 @@
457631
458632 TRACE_EVENT(xprtrdma_marshal,
459633 TP_PROTO(
460
- const struct rpc_rqst *rqst,
461
- unsigned int hdrlen,
634
+ const struct rpcrdma_req *req,
462635 unsigned int rtype,
463636 unsigned int wtype
464637 ),
465638
466
- TP_ARGS(rqst, hdrlen, rtype, wtype),
639
+ TP_ARGS(req, rtype, wtype),
467640
468641 TP_STRUCT__entry(
469642 __field(unsigned int, task_id)
....@@ -478,10 +651,12 @@
478651 ),
479652
480653 TP_fast_assign(
654
+ const struct rpc_rqst *rqst = &req->rl_slot;
655
+
481656 __entry->task_id = rqst->rq_task->tk_pid;
482657 __entry->client_id = rqst->rq_task->tk_client->cl_clid;
483658 __entry->xid = be32_to_cpu(rqst->rq_xid);
484
- __entry->hdrlen = hdrlen;
659
+ __entry->hdrlen = req->rl_hdrbuf.len;
485660 __entry->headlen = rqst->rq_snd_buf.head[0].iov_len;
486661 __entry->pagelen = rqst->rq_snd_buf.page_len;
487662 __entry->taillen = rqst->rq_snd_buf.tail[0].iov_len;
....@@ -498,53 +673,113 @@
498673 )
499674 );
500675
501
-TRACE_EVENT(xprtrdma_post_send,
502
- TP_PROTO(
503
- const struct rpcrdma_req *req,
504
- int status
676
+TRACE_EVENT(xprtrdma_marshal_failed,
677
+ TP_PROTO(const struct rpc_rqst *rqst,
678
+ int ret
505679 ),
506680
507
- TP_ARGS(req, status),
681
+ TP_ARGS(rqst, ret),
508682
509683 TP_STRUCT__entry(
510
- __field(const void *, req)
511
- __field(int, num_sge)
512
- __field(bool, signaled)
513
- __field(int, status)
684
+ __field(unsigned int, task_id)
685
+ __field(unsigned int, client_id)
686
+ __field(u32, xid)
687
+ __field(int, ret)
514688 ),
515689
516690 TP_fast_assign(
517
- __entry->req = req;
518
- __entry->num_sge = req->rl_sendctx->sc_wr.num_sge;
519
- __entry->signaled = req->rl_sendctx->sc_wr.send_flags &
520
- IB_SEND_SIGNALED;
521
- __entry->status = status;
691
+ __entry->task_id = rqst->rq_task->tk_pid;
692
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
693
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
694
+ __entry->ret = ret;
522695 ),
523696
524
- TP_printk("req=%p, %d SGEs%s, status=%d",
525
- __entry->req, __entry->num_sge,
526
- (__entry->signaled ? ", signaled" : ""),
527
- __entry->status
697
+ TP_printk("task:%u@%u xid=0x%08x: ret=%d",
698
+ __entry->task_id, __entry->client_id, __entry->xid,
699
+ __entry->ret
700
+ )
701
+);
702
+
703
+TRACE_EVENT(xprtrdma_prepsend_failed,
704
+ TP_PROTO(const struct rpc_rqst *rqst,
705
+ int ret
706
+ ),
707
+
708
+ TP_ARGS(rqst, ret),
709
+
710
+ TP_STRUCT__entry(
711
+ __field(unsigned int, task_id)
712
+ __field(unsigned int, client_id)
713
+ __field(u32, xid)
714
+ __field(int, ret)
715
+ ),
716
+
717
+ TP_fast_assign(
718
+ __entry->task_id = rqst->rq_task->tk_pid;
719
+ __entry->client_id = rqst->rq_task->tk_client->cl_clid;
720
+ __entry->xid = be32_to_cpu(rqst->rq_xid);
721
+ __entry->ret = ret;
722
+ ),
723
+
724
+ TP_printk("task:%u@%u xid=0x%08x: ret=%d",
725
+ __entry->task_id, __entry->client_id, __entry->xid,
726
+ __entry->ret
727
+ )
728
+);
729
+
730
+TRACE_EVENT(xprtrdma_post_send,
731
+ TP_PROTO(
732
+ const struct rpcrdma_req *req
733
+ ),
734
+
735
+ TP_ARGS(req),
736
+
737
+ TP_STRUCT__entry(
738
+ __field(const void *, req)
739
+ __field(const void *, sc)
740
+ __field(unsigned int, task_id)
741
+ __field(unsigned int, client_id)
742
+ __field(int, num_sge)
743
+ __field(int, signaled)
744
+ ),
745
+
746
+ TP_fast_assign(
747
+ const struct rpc_rqst *rqst = &req->rl_slot;
748
+
749
+ __entry->task_id = rqst->rq_task->tk_pid;
750
+ __entry->client_id = rqst->rq_task->tk_client ?
751
+ rqst->rq_task->tk_client->cl_clid : -1;
752
+ __entry->req = req;
753
+ __entry->sc = req->rl_sendctx;
754
+ __entry->num_sge = req->rl_wr.num_sge;
755
+ __entry->signaled = req->rl_wr.send_flags & IB_SEND_SIGNALED;
756
+ ),
757
+
758
+ TP_printk("task:%u@%u req=%p sc=%p (%d SGE%s) %s",
759
+ __entry->task_id, __entry->client_id,
760
+ __entry->req, __entry->sc, __entry->num_sge,
761
+ (__entry->num_sge == 1 ? "" : "s"),
762
+ (__entry->signaled ? "signaled" : "")
528763 )
529764 );
530765
531766 TRACE_EVENT(xprtrdma_post_recv,
532767 TP_PROTO(
533
- const struct ib_cqe *cqe
768
+ const struct rpcrdma_rep *rep
534769 ),
535770
536
- TP_ARGS(cqe),
771
+ TP_ARGS(rep),
537772
538773 TP_STRUCT__entry(
539
- __field(const void *, cqe)
774
+ __field(const void *, rep)
540775 ),
541776
542777 TP_fast_assign(
543
- __entry->cqe = cqe;
778
+ __entry->rep = rep;
544779 ),
545780
546
- TP_printk("cqe=%p",
547
- __entry->cqe
781
+ TP_printk("rep=%p",
782
+ __entry->rep
548783 )
549784 );
550785
....@@ -570,7 +805,7 @@
570805 __entry->r_xprt = r_xprt;
571806 __entry->count = count;
572807 __entry->status = status;
573
- __entry->posted = r_xprt->rx_buf.rb_posted_receives;
808
+ __entry->posted = r_xprt->rx_ep->re_receive_count;
574809 __assign_str(addr, rpcrdma_addrstr(r_xprt));
575810 __assign_str(port, rpcrdma_portstr(r_xprt));
576811 ),
....@@ -578,6 +813,31 @@
578813 TP_printk("peer=[%s]:%s r_xprt=%p: %u new recvs, %d active (rc %d)",
579814 __get_str(addr), __get_str(port), __entry->r_xprt,
580815 __entry->count, __entry->posted, __entry->status
816
+ )
817
+);
818
+
819
+TRACE_EVENT(xprtrdma_post_linv,
820
+ TP_PROTO(
821
+ const struct rpcrdma_req *req,
822
+ int status
823
+ ),
824
+
825
+ TP_ARGS(req, status),
826
+
827
+ TP_STRUCT__entry(
828
+ __field(const void *, req)
829
+ __field(int, status)
830
+ __field(u32, xid)
831
+ ),
832
+
833
+ TP_fast_assign(
834
+ __entry->req = req;
835
+ __entry->status = status;
836
+ __entry->xid = be32_to_cpu(req->rl_slot.rq_xid);
837
+ ),
838
+
839
+ TP_printk("req=%p xid=0x%08x status=%d",
840
+ __entry->req, __entry->xid, __entry->status
581841 )
582842 );
583843
....@@ -595,6 +855,7 @@
595855
596856 TP_STRUCT__entry(
597857 __field(const void *, req)
858
+ __field(const void *, sc)
598859 __field(unsigned int, unmap_count)
599860 __field(unsigned int, status)
600861 __field(unsigned int, vendor_err)
....@@ -602,13 +863,14 @@
602863
603864 TP_fast_assign(
604865 __entry->req = sc->sc_req;
866
+ __entry->sc = sc;
605867 __entry->unmap_count = sc->sc_unmap_count;
606868 __entry->status = wc->status;
607869 __entry->vendor_err = __entry->status ? wc->vendor_err : 0;
608870 ),
609871
610
- TP_printk("req=%p, unmapped %u pages: %s (%u/0x%x)",
611
- __entry->req, __entry->unmap_count,
872
+ TP_printk("req=%p sc=%p unmapped=%u: %s (%u/0x%x)",
873
+ __entry->req, __entry->sc, __entry->unmap_count,
612874 rdma_show_wc_status(__entry->status),
613875 __entry->status, __entry->vendor_err
614876 )
....@@ -622,14 +884,15 @@
622884 TP_ARGS(wc),
623885
624886 TP_STRUCT__entry(
625
- __field(const void *, cqe)
887
+ __field(const void *, rep)
626888 __field(u32, byte_len)
627889 __field(unsigned int, status)
628890 __field(u32, vendor_err)
629891 ),
630892
631893 TP_fast_assign(
632
- __entry->cqe = wc->wr_cqe;
894
+ __entry->rep = container_of(wc->wr_cqe, struct rpcrdma_rep,
895
+ rr_cqe);
633896 __entry->status = wc->status;
634897 if (wc->status) {
635898 __entry->byte_len = 0;
....@@ -640,8 +903,8 @@
640903 }
641904 ),
642905
643
- TP_printk("cqe=%p %u bytes: %s (%u/0x%x)",
644
- __entry->cqe, __entry->byte_len,
906
+ TP_printk("rep=%p %u bytes: %s (%u/0x%x)",
907
+ __entry->rep, __entry->byte_len,
645908 rdma_show_wc_status(__entry->status),
646909 __entry->status, __entry->vendor_err
647910 )
....@@ -650,12 +913,150 @@
650913 DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_fastreg);
651914 DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li);
652915 DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li_wake);
916
+DEFINE_FRWR_DONE_EVENT(xprtrdma_wc_li_done);
653917
654
-DEFINE_MR_EVENT(xprtrdma_localinv);
655
-DEFINE_MR_EVENT(xprtrdma_dma_map);
656
-DEFINE_MR_EVENT(xprtrdma_dma_unmap);
657
-DEFINE_MR_EVENT(xprtrdma_remoteinv);
658
-DEFINE_MR_EVENT(xprtrdma_recover_mr);
918
+TRACE_EVENT(xprtrdma_frwr_alloc,
919
+ TP_PROTO(
920
+ const struct rpcrdma_mr *mr,
921
+ int rc
922
+ ),
923
+
924
+ TP_ARGS(mr, rc),
925
+
926
+ TP_STRUCT__entry(
927
+ __field(u32, mr_id)
928
+ __field(int, rc)
929
+ ),
930
+
931
+ TP_fast_assign(
932
+ __entry->mr_id = mr->frwr.fr_mr->res.id;
933
+ __entry->rc = rc;
934
+ ),
935
+
936
+ TP_printk("mr.id=%u: rc=%d",
937
+ __entry->mr_id, __entry->rc
938
+ )
939
+);
940
+
941
+TRACE_EVENT(xprtrdma_frwr_dereg,
942
+ TP_PROTO(
943
+ const struct rpcrdma_mr *mr,
944
+ int rc
945
+ ),
946
+
947
+ TP_ARGS(mr, rc),
948
+
949
+ TP_STRUCT__entry(
950
+ __field(u32, mr_id)
951
+ __field(int, nents)
952
+ __field(u32, handle)
953
+ __field(u32, length)
954
+ __field(u64, offset)
955
+ __field(u32, dir)
956
+ __field(int, rc)
957
+ ),
958
+
959
+ TP_fast_assign(
960
+ __entry->mr_id = mr->frwr.fr_mr->res.id;
961
+ __entry->nents = mr->mr_nents;
962
+ __entry->handle = mr->mr_handle;
963
+ __entry->length = mr->mr_length;
964
+ __entry->offset = mr->mr_offset;
965
+ __entry->dir = mr->mr_dir;
966
+ __entry->rc = rc;
967
+ ),
968
+
969
+ TP_printk("mr.id=%u nents=%d %u@0x%016llx:0x%08x (%s): rc=%d",
970
+ __entry->mr_id, __entry->nents, __entry->length,
971
+ (unsigned long long)__entry->offset, __entry->handle,
972
+ xprtrdma_show_direction(__entry->dir),
973
+ __entry->rc
974
+ )
975
+);
976
+
977
+TRACE_EVENT(xprtrdma_frwr_sgerr,
978
+ TP_PROTO(
979
+ const struct rpcrdma_mr *mr,
980
+ int sg_nents
981
+ ),
982
+
983
+ TP_ARGS(mr, sg_nents),
984
+
985
+ TP_STRUCT__entry(
986
+ __field(u32, mr_id)
987
+ __field(u64, addr)
988
+ __field(u32, dir)
989
+ __field(int, nents)
990
+ ),
991
+
992
+ TP_fast_assign(
993
+ __entry->mr_id = mr->frwr.fr_mr->res.id;
994
+ __entry->addr = mr->mr_sg->dma_address;
995
+ __entry->dir = mr->mr_dir;
996
+ __entry->nents = sg_nents;
997
+ ),
998
+
999
+ TP_printk("mr.id=%u DMA addr=0x%llx (%s) sg_nents=%d",
1000
+ __entry->mr_id, __entry->addr,
1001
+ xprtrdma_show_direction(__entry->dir),
1002
+ __entry->nents
1003
+ )
1004
+);
1005
+
1006
+TRACE_EVENT(xprtrdma_frwr_maperr,
1007
+ TP_PROTO(
1008
+ const struct rpcrdma_mr *mr,
1009
+ int num_mapped
1010
+ ),
1011
+
1012
+ TP_ARGS(mr, num_mapped),
1013
+
1014
+ TP_STRUCT__entry(
1015
+ __field(u32, mr_id)
1016
+ __field(u64, addr)
1017
+ __field(u32, dir)
1018
+ __field(int, num_mapped)
1019
+ __field(int, nents)
1020
+ ),
1021
+
1022
+ TP_fast_assign(
1023
+ __entry->mr_id = mr->frwr.fr_mr->res.id;
1024
+ __entry->addr = mr->mr_sg->dma_address;
1025
+ __entry->dir = mr->mr_dir;
1026
+ __entry->num_mapped = num_mapped;
1027
+ __entry->nents = mr->mr_nents;
1028
+ ),
1029
+
1030
+ TP_printk("mr.id=%u DMA addr=0x%llx (%s) nents=%d of %d",
1031
+ __entry->mr_id, __entry->addr,
1032
+ xprtrdma_show_direction(__entry->dir),
1033
+ __entry->num_mapped, __entry->nents
1034
+ )
1035
+);
1036
+
1037
+DEFINE_MR_EVENT(localinv);
1038
+DEFINE_MR_EVENT(map);
1039
+DEFINE_MR_EVENT(unmap);
1040
+DEFINE_MR_EVENT(reminv);
1041
+DEFINE_MR_EVENT(recycle);
1042
+
1043
+TRACE_EVENT(xprtrdma_dma_maperr,
1044
+ TP_PROTO(
1045
+ u64 addr
1046
+ ),
1047
+
1048
+ TP_ARGS(addr),
1049
+
1050
+ TP_STRUCT__entry(
1051
+ __field(u64, addr)
1052
+ ),
1053
+
1054
+ TP_fast_assign(
1055
+ __entry->addr = addr;
1056
+ ),
1057
+
1058
+ TP_printk("dma addr=0x%llx\n", __entry->addr)
1059
+);
6591060
6601061 /**
6611062 ** Reply events
....@@ -730,66 +1131,32 @@
7301131 TRACE_EVENT(xprtrdma_fixup,
7311132 TP_PROTO(
7321133 const struct rpc_rqst *rqst,
733
- int len,
734
- int hdrlen
1134
+ unsigned long fixup
7351135 ),
7361136
737
- TP_ARGS(rqst, len, hdrlen),
1137
+ TP_ARGS(rqst, fixup),
7381138
7391139 TP_STRUCT__entry(
7401140 __field(unsigned int, task_id)
7411141 __field(unsigned int, client_id)
742
- __field(const void *, base)
743
- __field(int, len)
744
- __field(int, hdrlen)
1142
+ __field(unsigned long, fixup)
1143
+ __field(size_t, headlen)
1144
+ __field(unsigned int, pagelen)
1145
+ __field(size_t, taillen)
7451146 ),
7461147
7471148 TP_fast_assign(
7481149 __entry->task_id = rqst->rq_task->tk_pid;
7491150 __entry->client_id = rqst->rq_task->tk_client->cl_clid;
750
- __entry->base = rqst->rq_rcv_buf.head[0].iov_base;
751
- __entry->len = len;
752
- __entry->hdrlen = hdrlen;
1151
+ __entry->fixup = fixup;
1152
+ __entry->headlen = rqst->rq_rcv_buf.head[0].iov_len;
1153
+ __entry->pagelen = rqst->rq_rcv_buf.page_len;
1154
+ __entry->taillen = rqst->rq_rcv_buf.tail[0].iov_len;
7531155 ),
7541156
755
- TP_printk("task:%u@%u base=%p len=%d hdrlen=%d",
756
- __entry->task_id, __entry->client_id,
757
- __entry->base, __entry->len, __entry->hdrlen
758
- )
759
-);
760
-
761
-TRACE_EVENT(xprtrdma_fixup_pg,
762
- TP_PROTO(
763
- const struct rpc_rqst *rqst,
764
- int pageno,
765
- const void *pos,
766
- int len,
767
- int curlen
768
- ),
769
-
770
- TP_ARGS(rqst, pageno, pos, len, curlen),
771
-
772
- TP_STRUCT__entry(
773
- __field(unsigned int, task_id)
774
- __field(unsigned int, client_id)
775
- __field(const void *, pos)
776
- __field(int, pageno)
777
- __field(int, len)
778
- __field(int, curlen)
779
- ),
780
-
781
- TP_fast_assign(
782
- __entry->task_id = rqst->rq_task->tk_pid;
783
- __entry->client_id = rqst->rq_task->tk_client->cl_clid;
784
- __entry->pos = pos;
785
- __entry->pageno = pageno;
786
- __entry->len = len;
787
- __entry->curlen = curlen;
788
- ),
789
-
790
- TP_printk("task:%u@%u pageno=%d pos=%p len=%d curlen=%d",
791
- __entry->task_id, __entry->client_id,
792
- __entry->pageno, __entry->pos, __entry->len, __entry->curlen
1157
+ TP_printk("task:%u@%u fixup=%lu xdr=%zu/%u/%zu",
1158
+ __entry->task_id, __entry->client_id, __entry->fixup,
1159
+ __entry->headlen, __entry->pagelen, __entry->taillen
7931160 )
7941161 );
7951162
....@@ -817,68 +1184,6 @@
8171184 TP_printk("%u@0x%016llx:0x%08x",
8181185 __entry->length, (unsigned long long)__entry->offset,
8191186 __entry->handle
820
- )
821
-);
822
-
823
-/**
824
- ** Allocation/release of rpcrdma_reqs and rpcrdma_reps
825
- **/
826
-
827
-TRACE_EVENT(xprtrdma_allocate,
828
- TP_PROTO(
829
- const struct rpc_task *task,
830
- const struct rpcrdma_req *req
831
- ),
832
-
833
- TP_ARGS(task, req),
834
-
835
- TP_STRUCT__entry(
836
- __field(unsigned int, task_id)
837
- __field(unsigned int, client_id)
838
- __field(const void *, req)
839
- __field(size_t, callsize)
840
- __field(size_t, rcvsize)
841
- ),
842
-
843
- TP_fast_assign(
844
- __entry->task_id = task->tk_pid;
845
- __entry->client_id = task->tk_client->cl_clid;
846
- __entry->req = req;
847
- __entry->callsize = task->tk_rqstp->rq_callsize;
848
- __entry->rcvsize = task->tk_rqstp->rq_rcvsize;
849
- ),
850
-
851
- TP_printk("task:%u@%u req=%p (%zu, %zu)",
852
- __entry->task_id, __entry->client_id,
853
- __entry->req, __entry->callsize, __entry->rcvsize
854
- )
855
-);
856
-
857
-TRACE_EVENT(xprtrdma_rpc_done,
858
- TP_PROTO(
859
- const struct rpc_task *task,
860
- const struct rpcrdma_req *req
861
- ),
862
-
863
- TP_ARGS(task, req),
864
-
865
- TP_STRUCT__entry(
866
- __field(unsigned int, task_id)
867
- __field(unsigned int, client_id)
868
- __field(const void *, req)
869
- __field(const void *, rep)
870
- ),
871
-
872
- TP_fast_assign(
873
- __entry->task_id = task->tk_pid;
874
- __entry->client_id = task->tk_client->cl_clid;
875
- __entry->req = req;
876
- __entry->rep = req->rl_reply;
877
- ),
878
-
879
- TP_printk("task:%u@%u req=%p rep=%p",
880
- __entry->task_id, __entry->client_id,
881
- __entry->req, __entry->rep
8821187 )
8831188 );
8841189
....@@ -949,38 +1254,42 @@
9491254 ** Server-side RPC/RDMA events
9501255 **/
9511256
952
-DECLARE_EVENT_CLASS(svcrdma_xprt_event,
1257
+DECLARE_EVENT_CLASS(svcrdma_accept_class,
9531258 TP_PROTO(
954
- const struct svc_xprt *xprt
1259
+ const struct svcxprt_rdma *rdma,
1260
+ long status
9551261 ),
9561262
957
- TP_ARGS(xprt),
1263
+ TP_ARGS(rdma, status),
9581264
9591265 TP_STRUCT__entry(
960
- __field(const void *, xprt)
961
- __string(addr, xprt->xpt_remotebuf)
1266
+ __field(long, status)
1267
+ __string(addr, rdma->sc_xprt.xpt_remotebuf)
9621268 ),
9631269
9641270 TP_fast_assign(
965
- __entry->xprt = xprt;
966
- __assign_str(addr, xprt->xpt_remotebuf);
1271
+ __entry->status = status;
1272
+ __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
9671273 ),
9681274
969
- TP_printk("xprt=%p addr=%s",
970
- __entry->xprt, __get_str(addr)
1275
+ TP_printk("addr=%s status=%ld",
1276
+ __get_str(addr), __entry->status
9711277 )
9721278 );
9731279
974
-#define DEFINE_XPRT_EVENT(name) \
975
- DEFINE_EVENT(svcrdma_xprt_event, svcrdma_xprt_##name, \
976
- TP_PROTO( \
977
- const struct svc_xprt *xprt \
978
- ), \
979
- TP_ARGS(xprt))
1280
+#define DEFINE_ACCEPT_EVENT(name) \
1281
+ DEFINE_EVENT(svcrdma_accept_class, svcrdma_##name##_err, \
1282
+ TP_PROTO( \
1283
+ const struct svcxprt_rdma *rdma, \
1284
+ long status \
1285
+ ), \
1286
+ TP_ARGS(rdma, status))
9801287
981
-DEFINE_XPRT_EVENT(accept);
982
-DEFINE_XPRT_EVENT(fail);
983
-DEFINE_XPRT_EVENT(free);
1288
+DEFINE_ACCEPT_EVENT(pd);
1289
+DEFINE_ACCEPT_EVENT(qp);
1290
+DEFINE_ACCEPT_EVENT(fabric);
1291
+DEFINE_ACCEPT_EVENT(initdepth);
1292
+DEFINE_ACCEPT_EVENT(accept);
9841293
9851294 TRACE_DEFINE_ENUM(RDMA_MSG);
9861295 TRACE_DEFINE_ENUM(RDMA_NOMSG);
....@@ -998,13 +1307,16 @@
9981307
9991308 TRACE_EVENT(svcrdma_decode_rqst,
10001309 TP_PROTO(
1310
+ const struct svc_rdma_recv_ctxt *ctxt,
10011311 __be32 *p,
10021312 unsigned int hdrlen
10031313 ),
10041314
1005
- TP_ARGS(p, hdrlen),
1315
+ TP_ARGS(ctxt, p, hdrlen),
10061316
10071317 TP_STRUCT__entry(
1318
+ __field(u32, cq_id)
1319
+ __field(int, completion_id)
10081320 __field(u32, xid)
10091321 __field(u32, vers)
10101322 __field(u32, proc)
....@@ -1013,6 +1325,8 @@
10131325 ),
10141326
10151327 TP_fast_assign(
1328
+ __entry->cq_id = ctxt->rc_cid.ci_queue_id;
1329
+ __entry->completion_id = ctxt->rc_cid.ci_completion_id;
10161330 __entry->xid = be32_to_cpup(p++);
10171331 __entry->vers = be32_to_cpup(p++);
10181332 __entry->credits = be32_to_cpup(p++);
....@@ -1020,37 +1334,48 @@
10201334 __entry->hdrlen = hdrlen;
10211335 ),
10221336
1023
- TP_printk("xid=0x%08x vers=%u credits=%u proc=%s hdrlen=%u",
1337
+ TP_printk("cq.id=%u cid=%d xid=0x%08x vers=%u credits=%u proc=%s hdrlen=%u",
1338
+ __entry->cq_id, __entry->completion_id,
10241339 __entry->xid, __entry->vers, __entry->credits,
10251340 show_rpcrdma_proc(__entry->proc), __entry->hdrlen)
10261341 );
10271342
1028
-TRACE_EVENT(svcrdma_decode_short,
1343
+TRACE_EVENT(svcrdma_decode_short_err,
10291344 TP_PROTO(
1345
+ const struct svc_rdma_recv_ctxt *ctxt,
10301346 unsigned int hdrlen
10311347 ),
10321348
1033
- TP_ARGS(hdrlen),
1349
+ TP_ARGS(ctxt, hdrlen),
10341350
10351351 TP_STRUCT__entry(
1352
+ __field(u32, cq_id)
1353
+ __field(int, completion_id)
10361354 __field(unsigned int, hdrlen)
10371355 ),
10381356
10391357 TP_fast_assign(
1358
+ __entry->cq_id = ctxt->rc_cid.ci_queue_id;
1359
+ __entry->completion_id = ctxt->rc_cid.ci_completion_id;
10401360 __entry->hdrlen = hdrlen;
10411361 ),
10421362
1043
- TP_printk("hdrlen=%u", __entry->hdrlen)
1363
+ TP_printk("cq.id=%u cid=%d hdrlen=%u",
1364
+ __entry->cq_id, __entry->completion_id,
1365
+ __entry->hdrlen)
10441366 );
10451367
10461368 DECLARE_EVENT_CLASS(svcrdma_badreq_event,
10471369 TP_PROTO(
1370
+ const struct svc_rdma_recv_ctxt *ctxt,
10481371 __be32 *p
10491372 ),
10501373
1051
- TP_ARGS(p),
1374
+ TP_ARGS(ctxt, p),
10521375
10531376 TP_STRUCT__entry(
1377
+ __field(u32, cq_id)
1378
+ __field(int, completion_id)
10541379 __field(u32, xid)
10551380 __field(u32, vers)
10561381 __field(u32, proc)
....@@ -1058,22 +1383,27 @@
10581383 ),
10591384
10601385 TP_fast_assign(
1386
+ __entry->cq_id = ctxt->rc_cid.ci_queue_id;
1387
+ __entry->completion_id = ctxt->rc_cid.ci_completion_id;
10611388 __entry->xid = be32_to_cpup(p++);
10621389 __entry->vers = be32_to_cpup(p++);
10631390 __entry->credits = be32_to_cpup(p++);
10641391 __entry->proc = be32_to_cpup(p);
10651392 ),
10661393
1067
- TP_printk("xid=0x%08x vers=%u credits=%u proc=%u",
1394
+ TP_printk("cq.id=%u cid=%d xid=0x%08x vers=%u credits=%u proc=%u",
1395
+ __entry->cq_id, __entry->completion_id,
10681396 __entry->xid, __entry->vers, __entry->credits, __entry->proc)
10691397 );
10701398
10711399 #define DEFINE_BADREQ_EVENT(name) \
1072
- DEFINE_EVENT(svcrdma_badreq_event, svcrdma_decode_##name,\
1400
+ DEFINE_EVENT(svcrdma_badreq_event, \
1401
+ svcrdma_decode_##name##_err, \
10731402 TP_PROTO( \
1403
+ const struct svc_rdma_recv_ctxt *ctxt, \
10741404 __be32 *p \
10751405 ), \
1076
- TP_ARGS(p))
1406
+ TP_ARGS(ctxt, p))
10771407
10781408 DEFINE_BADREQ_EVENT(badvers);
10791409 DEFINE_BADREQ_EVENT(drop);
....@@ -1108,7 +1438,7 @@
11081438 );
11091439
11101440 #define DEFINE_SEGMENT_EVENT(name) \
1111
- DEFINE_EVENT(svcrdma_segment_event, svcrdma_encode_##name,\
1441
+ DEFINE_EVENT(svcrdma_segment_event, svcrdma_##name,\
11121442 TP_PROTO( \
11131443 u32 handle, \
11141444 u32 length, \
....@@ -1116,8 +1446,11 @@
11161446 ), \
11171447 TP_ARGS(handle, length, offset))
11181448
1119
-DEFINE_SEGMENT_EVENT(rseg);
1120
-DEFINE_SEGMENT_EVENT(wseg);
1449
+DEFINE_SEGMENT_EVENT(decode_wseg);
1450
+DEFINE_SEGMENT_EVENT(encode_rseg);
1451
+DEFINE_SEGMENT_EVENT(send_rseg);
1452
+DEFINE_SEGMENT_EVENT(encode_wseg);
1453
+DEFINE_SEGMENT_EVENT(send_wseg);
11211454
11221455 DECLARE_EVENT_CLASS(svcrdma_chunk_event,
11231456 TP_PROTO(
....@@ -1140,17 +1473,19 @@
11401473 );
11411474
11421475 #define DEFINE_CHUNK_EVENT(name) \
1143
- DEFINE_EVENT(svcrdma_chunk_event, svcrdma_encode_##name,\
1476
+ DEFINE_EVENT(svcrdma_chunk_event, svcrdma_##name, \
11441477 TP_PROTO( \
11451478 u32 length \
11461479 ), \
11471480 TP_ARGS(length))
11481481
1149
-DEFINE_CHUNK_EVENT(pzr);
1150
-DEFINE_CHUNK_EVENT(write);
1151
-DEFINE_CHUNK_EVENT(reply);
1482
+DEFINE_CHUNK_EVENT(send_pzr);
1483
+DEFINE_CHUNK_EVENT(encode_write_chunk);
1484
+DEFINE_CHUNK_EVENT(send_write_chunk);
1485
+DEFINE_CHUNK_EVENT(encode_read_chunk);
1486
+DEFINE_CHUNK_EVENT(send_reply_chunk);
11521487
1153
-TRACE_EVENT(svcrdma_encode_read,
1488
+TRACE_EVENT(svcrdma_send_read_chunk,
11541489 TP_PROTO(
11551490 u32 length,
11561491 u32 position
....@@ -1207,57 +1542,180 @@
12071542 ** Server-side RDMA API events
12081543 **/
12091544
1210
-TRACE_EVENT(svcrdma_dma_map_page,
1545
+DECLARE_EVENT_CLASS(svcrdma_dma_map_class,
12111546 TP_PROTO(
12121547 const struct svcxprt_rdma *rdma,
1213
- const void *page
1548
+ u64 dma_addr,
1549
+ u32 length
12141550 ),
12151551
1216
- TP_ARGS(rdma, page),
1552
+ TP_ARGS(rdma, dma_addr, length),
12171553
12181554 TP_STRUCT__entry(
1219
- __field(const void *, page);
1555
+ __field(u64, dma_addr)
1556
+ __field(u32, length)
12201557 __string(device, rdma->sc_cm_id->device->name)
12211558 __string(addr, rdma->sc_xprt.xpt_remotebuf)
12221559 ),
12231560
12241561 TP_fast_assign(
1225
- __entry->page = page;
1562
+ __entry->dma_addr = dma_addr;
1563
+ __entry->length = length;
12261564 __assign_str(device, rdma->sc_cm_id->device->name);
12271565 __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
12281566 ),
12291567
1230
- TP_printk("addr=%s device=%s page=%p",
1231
- __get_str(addr), __get_str(device), __entry->page
1568
+ TP_printk("addr=%s device=%s dma_addr=%llu length=%u",
1569
+ __get_str(addr), __get_str(device),
1570
+ __entry->dma_addr, __entry->length
12321571 )
12331572 );
12341573
1235
-TRACE_EVENT(svcrdma_dma_map_rwctx,
1574
+#define DEFINE_SVC_DMA_EVENT(name) \
1575
+ DEFINE_EVENT(svcrdma_dma_map_class, svcrdma_##name, \
1576
+ TP_PROTO( \
1577
+ const struct svcxprt_rdma *rdma,\
1578
+ u64 dma_addr, \
1579
+ u32 length \
1580
+ ), \
1581
+ TP_ARGS(rdma, dma_addr, length))
1582
+
1583
+DEFINE_SVC_DMA_EVENT(dma_map_page);
1584
+DEFINE_SVC_DMA_EVENT(dma_unmap_page);
1585
+
1586
+TRACE_EVENT(svcrdma_dma_map_rw_err,
12361587 TP_PROTO(
12371588 const struct svcxprt_rdma *rdma,
1589
+ unsigned int nents,
12381590 int status
12391591 ),
12401592
1241
- TP_ARGS(rdma, status),
1593
+ TP_ARGS(rdma, nents, status),
12421594
12431595 TP_STRUCT__entry(
12441596 __field(int, status)
1597
+ __field(unsigned int, nents)
12451598 __string(device, rdma->sc_cm_id->device->name)
12461599 __string(addr, rdma->sc_xprt.xpt_remotebuf)
12471600 ),
12481601
12491602 TP_fast_assign(
12501603 __entry->status = status;
1604
+ __entry->nents = nents;
12511605 __assign_str(device, rdma->sc_cm_id->device->name);
12521606 __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
12531607 ),
12541608
1255
- TP_printk("addr=%s device=%s status=%d",
1256
- __get_str(addr), __get_str(device), __entry->status
1609
+ TP_printk("addr=%s device=%s nents=%u status=%d",
1610
+ __get_str(addr), __get_str(device), __entry->nents,
1611
+ __entry->status
12571612 )
12581613 );
12591614
1260
-TRACE_EVENT(svcrdma_send_failed,
1615
+TRACE_EVENT(svcrdma_no_rwctx_err,
1616
+ TP_PROTO(
1617
+ const struct svcxprt_rdma *rdma,
1618
+ unsigned int num_sges
1619
+ ),
1620
+
1621
+ TP_ARGS(rdma, num_sges),
1622
+
1623
+ TP_STRUCT__entry(
1624
+ __field(unsigned int, num_sges)
1625
+ __string(device, rdma->sc_cm_id->device->name)
1626
+ __string(addr, rdma->sc_xprt.xpt_remotebuf)
1627
+ ),
1628
+
1629
+ TP_fast_assign(
1630
+ __entry->num_sges = num_sges;
1631
+ __assign_str(device, rdma->sc_cm_id->device->name);
1632
+ __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
1633
+ ),
1634
+
1635
+ TP_printk("addr=%s device=%s num_sges=%d",
1636
+ __get_str(addr), __get_str(device), __entry->num_sges
1637
+ )
1638
+);
1639
+
1640
+TRACE_EVENT(svcrdma_page_overrun_err,
1641
+ TP_PROTO(
1642
+ const struct svcxprt_rdma *rdma,
1643
+ const struct svc_rqst *rqst,
1644
+ unsigned int pageno
1645
+ ),
1646
+
1647
+ TP_ARGS(rdma, rqst, pageno),
1648
+
1649
+ TP_STRUCT__entry(
1650
+ __field(unsigned int, pageno)
1651
+ __field(u32, xid)
1652
+ __string(device, rdma->sc_cm_id->device->name)
1653
+ __string(addr, rdma->sc_xprt.xpt_remotebuf)
1654
+ ),
1655
+
1656
+ TP_fast_assign(
1657
+ __entry->pageno = pageno;
1658
+ __entry->xid = __be32_to_cpu(rqst->rq_xid);
1659
+ __assign_str(device, rdma->sc_cm_id->device->name);
1660
+ __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
1661
+ ),
1662
+
1663
+ TP_printk("addr=%s device=%s xid=0x%08x pageno=%u", __get_str(addr),
1664
+ __get_str(device), __entry->xid, __entry->pageno
1665
+ )
1666
+);
1667
+
1668
+TRACE_EVENT(svcrdma_small_wrch_err,
1669
+ TP_PROTO(
1670
+ const struct svcxprt_rdma *rdma,
1671
+ unsigned int remaining,
1672
+ unsigned int seg_no,
1673
+ unsigned int num_segs
1674
+ ),
1675
+
1676
+ TP_ARGS(rdma, remaining, seg_no, num_segs),
1677
+
1678
+ TP_STRUCT__entry(
1679
+ __field(unsigned int, remaining)
1680
+ __field(unsigned int, seg_no)
1681
+ __field(unsigned int, num_segs)
1682
+ __string(device, rdma->sc_cm_id->device->name)
1683
+ __string(addr, rdma->sc_xprt.xpt_remotebuf)
1684
+ ),
1685
+
1686
+ TP_fast_assign(
1687
+ __entry->remaining = remaining;
1688
+ __entry->seg_no = seg_no;
1689
+ __entry->num_segs = num_segs;
1690
+ __assign_str(device, rdma->sc_cm_id->device->name);
1691
+ __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
1692
+ ),
1693
+
1694
+ TP_printk("addr=%s device=%s remaining=%u seg_no=%u num_segs=%u",
1695
+ __get_str(addr), __get_str(device), __entry->remaining,
1696
+ __entry->seg_no, __entry->num_segs
1697
+ )
1698
+);
1699
+
1700
+TRACE_EVENT(svcrdma_send_pullup,
1701
+ TP_PROTO(
1702
+ unsigned int len
1703
+ ),
1704
+
1705
+ TP_ARGS(len),
1706
+
1707
+ TP_STRUCT__entry(
1708
+ __field(unsigned int, len)
1709
+ ),
1710
+
1711
+ TP_fast_assign(
1712
+ __entry->len = len;
1713
+ ),
1714
+
1715
+ TP_printk("len=%u", __entry->len)
1716
+);
1717
+
1718
+TRACE_EVENT(svcrdma_send_err,
12611719 TP_PROTO(
12621720 const struct svc_rqst *rqst,
12631721 int status
....@@ -1268,195 +1726,127 @@
12681726 TP_STRUCT__entry(
12691727 __field(int, status)
12701728 __field(u32, xid)
1271
- __field(const void *, xprt)
12721729 __string(addr, rqst->rq_xprt->xpt_remotebuf)
12731730 ),
12741731
12751732 TP_fast_assign(
12761733 __entry->status = status;
12771734 __entry->xid = __be32_to_cpu(rqst->rq_xid);
1278
- __entry->xprt = rqst->rq_xprt;
12791735 __assign_str(addr, rqst->rq_xprt->xpt_remotebuf);
12801736 ),
12811737
1282
- TP_printk("xprt=%p addr=%s xid=0x%08x status=%d",
1283
- __entry->xprt, __get_str(addr),
1738
+ TP_printk("addr=%s xid=0x%08x status=%d", __get_str(addr),
12841739 __entry->xid, __entry->status
12851740 )
12861741 );
12871742
1288
-DECLARE_EVENT_CLASS(svcrdma_sendcomp_event,
1289
- TP_PROTO(
1290
- const struct ib_wc *wc
1291
- ),
1292
-
1293
- TP_ARGS(wc),
1294
-
1295
- TP_STRUCT__entry(
1296
- __field(const void *, cqe)
1297
- __field(unsigned int, status)
1298
- __field(unsigned int, vendor_err)
1299
- ),
1300
-
1301
- TP_fast_assign(
1302
- __entry->cqe = wc->wr_cqe;
1303
- __entry->status = wc->status;
1304
- if (wc->status)
1305
- __entry->vendor_err = wc->vendor_err;
1306
- else
1307
- __entry->vendor_err = 0;
1308
- ),
1309
-
1310
- TP_printk("cqe=%p status=%s (%u/0x%x)",
1311
- __entry->cqe, rdma_show_wc_status(__entry->status),
1312
- __entry->status, __entry->vendor_err
1313
- )
1314
-);
1315
-
1316
-#define DEFINE_SENDCOMP_EVENT(name) \
1317
- DEFINE_EVENT(svcrdma_sendcomp_event, svcrdma_wc_##name, \
1318
- TP_PROTO( \
1319
- const struct ib_wc *wc \
1320
- ), \
1321
- TP_ARGS(wc))
1322
-
13231743 TRACE_EVENT(svcrdma_post_send,
13241744 TP_PROTO(
1325
- const struct ib_send_wr *wr
1745
+ const struct svc_rdma_send_ctxt *ctxt
13261746 ),
13271747
1328
- TP_ARGS(wr),
1748
+ TP_ARGS(ctxt),
13291749
13301750 TP_STRUCT__entry(
1331
- __field(const void *, cqe)
1751
+ __field(u32, cq_id)
1752
+ __field(int, completion_id)
13321753 __field(unsigned int, num_sge)
13331754 __field(u32, inv_rkey)
13341755 ),
13351756
13361757 TP_fast_assign(
1337
- __entry->cqe = wr->wr_cqe;
1758
+ const struct ib_send_wr *wr = &ctxt->sc_send_wr;
1759
+
1760
+ __entry->cq_id = ctxt->sc_cid.ci_queue_id;
1761
+ __entry->completion_id = ctxt->sc_cid.ci_completion_id;
13381762 __entry->num_sge = wr->num_sge;
13391763 __entry->inv_rkey = (wr->opcode == IB_WR_SEND_WITH_INV) ?
13401764 wr->ex.invalidate_rkey : 0;
13411765 ),
13421766
1343
- TP_printk("cqe=%p num_sge=%u inv_rkey=0x%08x",
1344
- __entry->cqe, __entry->num_sge,
1345
- __entry->inv_rkey
1767
+ TP_printk("cq_id=%u cid=%d num_sge=%u inv_rkey=0x%08x",
1768
+ __entry->cq_id, __entry->completion_id,
1769
+ __entry->num_sge, __entry->inv_rkey
13461770 )
13471771 );
13481772
1349
-DEFINE_SENDCOMP_EVENT(send);
1773
+DEFINE_COMPLETION_EVENT(svcrdma_wc_send);
13501774
13511775 TRACE_EVENT(svcrdma_post_recv,
13521776 TP_PROTO(
1353
- const struct ib_recv_wr *wr,
1777
+ const struct svc_rdma_recv_ctxt *ctxt
1778
+ ),
1779
+
1780
+ TP_ARGS(ctxt),
1781
+
1782
+ TP_STRUCT__entry(
1783
+ __field(u32, cq_id)
1784
+ __field(int, completion_id)
1785
+ ),
1786
+
1787
+ TP_fast_assign(
1788
+ __entry->cq_id = ctxt->rc_cid.ci_queue_id;
1789
+ __entry->completion_id = ctxt->rc_cid.ci_completion_id;
1790
+ ),
1791
+
1792
+ TP_printk("cq.id=%d cid=%d",
1793
+ __entry->cq_id, __entry->completion_id
1794
+ )
1795
+);
1796
+
1797
+DEFINE_COMPLETION_EVENT(svcrdma_wc_receive);
1798
+
1799
+TRACE_EVENT(svcrdma_rq_post_err,
1800
+ TP_PROTO(
1801
+ const struct svcxprt_rdma *rdma,
13541802 int status
13551803 ),
13561804
1357
- TP_ARGS(wr, status),
1805
+ TP_ARGS(rdma, status),
13581806
13591807 TP_STRUCT__entry(
1360
- __field(const void *, cqe)
13611808 __field(int, status)
1809
+ __string(addr, rdma->sc_xprt.xpt_remotebuf)
13621810 ),
13631811
13641812 TP_fast_assign(
1365
- __entry->cqe = wr->wr_cqe;
13661813 __entry->status = status;
1814
+ __assign_str(addr, rdma->sc_xprt.xpt_remotebuf);
13671815 ),
13681816
1369
- TP_printk("cqe=%p status=%d",
1370
- __entry->cqe, __entry->status
1817
+ TP_printk("addr=%s status=%d",
1818
+ __get_str(addr), __entry->status
13711819 )
13721820 );
13731821
1374
-TRACE_EVENT(svcrdma_wc_receive,
1822
+TRACE_EVENT(svcrdma_post_chunk,
13751823 TP_PROTO(
1376
- const struct ib_wc *wc
1377
- ),
1378
-
1379
- TP_ARGS(wc),
1380
-
1381
- TP_STRUCT__entry(
1382
- __field(const void *, cqe)
1383
- __field(u32, byte_len)
1384
- __field(unsigned int, status)
1385
- __field(u32, vendor_err)
1386
- ),
1387
-
1388
- TP_fast_assign(
1389
- __entry->cqe = wc->wr_cqe;
1390
- __entry->status = wc->status;
1391
- if (wc->status) {
1392
- __entry->byte_len = 0;
1393
- __entry->vendor_err = wc->vendor_err;
1394
- } else {
1395
- __entry->byte_len = wc->byte_len;
1396
- __entry->vendor_err = 0;
1397
- }
1398
- ),
1399
-
1400
- TP_printk("cqe=%p byte_len=%u status=%s (%u/0x%x)",
1401
- __entry->cqe, __entry->byte_len,
1402
- rdma_show_wc_status(__entry->status),
1403
- __entry->status, __entry->vendor_err
1404
- )
1405
-);
1406
-
1407
-TRACE_EVENT(svcrdma_post_rw,
1408
- TP_PROTO(
1409
- const void *cqe,
1824
+ const struct rpc_rdma_cid *cid,
14101825 int sqecount
14111826 ),
14121827
1413
- TP_ARGS(cqe, sqecount),
1828
+ TP_ARGS(cid, sqecount),
14141829
14151830 TP_STRUCT__entry(
1416
- __field(const void *, cqe)
1831
+ __field(u32, cq_id)
1832
+ __field(int, completion_id)
14171833 __field(int, sqecount)
14181834 ),
14191835
14201836 TP_fast_assign(
1421
- __entry->cqe = cqe;
1837
+ __entry->cq_id = cid->ci_queue_id;
1838
+ __entry->completion_id = cid->ci_completion_id;
14221839 __entry->sqecount = sqecount;
14231840 ),
14241841
1425
- TP_printk("cqe=%p sqecount=%d",
1426
- __entry->cqe, __entry->sqecount
1842
+ TP_printk("cq.id=%u cid=%d sqecount=%d",
1843
+ __entry->cq_id, __entry->completion_id,
1844
+ __entry->sqecount
14271845 )
14281846 );
14291847
1430
-DEFINE_SENDCOMP_EVENT(read);
1431
-DEFINE_SENDCOMP_EVENT(write);
1432
-
1433
-TRACE_EVENT(svcrdma_cm_event,
1434
- TP_PROTO(
1435
- const struct rdma_cm_event *event,
1436
- const struct sockaddr *sap
1437
- ),
1438
-
1439
- TP_ARGS(event, sap),
1440
-
1441
- TP_STRUCT__entry(
1442
- __field(unsigned int, event)
1443
- __field(int, status)
1444
- __array(__u8, addr, INET6_ADDRSTRLEN + 10)
1445
- ),
1446
-
1447
- TP_fast_assign(
1448
- __entry->event = event->event;
1449
- __entry->status = event->status;
1450
- snprintf(__entry->addr, sizeof(__entry->addr) - 1,
1451
- "%pISpc", sap);
1452
- ),
1453
-
1454
- TP_printk("addr=%s event=%s (%u/%d)",
1455
- __entry->addr,
1456
- rdma_show_cm_event(__entry->event),
1457
- __entry->event, __entry->status
1458
- )
1459
-);
1848
+DEFINE_COMPLETION_EVENT(svcrdma_wc_read);
1849
+DEFINE_COMPLETION_EVENT(svcrdma_wc_write);
14601850
14611851 TRACE_EVENT(svcrdma_qp_error,
14621852 TP_PROTO(