tree 888db98a205eab1310ed8aa6a6f4338c49fc4dca
parent ad9efa05a0ea2fd9960d4e163fad56279cde45b2
author Chuck Lever <chuck.lever@oracle.com> 1576700290 -0500
committer Jason Gunthorpe <jgg@mellanox.com> 1578427853 -0400

RDMA/cma: Add trace points in RDMA Connection Manager

Record state transitions as each connection is established. The IP address
of both peers and the Type of Service is reported. These trace points are
not in performance hot paths.

Also, record each cm_event_handler call to ULPs. This eliminates the need
for each ULP to add its own similar trace point in its CM event handler
function.

These new trace points appear in a new trace subsystem called "rdma_cma".

Sample events:

           <...>-220   [004]   121.430733: cm_id_create:         cm.id=0
           <...>-472   [003]   121.430991: cm_event_handler:     cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 ADDR_RESOLVED (0/0)
           <...>-472   [003]   121.430995: cm_event_done:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 result=0
           <...>-472   [003]   121.431172: cm_event_handler:     cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 ROUTE_RESOLVED (2/0)
           <...>-472   [003]   121.431174: cm_event_done:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 result=0
           <...>-220   [004]   121.433480: cm_qp_create:         cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 pd.id=2 qp_type=RC send_wr=4091 recv_wr=256 qp_num=521 rc=0
           <...>-220   [004]   121.433577: cm_send_req:          cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 qp_num=521
     kworker/1:2-973   [001]   121.436190: cm_send_mra:          cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0
     kworker/1:2-973   [001]   121.436340: cm_send_rtu:          cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0
     kworker/1:2-973   [001]   121.436359: cm_event_handler:     cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 ESTABLISHED (9/0)
     kworker/1:2-973   [001]   121.436365: cm_event_done:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 result=0
           <...>-1975  [005]   123.161954: cm_disconnect:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0
           <...>-1975  [005]   123.161974: cm_sent_dreq:         cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0
           <...>-220   [004]   123.162102: cm_disconnect:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0
     kworker/0:1-13    [000]   123.162391: cm_event_handler:     cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 DISCONNECTED (10/0)
     kworker/0:1-13    [000]   123.162393: cm_event_done:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 result=0
           <...>-220   [004]   123.164456: cm_qp_destroy:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0 qp_num=521
           <...>-220   [004]   123.165290: cm_id_destroy:        cm.id=0 src=192.168.2.51:35090 dst=192.168.2.55:20049 tos=0

Some features to note:
- restracker ID of the rdma_cm_id is tagged on each trace event
- The source and destination IP addresses and TOS are reported
- CM event upcalls are shown with decoded event and status
- CM state transitions are reported
- rdma_cm_id lifetime events are captured
- The latency of ULP CM event handlers is reported
- Lifetime events of associated QPs are reported
- Device removal and insertion is reported

This patch is based on previous work by:

Saeed Mahameed <saeedm@mellanox.com>
Mukesh Kacker <mukesh.kacker@oracle.com>
Ajaykumar Hotchandani <ajaykumar.hotchandani@oracle.com>
Aron Silverton <aron.silverton@oracle.com>
Avinash Repaka <avinash.repaka@oracle.com>
Somasundaram Krishnasamy <somasundaram.krishnasamy@oracle.com>

Link: https://lore.kernel.org/r/20191218201810.30584.3052.stgit@manet.1015granger.net
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>
Signed-off-by: Jason Gunthorpe <jgg@mellanox.com>