[PATCH 00/17] Drivers: hv: vmbus: Add tracing to VMBus

From: kys
Date: Sun Oct 29 2017 - 15:21:42 EST


From: "K. Y. Srinivasan" <kys@xxxxxxxxxxxxx>

Reply-To: kys@xxxxxxxxxxxxx

Messages between guest and host are used in Hyper-V as control flow. To
simplify debugging various issues which are often hard to reproduce add
tracepoints to all message senders and handlers. This is not a
performance
critical path and tracing overhead should be negligible.

The example usage and output is:

Enable all tracing events:
# echo 1 > /sys/kernel/debug/tracing/events/hyperv/enable

Do something which causes messages to be sent between host and guest,
e.g.
hot remove a VMBus device.

Check events:
# cat /sys/kernel/debug/tracing/trace

# tracer: nop
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<idle>-0 [011] ..s. 122.981583: vmbus_on_msg_dpc:
msgtype=1
kworker/11:7-1506 [011] .... 122.981597: vmbus_on_message:
msgtype=1
kworker/11:7-1506 [011] .... 122.981598: vmbus_onoffer:
child_relid 0x10, monitorid 0x2, is_dedicated 1, connection_id 0x10010,
if_type f8615163-df3e-46c5-913f-f2d2f965ed0e, if_instance
6676e078-e4b3-44da-8a7d-12eafb577d31, chn_flags 0x0, mmio_megabytes 0,
sub_channel_index 0
kworker/11:7-1506 [011] .... 122.982130:
vmbus_establish_gpadl_header: sending child_relid 0x10, gpadl 0xe1e34,
range_buflen 2056 rangecount 1, ret 0
kworker/11:7-1506 [011] .... 122.982133:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982136:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982137:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982139:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982141:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982142:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982144:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982146:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
kworker/11:7-1506 [011] .... 122.982148:
vmbus_establish_gpadl_body: sending msgnumber 0, gpadl 0xe1e34, ret 0
<idle>-0 [011] ..s. 122.982336: vmbus_on_msg_dpc:
msgtype=10
<idle>-0 [011] ..s. 122.982337: vmbus_ongpadl_created:
child_relid 0x10, gpadl 0xe1e34, creation_status 0
kworker/11:7-1506 [011] .... 122.982351: vmbus_open: sending
child_relid 0x10, openid 16, gpadlhandle 0xe1e34, target_vp 0xb, offset
0x80, ret 0
kworker/3:1-214 [003] .... 123.015007: vmbus_setevent: relid
0x5
<idle>-0 [011] ..s. 123.029467: vmbus_on_msg_dpc:
msgtype=6
<idle>-0 [011] ..s. 123.029470: vmbus_onopen_result:
child_relid 0x10, openid 16, status 0
kworker/11:7-1506 [011] .... 123.029492: vmbus_setevent: relid
0x10
<idle>-0 [011] d.h. 123.029533: vmbus_chan_sched: relid
0x10
kworker/11:7-1506 [011] .... 123.029539: vmbus_setevent: relid
0x10

CHANNELMSG_UNLOAD/CHANNELMSG_UNLOAD_RESPONSE are not traced as these are
mostly used on crash.


Vitaly Kuznetsov (17):
hyper-v: trace vmbus_on_msg_dpc()
hyper-v: trace vmbus_on_message()
hyper-v: trace vmbus_onoffer()
hyper-v: trace vmbus_onoffer_rescind()
hyper-v: trace vmbus_onopen_result()
hyper-v: trace vmbus_ongpadl_created()
hyper-v: trace vmbus_ongpadl_torndown()
hyper-v: trace vmbus_onversion_response()
hyper-v: trace vmbus_request_offers()
hyper-v: trace vmbus_open()
hyper-v: trace vmbus_close_internal()
hyper-v: trace vmbus_establish_gpadl()
hyper-v: trace vmbus_teardown_gpadl()
hyper-v: trace vmbus_negotiate_version()
hyper-v: trace vmbus_release_relid()
hyper-v: trace vmbus_send_tl_connect_request()
hyper-v: trace channel events

drivers/hv/Makefile | 4 +-
drivers/hv/channel.c | 21 ++-
drivers/hv/channel_mgmt.c | 26 +++-
drivers/hv/connection.c | 5 +
drivers/hv/hv_trace.c | 4 +
drivers/hv/hv_trace.h | 327 ++++++++++++++++++++++++++++++++++++++++++++++
drivers/hv/hyperv_vmbus.h | 2 +
drivers/hv/vmbus_drv.c | 4 +
8 files changed, 388 insertions(+), 5 deletions(-)
create mode 100644 drivers/hv/hv_trace.c
create mode 100644 drivers/hv/hv_trace.h

--
2.14.1