[PATCH 00/16] Hyper-V: add tracing to VMBus module and trace all messages

[PATCH 00/16] Hyper-V: add tracing to VMBus module and trace all messages

[Vitaly Kuznetsov]

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     [005] .Ns.   465.923970: vmbus_on_msg_dpc: message 2 received
     ksoftirqd/5-41    [005] ..s.   465.923998: vmbus_on_msg_dpc: message 2 received
     kworker/5:1-64    [005] ....   465.924005: vmbus_on_message: processing message 2
     kworker/5:1-64    [005] ....   465.924005: vmbus_onoffer_rescind: child_relid 0x16
          <idle>-0     [005] ..s.   465.924114: vmbus_on_msg_dpc: message 2 received
          <idle>-0     [005] ..s.   465.924120: vmbus_on_msg_dpc: message 2 received
          <idle>-0     [005] .Ns.   465.924502: vmbus_on_msg_dpc: message 2 received
     kworker/5:2-208   [005] ....   465.924520: vmbus_on_message: processing message 2
     kworker/5:2-208   [005] ....   465.924520: vmbus_onoffer_rescind: child_relid 0x18
     kworker/5:0-2533  [005] ....   465.924713: vmbus_on_message: processing message 2
     kworker/5:0-2533  [005] ....   465.924713: vmbus_onoffer_rescind: child_relid 0x17
     kworker/5:3-2534  [005] ....   465.924810: vmbus_on_message: processing message 2
     kworker/5:3-2534  [005] ....   465.924810: vmbus_onoffer_rescind: child_relid 0x15
     kworker/5:4-2535  [005] ....   465.924900: vmbus_on_message: processing message 2
     kworker/5:4-2535  [005] ....   465.924901: vmbus_onoffer_rescind: child_relid 0x10
     kworker/5:4-2535  [005] ....   465.932588: vmbus_close_internal: sending child_relid 0x15, ret 0
     kworker/5:4-2535  [005] ....   465.932623: vmbus_close_internal: sending child_relid 0x16, ret 0
     kworker/5:4-2535  [005] ....   465.932656: vmbus_close_internal: sending child_relid 0x17, ret 0
     kworker/5:4-2535  [005] ....   465.932683: vmbus_close_internal: sending child_relid 0x18, ret 0
     kworker/5:4-2535  [005] ....   465.932709: vmbus_close_internal: sending child_relid 0x10, ret 0
     kworker/5:4-2535  [005] ....   465.986417: vmbus_release_relid: sending child_relid 0x10, ret 0

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

Vitaly Kuznetsov (16):
  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()

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

-- 
2.13.5

[PATCH 01/16] hyper-v: trace vmbus_on_msg_dpc()

[Vitaly Kuznetsov]

Add tracing subsystem to Hyper-V VMBus module and add tracepoint
to vmbus_on_msg_dpc() which is called when we receive a message from host.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/Makefile       |  4 +++-
 drivers/hv/hv_trace.c     |  4 ++++
 drivers/hv/hv_trace.h     | 24 ++++++++++++++++++++++++
 drivers/hv/hyperv_vmbus.h |  2 ++
 drivers/hv/vmbus_drv.c    |  2 ++
 5 files changed, 35 insertions(+), 1 deletion(-)
 create mode 100644 drivers/hv/hv_trace.c
 create mode 100644 drivers/hv/hv_trace.h

diff --git a/drivers/hv/Makefile b/drivers/hv/Makefile
index 39c9b2c08d33..ad791e00230f 100644
--- a/drivers/hv/Makefile
+++ b/drivers/hv/Makefile
@@ -2,7 +2,9 @@ obj-$(CONFIG_HYPERV)		+= hv_vmbus.o
 obj-$(CONFIG_HYPERV_UTILS)	+= hv_utils.o
 obj-$(CONFIG_HYPERV_BALLOON)	+= hv_balloon.o
 
+CFLAGS_hv_trace.o = -I$(src)
+
 hv_vmbus-y := vmbus_drv.o \
 		 hv.o connection.o channel.o \
-		 channel_mgmt.o ring_buffer.o
+		 channel_mgmt.o ring_buffer.o hv_trace.o
 hv_utils-y := hv_util.o hv_kvp.o hv_snapshot.o hv_fcopy.o hv_utils_transport.o
diff --git a/drivers/hv/hv_trace.c b/drivers/hv/hv_trace.c
new file mode 100644
index 000000000000..df47acd01a81
--- /dev/null
+++ b/drivers/hv/hv_trace.c
@@ -0,0 +1,4 @@
+#include "hyperv_vmbus.h"
+
+#define CREATE_TRACE_POINTS
+#include "hv_trace.h"
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
new file mode 100644
index 000000000000..9a29ef55477d
--- /dev/null
+++ b/drivers/hv/hv_trace.h
@@ -0,0 +1,24 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM hyperv
+
+#if !defined(_HV_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _HV_TRACE_H
+
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(vmbus_on_msg_dpc,
+	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
+	    TP_ARGS(hdr),
+	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
+	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
+	    TP_printk("message %u received", __entry->msgtype)
+	);
+
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH .
+#undef TRACE_INCLUDE_FILE
+#define TRACE_INCLUDE_FILE hv_trace
+#endif /* _HV_TRACE_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
diff --git a/drivers/hv/hyperv_vmbus.h b/drivers/hv/hyperv_vmbus.h
index 49569f8fe038..82eb082f3302 100644
--- a/drivers/hv/hyperv_vmbus.h
+++ b/drivers/hv/hyperv_vmbus.h
@@ -31,6 +31,8 @@
 #include <linux/hyperv.h>
 #include <linux/interrupt.h>
 
+#include "hv_trace.h"
+
 /*
  * Timeout for services such as KVP and fcopy.
  */
diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c
index a9d49f6f6501..ced33b1982c4 100644
--- a/drivers/hv/vmbus_drv.c
+++ b/drivers/hv/vmbus_drv.c
@@ -834,6 +834,8 @@ void vmbus_on_msg_dpc(unsigned long data)
 
 	hdr = (struct vmbus_channel_message_header *)msg->u.payload;
 
+	trace_vmbus_on_msg_dpc(hdr);
+
 	if (hdr->msgtype >= CHANNELMSG_COUNT) {
 		WARN_ONCE(1, "unknown msgtype=%d\n", hdr->msgtype);
 		goto msg_handled;
-- 
2.13.5

[PATCH 02/16] hyper-v: trace vmbus_on_message()

[Vitaly Kuznetsov]

Add tracepoint to vmbus_on_message() which is called when we start
processing a blocking from work context.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c | 2 ++
 drivers/hv/hv_trace.h     | 8 ++++++++
 2 files changed, 10 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 060df71c2e8b..ddeebba8971e 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -1170,6 +1170,8 @@ void vmbus_onmessage(void *context)
 	hdr = (struct vmbus_channel_message_header *)msg->u.payload;
 	size = msg->header.payload_size;
 
+	trace_vmbus_on_message(hdr);
+
 	if (hdr->msgtype >= CHANNELMSG_COUNT) {
 		pr_err("Received invalid channel message type %d size %d\n",
 			   hdr->msgtype, size);
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 9a29ef55477d..72911dfc9682 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -14,6 +14,14 @@ TRACE_EVENT(vmbus_on_msg_dpc,
 	    TP_printk("message %u received", __entry->msgtype)
 	);
 
+TRACE_EVENT(vmbus_on_message,
+	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
+	    TP_ARGS(hdr),
+	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
+	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
+	    TP_printk("processing message %u", __entry->msgtype)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 03/16] hyper-v: trace vmbus_onoffer()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_OFFERCHANNEL handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c |  2 ++
 drivers/hv/hv_trace.h     | 37 +++++++++++++++++++++++++++++++++++++
 2 files changed, 39 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index ddeebba8971e..290ea25ce409 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -797,6 +797,8 @@ static void vmbus_onoffer(struct vmbus_channel_message_header *hdr)
 
 	offer = (struct vmbus_channel_offer_channel *)hdr;
 
+	trace_vmbus_onoffer(offer);
+
 	/* Allocate the channel object and save this offer. */
 	newchannel = alloc_channel();
 	if (!newchannel) {
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 72911dfc9682..8376fdf9d054 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -22,6 +22,43 @@ TRACE_EVENT(vmbus_on_message,
 	    TP_printk("processing message %u", __entry->msgtype)
 	);
 
+TRACE_EVENT(vmbus_onoffer,
+	    TP_PROTO(const struct vmbus_channel_offer_channel *offer),
+	    TP_ARGS(offer),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u8, monitorid)
+		    __field(u16, is_ddc_int)
+		    __field(u32, connection_id)
+		    __array(char, if_type, 16)
+		    __array(char, if_instance, 16)
+		    __field(u16, chn_flags)
+		    __field(u16, mmio_mb)
+		    __field(u16, sub_idx)
+		    ),
+	    TP_fast_assign(__entry->child_relid = offer->child_relid;
+			   __entry->monitorid = offer->monitorid;
+			   __entry->is_ddc_int = offer->is_dedicated_interrupt;
+			   __entry->connection_id = offer->connection_id;
+			   memcpy(__entry->if_type,
+				  &offer->offer.if_type.b, 16);
+			   memcpy(__entry->if_instance,
+				  &offer->offer.if_instance.b, 16);
+			   __entry->chn_flags = offer->offer.chn_flags;
+			   __entry->mmio_mb = offer->offer.mmio_megabytes;
+			   __entry->sub_idx = offer->offer.sub_channel_index;
+		    ),
+	    TP_printk("child_relid 0x%x, monitorid 0x%x, is_dedicated %d, "
+		      "connection_id 0x%x, if_type %pUl, if_instance %pUl, "
+		      "chn_flags 0x%x, mmio_megabytes %d, sub_channel_index %d",
+		      __entry->child_relid, __entry->monitorid,
+		      __entry->is_ddc_int, __entry->connection_id,
+		      __entry->if_type, __entry->if_instance,
+		      __entry->chn_flags, __entry->mmio_mb,
+		      __entry->sub_idx
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 04/16] hyper-v: trace vmbus_onoffer_rescind()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_RESCIND_CHANNELOFFER handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c | 2 ++
 drivers/hv/hv_trace.h     | 8 ++++++++
 2 files changed, 10 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 290ea25ce409..563653a02ab6 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -841,6 +841,8 @@ static void vmbus_onoffer_rescind(struct vmbus_channel_message_header *hdr)
 
 	rescind = (struct vmbus_channel_rescind_offer *)hdr;
 
+	trace_vmbus_onoffer_rescind(rescind);
+
 	/*
 	 * The offer msg and the corresponding rescind msg
 	 * from the host are guranteed to be ordered -
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 8376fdf9d054..d2a5a97dcf2a 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -59,6 +59,14 @@ TRACE_EVENT(vmbus_onoffer,
 		    )
 	);
 
+TRACE_EVENT(vmbus_onoffer_rescind,
+	    TP_PROTO(const struct vmbus_channel_rescind_offer *offer),
+	    TP_ARGS(offer),
+	    TP_STRUCT__entry(__field(u32, child_relid)),
+	    TP_fast_assign(__entry->child_relid = offer->child_relid),
+	    TP_printk("child_relid 0x%x", __entry->child_relid)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 05/16] hyper-v: trace vmbus_onopen_result()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_OPENCHANNEL_RESULT handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c |  2 ++
 drivers/hv/hv_trace.h     | 17 +++++++++++++++++
 2 files changed, 19 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 563653a02ab6..2abe0563876b 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -980,6 +980,8 @@ static void vmbus_onopen_result(struct vmbus_channel_message_header *hdr)
 
 	result = (struct vmbus_channel_open_result *)hdr;
 
+	trace_vmbus_onopen_result(result);
+
 	/*
 	 * Find the open msg, copy the result and signal/unblock the wait event
 	 */
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index d2a5a97dcf2a..c98d66d683f4 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -67,6 +67,23 @@ TRACE_EVENT(vmbus_onoffer_rescind,
 	    TP_printk("child_relid 0x%x", __entry->child_relid)
 	);
 
+TRACE_EVENT(vmbus_onopen_result,
+	    TP_PROTO(const struct vmbus_channel_open_result *result),
+	    TP_ARGS(result),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u32, openid)
+		    __field(u32, status)
+		    ),
+	    TP_fast_assign(__entry->child_relid = result->child_relid;
+			   __entry->openid = result->openid;
+			   __entry->status = result->status;
+		    ),
+	    TP_printk("child_relid 0x%x, openid %d, status %d",
+		      __entry->child_relid,  __entry->openid,  __entry->status
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 06/16] hyper-v: trace vmbus_ongpadl_created()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_GPADL_CREATED handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c |  2 ++
 drivers/hv/hv_trace.h     | 17 +++++++++++++++++
 2 files changed, 19 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 2abe0563876b..af2448e245ca 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -1026,6 +1026,8 @@ static void vmbus_ongpadl_created(struct vmbus_channel_message_header *hdr)
 
 	gpadlcreated = (struct vmbus_channel_gpadl_created *)hdr;
 
+	trace_vmbus_ongpadl_created(gpadlcreated);
+
 	/*
 	 * Find the establish msg, copy the result and signal/unblock the wait
 	 * event
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index c98d66d683f4..99e2b8858e18 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -84,6 +84,23 @@ TRACE_EVENT(vmbus_onopen_result,
 		    )
 	);
 
+TRACE_EVENT(vmbus_ongpadl_created,
+	    TP_PROTO(const struct vmbus_channel_gpadl_created *gpadlcreated),
+	    TP_ARGS(gpadlcreated),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u32, gpadl)
+		    __field(u32, status)
+		    ),
+	    TP_fast_assign(__entry->child_relid = gpadlcreated->child_relid;
+			   __entry->gpadl = gpadlcreated->gpadl;
+			   __entry->status = gpadlcreated->creation_status;
+		    ),
+	    TP_printk("child_relid 0x%x, gpadl 0x%x, creation_status %d",
+		      __entry->child_relid,  __entry->gpadl,  __entry->status
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 07/16] hyper-v: trace vmbus_ongpadl_torndown()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_GPADL_TORNDOWN handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c | 2 ++
 drivers/hv/hv_trace.h     | 8 ++++++++
 2 files changed, 10 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index af2448e245ca..1ff2cc064850 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -1076,6 +1076,8 @@ static void vmbus_ongpadl_torndown(
 
 	gpadl_torndown = (struct vmbus_channel_gpadl_torndown *)hdr;
 
+	trace_vmbus_ongpadl_torndown(gpadl_torndown);
+
 	/*
 	 * Find the open msg, copy the result and signal/unblock the wait event
 	 */
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 99e2b8858e18..67e43dd59771 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -101,6 +101,14 @@ TRACE_EVENT(vmbus_ongpadl_created,
 		    )
 	);
 
+TRACE_EVENT(vmbus_ongpadl_torndown,
+	    TP_PROTO(const struct vmbus_channel_gpadl_torndown *gpadltorndown),
+	    TP_ARGS(gpadltorndown),
+	    TP_STRUCT__entry(__field(u32, gpadl)),
+	    TP_fast_assign(__entry->gpadl = gpadltorndown->gpadl),
+	    TP_printk("gpadl 0x%x", __entry->gpadl)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 08/16] hyper-v: trace vmbus_onversion_response()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_VERSION_RESPONSE handler.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c |  3 +++
 drivers/hv/hv_trace.h     | 11 +++++++++++
 2 files changed, 14 insertions(+)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 1ff2cc064850..a9a1fc1424c6 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -1121,6 +1121,9 @@ static void vmbus_onversion_response(
 	unsigned long flags;
 
 	version_response = (struct vmbus_channel_version_response *)hdr;
+
+	trace_vmbus_onversion_response(version_response);
+
 	spin_lock_irqsave(&vmbus_connection.channelmsg_lock, flags);
 
 	list_for_each_entry(msginfo, &vmbus_connection.chn_msg_list,
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 67e43dd59771..1478ec36967e 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -109,6 +109,17 @@ TRACE_EVENT(vmbus_ongpadl_torndown,
 	    TP_printk("gpadl 0x%x", __entry->gpadl)
 	);
 
+TRACE_EVENT(vmbus_onversion_response,
+	    TP_PROTO(const struct vmbus_channel_version_response *response),
+	    TP_ARGS(response),
+	    TP_STRUCT__entry(
+		    __field(u8, ver)
+		    ),
+	    TP_fast_assign(__entry->ver = response->version_supported;
+		    ),
+	    TP_printk("version_supported %d", __entry->ver)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 09/16] hyper-v: trace vmbus_request_offers()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_REQUESTOFFERS sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c | 4 +++-
 drivers/hv/hv_trace.h     | 8 ++++++++
 2 files changed, 11 insertions(+), 1 deletion(-)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index a9a1fc1424c6..5c39388545f5 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -1218,9 +1218,11 @@ int vmbus_request_offers(void)
 
 	msg->msgtype = CHANNELMSG_REQUESTOFFERS;
 
-
 	ret = vmbus_post_msg(msg, sizeof(struct vmbus_channel_message_header),
 			     true);
+
+	trace_vmbus_request_offers(ret);
+
 	if (ret != 0) {
 		pr_err("Unable to request offers - %d\n", ret);
 
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 1478ec36967e..b8d8460afc07 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -120,6 +120,14 @@ TRACE_EVENT(vmbus_onversion_response,
 	    TP_printk("version_supported %d", __entry->ver)
 	);
 
+TRACE_EVENT(vmbus_request_offers,
+	    TP_PROTO(int ret),
+	    TP_ARGS(ret),
+	    TP_STRUCT__entry(__field(int, ret)),
+	    TP_fast_assign(__entry->ret = ret),
+	    TP_printk("sending ret %d", __entry->ret)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 10/16] hyper-v: trace vmbus_open()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_OPENCHANNEL sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel.c  |  2 ++
 drivers/hv/hv_trace.h | 27 +++++++++++++++++++++++++++
 2 files changed, 29 insertions(+)

diff --git a/drivers/hv/channel.c b/drivers/hv/channel.c
index 676a130f0575..7b114b390871 100644
--- a/drivers/hv/channel.c
+++ b/drivers/hv/channel.c
@@ -185,6 +185,8 @@ int vmbus_open(struct vmbus_channel *newchannel, u32 send_ringbuffer_size,
 	ret = vmbus_post_msg(open_msg,
 			     sizeof(struct vmbus_channel_open_channel), true);
 
+	trace_vmbus_open(open_msg, ret);
+
 	if (ret != 0) {
 		err = ret;
 		goto error_clean_msglist;
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index b8d8460afc07..aefbbb56e686 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -128,6 +128,33 @@ TRACE_EVENT(vmbus_request_offers,
 	    TP_printk("sending ret %d", __entry->ret)
 	);
 
+TRACE_EVENT(vmbus_open,
+	    TP_PROTO(const struct vmbus_channel_open_channel *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u32, openid)
+		    __field(u32, gpadlhandle)
+		    __field(u32, target_vp)
+		    __field(u32, offset)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->child_relid = msg->child_relid;
+		    __entry->openid = msg->openid;
+		    __entry->gpadlhandle = msg->ringbuffer_gpadlhandle;
+		    __entry->target_vp = msg->target_vp;
+		    __entry->offset = msg->downstream_ringbuffer_pageoffset;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending child_relid 0x%x, openid %d, "
+		      "gpadlhandle 0x%x, target_vp 0x%x, offset 0x%x, ret %d",
+		      __entry->child_relid,  __entry->openid,
+		      __entry->gpadlhandle, __entry->target_vp,
+		      __entry->offset, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 11/16] hyper-v: trace vmbus_close_internal()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_CLOSECHANNEL sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel.c  |  2 ++
 drivers/hv/hv_trace.h | 15 +++++++++++++++
 2 files changed, 17 insertions(+)

diff --git a/drivers/hv/channel.c b/drivers/hv/channel.c
index 7b114b390871..9fe4c0624dbd 100644
--- a/drivers/hv/channel.c
+++ b/drivers/hv/channel.c
@@ -591,6 +591,8 @@ static int vmbus_close_internal(struct vmbus_channel *channel)
 	ret = vmbus_post_msg(msg, sizeof(struct vmbus_channel_close_channel),
 			     true);
 
+	trace_vmbus_close_internal(msg, ret);
+
 	if (ret) {
 		pr_err("Close failed: close post msg return is %d\n", ret);
 		/*
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index aefbbb56e686..a8c4bcd1fc8e 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -155,6 +155,21 @@ TRACE_EVENT(vmbus_open,
 		    )
 	);
 
+TRACE_EVENT(vmbus_close_internal,
+	    TP_PROTO(const struct vmbus_channel_close_channel *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->child_relid = msg->child_relid;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending child_relid 0x%x, ret %d", __entry->child_relid,
+		    __entry->ret)
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 12/16] hyper-v: trace vmbus_establish_gpadl()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_GPADL_HEADER/CHANNELMSG_GPADL_BODY sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel.c  |  6 ++++++
 drivers/hv/hv_trace.h | 42 ++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 48 insertions(+)

diff --git a/drivers/hv/channel.c b/drivers/hv/channel.c
index 9fe4c0624dbd..f51ddc89c85a 100644
--- a/drivers/hv/channel.c
+++ b/drivers/hv/channel.c
@@ -435,6 +435,9 @@ int vmbus_establish_gpadl(struct vmbus_channel *channel, void *kbuffer,
 
 	ret = vmbus_post_msg(gpadlmsg, msginfo->msgsize -
 			     sizeof(*msginfo), true);
+
+	trace_vmbus_establish_gpadl_header(gpadlmsg, ret);
+
 	if (ret != 0)
 		goto cleanup;
 
@@ -450,6 +453,9 @@ int vmbus_establish_gpadl(struct vmbus_channel *channel, void *kbuffer,
 		ret = vmbus_post_msg(gpadl_body,
 				     submsginfo->msgsize - sizeof(*submsginfo),
 				     true);
+
+		trace_vmbus_establish_gpadl_body(gpadl_body, ret);
+
 		if (ret != 0)
 			goto cleanup;
 
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index a8c4bcd1fc8e..a77a1f3b83ed 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -170,6 +170,48 @@ TRACE_EVENT(vmbus_close_internal,
 		    __entry->ret)
 	);
 
+TRACE_EVENT(vmbus_establish_gpadl_header,
+	    TP_PROTO(const struct vmbus_channel_gpadl_header *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u32, gpadl)
+		    __field(u16, range_buflen)
+		    __field(u16, rangecount)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->child_relid = msg->child_relid;
+		    __entry->gpadl = msg->gpadl;
+		    __entry->range_buflen = msg->range_buflen;
+		    __entry->rangecount = msg->rangecount;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending child_relid 0x%x, gpadl 0x%x, range_buflen %d "
+		      "rangecount %d, ret %d",
+		      __entry->child_relid, __entry->gpadl,
+		      __entry->range_buflen, __entry->rangecount, __entry->ret
+		    )
+	);
+
+TRACE_EVENT(vmbus_establish_gpadl_body,
+	    TP_PROTO(const struct vmbus_channel_gpadl_body *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, msgnumber)
+		    __field(u32, gpadl)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->msgnumber = msg->msgnumber;
+		    __entry->gpadl = msg->gpadl;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending msgnumber %d, gpadl 0x%x, ret %d",
+		      __entry->msgnumber, __entry->gpadl, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 13/16] hyper-v: trace vmbus_teardown_gpadl()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_GPADL_TEARDOWN sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel.c  |  2 ++
 drivers/hv/hv_trace.h | 18 ++++++++++++++++++
 2 files changed, 20 insertions(+)

diff --git a/drivers/hv/channel.c b/drivers/hv/channel.c
index f51ddc89c85a..2422ef6f9164 100644
--- a/drivers/hv/channel.c
+++ b/drivers/hv/channel.c
@@ -519,6 +519,8 @@ int vmbus_teardown_gpadl(struct vmbus_channel *channel, u32 gpadl_handle)
 	ret = vmbus_post_msg(msg, sizeof(struct vmbus_channel_gpadl_teardown),
 			     true);
 
+	trace_vmbus_teardown_gpadl(msg, ret);
+
 	if (ret)
 		goto post_msg_err;
 
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index a77a1f3b83ed..98c2e9e9ad5e 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -212,6 +212,24 @@ TRACE_EVENT(vmbus_establish_gpadl_body,
 		    )
 	);
 
+TRACE_EVENT(vmbus_teardown_gpadl,
+	    TP_PROTO(const struct vmbus_channel_gpadl_teardown *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(u32, gpadl)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->child_relid = msg->child_relid;
+		    __entry->gpadl = msg->gpadl;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending child_relid 0x%x, gpadl 0x%x, ret %d",
+		      __entry->child_relid, __entry->gpadl, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 14/16] hyper-v: trace vmbus_negotiate_version()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_INITIATE_CONTACT sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/connection.c |  3 +++
 drivers/hv/hv_trace.h   | 26 ++++++++++++++++++++++++++
 2 files changed, 29 insertions(+)

diff --git a/drivers/hv/connection.c b/drivers/hv/connection.c
index f41901f80b64..5e36f86d0b0c 100644
--- a/drivers/hv/connection.c
+++ b/drivers/hv/connection.c
@@ -117,6 +117,9 @@ static int vmbus_negotiate_version(struct vmbus_channel_msginfo *msginfo,
 	ret = vmbus_post_msg(msg,
 			     sizeof(struct vmbus_channel_initiate_contact),
 			     true);
+
+	trace_vmbus_negotiate_version(msg, ret);
+
 	if (ret != 0) {
 		spin_lock_irqsave(&vmbus_connection.channelmsg_lock, flags);
 		list_del(&msginfo->msglistentry);
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 98c2e9e9ad5e..70a4ae28e843 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -230,6 +230,32 @@ TRACE_EVENT(vmbus_teardown_gpadl,
 		    )
 	);
 
+TRACE_EVENT(vmbus_negotiate_version,
+	    TP_PROTO(const struct vmbus_channel_initiate_contact *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, ver)
+		    __field(u32, target_vcpu)
+		    __field(int, ret)
+		    __field(u64, int_page)
+		    __field(u64, mon_page1)
+		    __field(u64, mon_page2)
+		    ),
+	    TP_fast_assign(
+		    __entry->ver = msg->vmbus_version_requested;
+		    __entry->target_vcpu = msg->target_vcpu;
+		    __entry->int_page = msg->interrupt_page;
+		    __entry->mon_page1 = msg->monitor_page1;
+		    __entry->mon_page2 = msg->monitor_page2;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending vmbus_version_requested %d, target_vcpu 0x%x, "
+		      "pages %llx:%llx:%llx, ret %d",
+		      __entry->ver, __entry->target_vcpu, __entry->int_page,
+		      __entry->mon_page1, __entry->mon_page2, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 15/16] hyper-v: trace vmbus_release_relid()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_RELID_RELEASED sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel_mgmt.c |  7 +++++--
 drivers/hv/hv_trace.h     | 16 ++++++++++++++++
 2 files changed, 21 insertions(+), 2 deletions(-)

diff --git a/drivers/hv/channel_mgmt.c b/drivers/hv/channel_mgmt.c
index 5c39388545f5..ca2dea638bfb 100644
--- a/drivers/hv/channel_mgmt.c
+++ b/drivers/hv/channel_mgmt.c
@@ -373,12 +373,15 @@ static void percpu_channel_deq(void *arg)
 static void vmbus_release_relid(u32 relid)
 {
 	struct vmbus_channel_relid_released msg;
+	int ret;
 
 	memset(&msg, 0, sizeof(struct vmbus_channel_relid_released));
 	msg.child_relid = relid;
 	msg.header.msgtype = CHANNELMSG_RELID_RELEASED;
-	vmbus_post_msg(&msg, sizeof(struct vmbus_channel_relid_released),
-		       true);
+	ret = vmbus_post_msg(&msg, sizeof(struct vmbus_channel_relid_released),
+			     true);
+
+	trace_vmbus_release_relid(&msg, ret);
 }
 
 void hv_process_channel_removal(struct vmbus_channel *channel, u32 relid)
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index 70a4ae28e843..f2c1f45df647 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -256,6 +256,22 @@ TRACE_EVENT(vmbus_negotiate_version,
 		    )
 	);
 
+TRACE_EVENT(vmbus_release_relid,
+	    TP_PROTO(const struct vmbus_channel_relid_released *msg, int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __field(u32, child_relid)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    __entry->child_relid = msg->child_relid;
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending child_relid 0x%x, ret %d",
+		      __entry->child_relid, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH 16/16] hyper-v: trace vmbus_send_tl_connect_request()

[Vitaly Kuznetsov]

Add tracepoint to CHANNELMSG_TL_CONNECT_REQUEST sender.

Signed-off-by: Vitaly Kuznetsov <vkuznets@redhat.com>
---
 drivers/hv/channel.c  |  7 ++++++-
 drivers/hv/hv_trace.h | 20 ++++++++++++++++++++
 2 files changed, 26 insertions(+), 1 deletion(-)

diff --git a/drivers/hv/channel.c b/drivers/hv/channel.c
index 2422ef6f9164..71bdd2bb6647 100644
--- a/drivers/hv/channel.c
+++ b/drivers/hv/channel.c
@@ -236,13 +236,18 @@ int vmbus_send_tl_connect_request(const uuid_le *shv_guest_servie_id,
 				  const uuid_le *shv_host_servie_id)
 {
 	struct vmbus_channel_tl_connect_request conn_msg;
+	int ret;
 
 	memset(&conn_msg, 0, sizeof(conn_msg));
 	conn_msg.header.msgtype = CHANNELMSG_TL_CONNECT_REQUEST;
 	conn_msg.guest_endpoint_id = *shv_guest_servie_id;
 	conn_msg.host_service_id = *shv_host_servie_id;
 
-	return vmbus_post_msg(&conn_msg, sizeof(conn_msg), true);
+	ret = vmbus_post_msg(&conn_msg, sizeof(conn_msg), true);
+
+	trace_vmbus_send_tl_connect_request(&conn_msg, ret);
+
+	return ret;
 }
 EXPORT_SYMBOL_GPL(vmbus_send_tl_connect_request);
 
diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index f2c1f45df647..1d7e90fbeaa0 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -272,6 +272,26 @@ TRACE_EVENT(vmbus_release_relid,
 		    )
 	);
 
+TRACE_EVENT(vmbus_send_tl_connect_request,
+	    TP_PROTO(const struct vmbus_channel_tl_connect_request *msg,
+		     int ret),
+	    TP_ARGS(msg, ret),
+	    TP_STRUCT__entry(
+		    __array(char, guest_id, 16)
+		    __array(char, host_id, 16)
+		    __field(int, ret)
+		    ),
+	    TP_fast_assign(
+		    memcpy(__entry->guest_id, &msg->guest_endpoint_id.b, 16);
+		    memcpy(__entry->host_id, &msg->host_service_id.b, 16);
+		    __entry->ret = ret;
+		    ),
+	    TP_printk("sending guest_endpoint_id %pUl, host_service_id %pUl, "
+		      "ret %d",
+		      __entry->guest_id, __entry->host_id, __entry->ret
+		    )
+	);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

Re: [PATCH 02/16] hyper-v: trace vmbus_on_message()

[Steven Rostedt]

On Wed, 20 Sep 2017 19:21:53 +0200
Vitaly Kuznetsov <vkuznets@redhat.com> wrote:

> diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
> index 9a29ef55477d..72911dfc9682 100644
> --- a/drivers/hv/hv_trace.h
> +++ b/drivers/hv/hv_trace.h
> @@ -14,6 +14,14 @@ TRACE_EVENT(vmbus_on_msg_dpc,
>  	    TP_printk("message %u received", __entry->msgtype)
>  	);
>  
> +TRACE_EVENT(vmbus_on_message,
> +	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
> +	    TP_ARGS(hdr),
> +	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
> +	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
> +	    TP_printk("processing message %u", __entry->msgtype)
> +	);

Whenever you have two trace events with everything the same but the
TP_printk(), you can save a little space by using DEFINE_EVENT_PRINT()

DECLARE_EVENT_CLASS(vmbus_hdr_msg,
	TP_PROTO(const struct vmbus_channel_message_header *hdr),
	TP_ARGS(hdr),
	TP_STRUCT__entry(__field(unsigned int, msgtype),
	TP_fast_assign(__entry->msg = hdr->msgtype;),
	TP_printk("msgtype=%d", __entry->msgtype)
);

DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
	TP_PROTO(const struct vmbus_channel_message_header *hdr),
	TP_ARGS(hdr),
	TP_printk("message %u received", __entry->msgtype));

DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
	TP_PROTO(const struct vmbus_channel_message_header *hdr),
	TP_ARGS(hdr),
	TP_printk("processing message %u", __entry->msgtype));

This will use the same functions required to save and record the
message but will use a different function to output it to the trace.

-- Steve

Re: [PATCH 02/16] hyper-v: trace vmbus_on_message()

[Vitaly Kuznetsov]

Steven Rostedt <rostedt@goodmis.org> writes:

> On Wed, 20 Sep 2017 19:21:53 +0200
> Vitaly Kuznetsov <vkuznets@redhat.com> wrote:
>
>> diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
>> index 9a29ef55477d..72911dfc9682 100644
>> --- a/drivers/hv/hv_trace.h
>> +++ b/drivers/hv/hv_trace.h
>> @@ -14,6 +14,14 @@ TRACE_EVENT(vmbus_on_msg_dpc,
>>  	    TP_printk("message %u received", __entry->msgtype)
>>  	);
>>  
>> +TRACE_EVENT(vmbus_on_message,
>> +	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
>> +	    TP_ARGS(hdr),
>> +	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
>> +	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
>> +	    TP_printk("processing message %u", __entry->msgtype)
>> +	);
>
> Whenever you have two trace events with everything the same but the
> TP_printk(), you can save a little space by using DEFINE_EVENT_PRINT()
>
> DECLARE_EVENT_CLASS(vmbus_hdr_msg,
> 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> 	TP_ARGS(hdr),
> 	TP_STRUCT__entry(__field(unsigned int, msgtype),
> 	TP_fast_assign(__entry->msg = hdr->msgtype;),
> 	TP_printk("msgtype=%d", __entry->msgtype)
> );
>
> DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
> 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> 	TP_ARGS(hdr),
> 	TP_printk("message %u received", __entry->msgtype));
>
> DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
> 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> 	TP_ARGS(hdr),
> 	TP_printk("processing message %u", __entry->msgtype));
>
> This will use the same functions required to save and record the
> message but will use a different function to output it to the trace.

Oh, thanks! This seems to be useful for
vmbus_on_msg_dpc/vmbus_on_message only as all the rest needs to parse
different structures. Will use it in v2.

-- 
  Vitaly

Re: [PATCH 02/16] hyper-v: trace vmbus_on_message()

[Stephen Hemminger]

On Thu, 21 Sep 2017 10:17:18 +0200
Vitaly Kuznetsov <vkuznets@redhat.com> wrote:

> Steven Rostedt <rostedt@goodmis.org> writes:
> 
> > On Wed, 20 Sep 2017 19:21:53 +0200
> > Vitaly Kuznetsov <vkuznets@redhat.com> wrote:
> >  
> >> diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
> >> index 9a29ef55477d..72911dfc9682 100644
> >> --- a/drivers/hv/hv_trace.h
> >> +++ b/drivers/hv/hv_trace.h
> >> @@ -14,6 +14,14 @@ TRACE_EVENT(vmbus_on_msg_dpc,
> >>  	    TP_printk("message %u received", __entry->msgtype)
> >>  	);
> >>  
> >> +TRACE_EVENT(vmbus_on_message,
> >> +	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
> >> +	    TP_ARGS(hdr),
> >> +	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
> >> +	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
> >> +	    TP_printk("processing message %u", __entry->msgtype)
> >> +	);  
> >
> > Whenever you have two trace events with everything the same but the
> > TP_printk(), you can save a little space by using DEFINE_EVENT_PRINT()
> >
> > DECLARE_EVENT_CLASS(vmbus_hdr_msg,
> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> > 	TP_ARGS(hdr),
> > 	TP_STRUCT__entry(__field(unsigned int, msgtype),
> > 	TP_fast_assign(__entry->msg = hdr->msgtype;),
> > 	TP_printk("msgtype=%d", __entry->msgtype)
> > );
> >
> > DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> > 	TP_ARGS(hdr),
> > 	TP_printk("message %u received", __entry->msgtype));
> >
> > DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> > 	TP_ARGS(hdr),
> > 	TP_printk("processing message %u", __entry->msgtype));
> >
> > This will use the same functions required to save and record the
> > message but will use a different function to output it to the trace.  
> 
> Oh, thanks! This seems to be useful for
> vmbus_on_msg_dpc/vmbus_on_message only as all the rest needs to parse
> different structures. Will use it in v2.
> 

I just used this patch. Since function name is already in the trace message
no need to have different print's for each one.

>From ff85967810c216eb01d181789af4f56bd00dc9b9 Mon Sep 17 00:00:00 2001
From: Stephen Hemminger <sthemmin@microsoft.com>
Date: Tue, 3 Oct 2017 09:24:11 -0700
Subject: [PATCH 3/4] hyperv: fix warnings in trace print

This gets rid of the build warnings from unused printf format.
And uses common class for print.
---
 drivers/hv/hv_trace.h | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
index be7762955650..4755c4640e39 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -11,18 +11,18 @@ DECLARE_EVENT_CLASS(vmbus_hdr_msg,
 	TP_ARGS(hdr),
 	TP_STRUCT__entry(__field(unsigned int, msgtype)),
 	TP_fast_assign(__entry->msgtype = hdr->msgtype;),
-	TP_printk("msgtype=%d", __entry->msgtype)
+	TP_printk("msgtype=%u", __entry->msgtype)
 );
 
-DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
+DEFINE_EVENT(vmbus_hdr_msg, vmbus_on_msg_dpc,
 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
-	TP_ARGS(hdr),
-	TP_printk("message %u received", __entry->msgtype));
+	TP_ARGS(hdr)
+);
 
-DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
+DEFINE_EVENT(vmbus_hdr_msg, vmbus_on_message,
         TP_PROTO(const struct vmbus_channel_message_header *hdr),
-        TP_ARGS(hdr),
-        TP_printk("processing message %u", __entry->msgtype));
+        TP_ARGS(hdr)
+);
 
 TRACE_EVENT(vmbus_onoffer,
 	    TP_PROTO(const struct vmbus_channel_offer_channel *offer),
-- 
2.11.0

Re: [PATCH 02/16] hyper-v: trace vmbus_on_message()

[Vitaly Kuznetsov]

Stephen Hemminger <stephen@networkplumber.org> writes:

> On Thu, 21 Sep 2017 10:17:18 +0200
> Vitaly Kuznetsov <vkuznets@redhat.com> wrote:
>
>> Steven Rostedt <rostedt@goodmis.org> writes:
>> 
>> > On Wed, 20 Sep 2017 19:21:53 +0200
>> > Vitaly Kuznetsov <vkuznets@redhat.com> wrote:
>> >  
>> >> diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
>> >> index 9a29ef55477d..72911dfc9682 100644
>> >> --- a/drivers/hv/hv_trace.h
>> >> +++ b/drivers/hv/hv_trace.h
>> >> @@ -14,6 +14,14 @@ TRACE_EVENT(vmbus_on_msg_dpc,
>> >>  	    TP_printk("message %u received", __entry->msgtype)
>> >>  	);
>> >>  
>> >> +TRACE_EVENT(vmbus_on_message,
>> >> +	    TP_PROTO(const struct vmbus_channel_message_header *hdr),
>> >> +	    TP_ARGS(hdr),
>> >> +	    TP_STRUCT__entry(__field(unsigned int, msgtype)),
>> >> +	    TP_fast_assign(__entry->msgtype = hdr->msgtype),
>> >> +	    TP_printk("processing message %u", __entry->msgtype)
>> >> +	);  
>> >
>> > Whenever you have two trace events with everything the same but the
>> > TP_printk(), you can save a little space by using DEFINE_EVENT_PRINT()
>> >
>> > DECLARE_EVENT_CLASS(vmbus_hdr_msg,
>> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
>> > 	TP_ARGS(hdr),
>> > 	TP_STRUCT__entry(__field(unsigned int, msgtype),
>> > 	TP_fast_assign(__entry->msg = hdr->msgtype;),
>> > 	TP_printk("msgtype=%d", __entry->msgtype)
>> > );
>> >
>> > DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
>> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
>> > 	TP_ARGS(hdr),
>> > 	TP_printk("message %u received", __entry->msgtype));
>> >
>> > DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
>> > 	TP_PROTO(const struct vmbus_channel_message_header *hdr),
>> > 	TP_ARGS(hdr),
>> > 	TP_printk("processing message %u", __entry->msgtype));
>> >
>> > This will use the same functions required to save and record the
>> > message but will use a different function to output it to the trace.  
>> 
>> Oh, thanks! This seems to be useful for
>> vmbus_on_msg_dpc/vmbus_on_message only as all the rest needs to parse
>> different structures. Will use it in v2.
>> 
>
> I just used this patch. Since function name is already in the trace message
> no need to have different print's for each one.
>

Sure, will incorporate this into v3.

> From ff85967810c216eb01d181789af4f56bd00dc9b9 Mon Sep 17 00:00:00 2001
> From: Stephen Hemminger <sthemmin@microsoft.com>
> Date: Tue, 3 Oct 2017 09:24:11 -0700
> Subject: [PATCH 3/4] hyperv: fix warnings in trace print
>
> This gets rid of the build warnings from unused printf format.
> And uses common class for print.
> ---
>  drivers/hv/hv_trace.h | 14 +++++++-------
>  1 file changed, 7 insertions(+), 7 deletions(-)
>
> diff --git a/drivers/hv/hv_trace.h b/drivers/hv/hv_trace.h
> index be7762955650..4755c4640e39 100644
> --- a/drivers/hv/hv_trace.h
> +++ b/drivers/hv/hv_trace.h
> @@ -11,18 +11,18 @@ DECLARE_EVENT_CLASS(vmbus_hdr_msg,
>  	TP_ARGS(hdr),
>  	TP_STRUCT__entry(__field(unsigned int, msgtype)),
>  	TP_fast_assign(__entry->msgtype = hdr->msgtype;),
> -	TP_printk("msgtype=%d", __entry->msgtype)
> +	TP_printk("msgtype=%u", __entry->msgtype)
>  );
>
> -DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
> +DEFINE_EVENT(vmbus_hdr_msg, vmbus_on_msg_dpc,
>  	TP_PROTO(const struct vmbus_channel_message_header *hdr),
> -	TP_ARGS(hdr),
> -	TP_printk("message %u received", __entry->msgtype));
> +	TP_ARGS(hdr)
> +);
>
> -DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
> +DEFINE_EVENT(vmbus_hdr_msg, vmbus_on_message,
>          TP_PROTO(const struct vmbus_channel_message_header *hdr),
> -        TP_ARGS(hdr),
> -        TP_printk("processing message %u", __entry->msgtype));
> +        TP_ARGS(hdr)
> +);
>
>  TRACE_EVENT(vmbus_onoffer,
>  	    TP_PROTO(const struct vmbus_channel_offer_channel *offer),

-- 
  Vitaly