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

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

[Vitaly Kuznetsov]

Changes since v1:
- Use DECLARE_EVENT_CLASS/DEFINE_EVENT_PRINT for vmbus_on_msg_dpc/
  vmbus_onmessage tracing (Steven Rostedt)

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     | 304 ++++++++++++++++++++++++++++++++++++++++++++++
 drivers/hv/hyperv_vmbus.h |   2 +
 drivers/hv/vmbus_drv.c    |   2 +
 8 files changed, 359 insertions(+), 5 deletions(-)
 create mode 100644 drivers/hv/hv_trace.c
 create mode 100644 drivers/hv/hv_trace.h

-- 
2.13.5

[PATCH v2 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     | 29 +++++++++++++++++++++++++++++
 drivers/hv/hyperv_vmbus.h |  2 ++
 drivers/hv/vmbus_drv.c    |  2 ++
 5 files changed, 40 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..82432e351724
--- /dev/null
+++ b/drivers/hv/hv_trace.h
@@ -0,0 +1,29 @@
+#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>
+
+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->msgtype = 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));
+
+#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 v2 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     | 5 +++++
 2 files changed, 7 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 82432e351724..4aac780099b4 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -19,6 +19,11 @@ DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_msg_dpc,
 	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));
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
-- 
2.13.5

[PATCH v2 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 4aac780099b4..d38f8ed272ca 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -24,6 +24,43 @@ DEFINE_EVENT_PRINT(vmbus_hdr_msg, vmbus_on_message,
         TP_ARGS(hdr),
         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 v2 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 d38f8ed272ca..8bb8806a16f7 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -61,6 +61,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 v2 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 8bb8806a16f7..c42653c21238 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -69,6 +69,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 v2 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 c42653c21238..e5973ab27c58 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -86,6 +86,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 v2 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 e5973ab27c58..0c50527c815c 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -103,6 +103,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 v2 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 0c50527c815c..e99db56d27b7 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -111,6 +111,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 v2 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 e99db56d27b7..7212d8898775 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -122,6 +122,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 v2 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 efd5db743319..82cb57e2d6bd 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 7212d8898775..01acbbf7badf 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -130,6 +130,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 v2 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 82cb57e2d6bd..f919d9dd984b 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 01acbbf7badf..ecfacb114331 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -157,6 +157,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 v2 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 f919d9dd984b..cf6bc0667cde 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 ecfacb114331..9eb8ee51a77f 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -172,6 +172,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 v2 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 cf6bc0667cde..9cb81838e7bb 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 9eb8ee51a77f..6c585a012a40 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -214,6 +214,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 v2 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 6c585a012a40..570482014740 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -232,6 +232,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 v2 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 570482014740..3e751f948a5f 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -258,6 +258,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 v2 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 9cb81838e7bb..3efe9e8ab079 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 3e751f948a5f..3a7eaff355dd 100644
--- a/drivers/hv/hv_trace.h
+++ b/drivers/hv/hv_trace.h
@@ -274,6 +274,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 v2 01/16] hyper-v: trace vmbus_on_msg_dpc()

[kbuild test robot]

[-- Attachment #1: Type: text/plain, Size: 2140 bytes --]

Hi Vitaly,

[auto build test WARNING on linus/master]
[also build test WARNING on v4.14-rc3 next-20170929]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Vitaly-Kuznetsov/hyper-v-trace-vmbus_on_msg_dpc/20171002-062040
config: i386-randconfig-x017-201740 (attached as .config)
compiler: gcc-6 (Debian 6.2.0-3) 6.2.0 20160901
reproduce:
        # save the attached .config to linux build tree
        make ARCH=i386 

All warnings (new ones prefixed by >>):

   In file included from include/trace/define_trace.h:95:0,
                    from drivers/hv/hv_trace.h:29,
                    from drivers/hv/hv_trace.c:4:
   include/trace/trace_events.h:759:13: warning: 'print_fmt_vmbus_hdr_msg' defined but not used [-Wunused-variable]
    static char print_fmt_##call[] = print;     \
                ^
>> drivers/hv/./hv_trace.h:9:1: note: in expansion of macro 'DECLARE_EVENT_CLASS'
    DECLARE_EVENT_CLASS(vmbus_hdr_msg,
    ^~~~~~~~~~~~~~~~~~~
   In file included from include/trace/define_trace.h:95:0,
                    from drivers/hv/hv_trace.h:29,
                    from drivers/hv/hv_trace.c:4:
   include/trace/trace_events.h:363:37: warning: 'trace_event_type_funcs_vmbus_hdr_msg' defined but not used [-Wunused-variable]
    static struct trace_event_functions trace_event_type_funcs_##call = { \
                                        ^
>> drivers/hv/./hv_trace.h:9:1: note: in expansion of macro 'DECLARE_EVENT_CLASS'
    DECLARE_EVENT_CLASS(vmbus_hdr_msg,
    ^~~~~~~~~~~~~~~~~~~

vim +/DECLARE_EVENT_CLASS +9 drivers/hv/./hv_trace.h

     8	
   > 9	DECLARE_EVENT_CLASS(vmbus_hdr_msg,
    10		TP_PROTO(const struct vmbus_channel_message_header *hdr),
    11		TP_ARGS(hdr),
    12		TP_STRUCT__entry(__field(unsigned int, msgtype)),
    13		TP_fast_assign(__entry->msgtype = hdr->msgtype;),
    14		TP_printk("msgtype=%d", __entry->msgtype)
    15	);
    16	

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

[-- Attachment #2: .config.gz --]
[-- Type: application/gzip, Size: 25465 bytes --]

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

[Stephen Hemminger]

I added an additional set of trace points for when channel gets notified or signals host.

diff -urNp linux-msft/drivers/hv/channel.c msft-4.14-rc3/drivers/hv/channel.c
--- linux-msft/drivers/hv/channel.c	2017-10-03 10:06:54.893209237 -0700
+++ msft-4.14-rc3/drivers/hv/channel.c	2017-10-03 10:07:35.501665114 -0700
@@ -55,6 +55,8 @@ void vmbus_setevent(struct vmbus_channel
 {
 	struct hv_monitor_page *monitorpage;
 
+	trace_vmbus_setevent(channel);
+
 	/*
 	 * For channels marked as in "low latency" mode
 	 * bypass the monitor page mechanism.
diff -urNp linux-msft/drivers/hv/connection.c msft-4.14-rc3/drivers/hv/connection.c
--- linux-msft/drivers/hv/connection.c	2017-10-03 10:06:54.893209237 -0700
+++ msft-4.14-rc3/drivers/hv/connection.c	2017-10-03 10:07:35.501665114 -0700
@@ -322,6 +322,8 @@ void vmbus_on_event(unsigned long data)
 	struct vmbus_channel *channel = (void *) data;
 	unsigned long time_limit = jiffies + 2;
 
+	trace_vmbus_on_event(channel);
+	
 	do {
 		void (*callback_fn)(void *);
 
diff -urNp linux-msft/drivers/hv/hv_trace.h msft-4.14-rc3/drivers/hv/hv_trace.h
--- linux-msft/drivers/hv/hv_trace.h	2017-10-03 10:08:06.514014019 -0700
+++ msft-4.14-rc3/drivers/hv/hv_trace.h	2017-10-03 10:07:35.505665159 -0700
@@ -294,6 +294,29 @@ TRACE_EVENT(vmbus_send_tl_connect_reques
 		    )
 	);
 
+DECLARE_EVENT_CLASS(vmbus_channel,
+	TP_PROTO(const struct vmbus_channel *channel),
+	TP_ARGS(channel),
+	TP_STRUCT__entry(__field(u32, relid)),
+	TP_fast_assign(__entry->relid = channel->offermsg.child_relid),
+	TP_printk("relid 0x%x", __entry->relid)
+);
+
+DEFINE_EVENT(vmbus_channel, vmbus_chan_sched,
+	    TP_PROTO(const struct vmbus_channel *channel),
+	    TP_ARGS(channel)
+);
+
+DEFINE_EVENT(vmbus_channel, vmbus_setevent,
+	    TP_PROTO(const struct vmbus_channel *channel),
+	    TP_ARGS(channel)
+);
+
+DEFINE_EVENT(vmbus_channel, vmbus_on_event,
+	    TP_PROTO(const struct vmbus_channel *channel),
+	    TP_ARGS(channel)
+);
+
 #undef TRACE_INCLUDE_PATH
 #define TRACE_INCLUDE_PATH .
 #undef TRACE_INCLUDE_FILE
diff -urNp linux-msft/drivers/hv/vmbus_drv.c msft-4.14-rc3/drivers/hv/vmbus_drv.c
--- linux-msft/drivers/hv/vmbus_drv.c	2017-10-03 10:06:54.897209282 -0700
+++ msft-4.14-rc3/drivers/hv/vmbus_drv.c	2017-10-03 10:07:35.505665159 -0700
@@ -948,6 +948,7 @@ static void vmbus_chan_sched(struct hv_p
 				continue;
 
 			++channel->interrupts_in;
+			trace_vmbus_chan_sched(channel);
 
 			switch (channel->callback_mode) {
 			case HV_CALL_ISR:

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

[Steven Rostedt]

On Mon, 2 Oct 2017 08:18:50 +0800
kbuild test robot <lkp@intel.com> wrote:

> Hi Vitaly,
> 
> [auto build test WARNING on linus/master]
> [also build test WARNING on v4.14-rc3 next-20170929]
> [if your patch is applied to the wrong git tree, please drop us a note to help improve the system]
> 
> url:    https://github.com/0day-ci/linux/commits/Vitaly-Kuznetsov/hyper-v-trace-vmbus_on_msg_dpc/20171002-062040
> config: i386-randconfig-x017-201740 (attached as .config)
> compiler: gcc-6 (Debian 6.2.0-3) 6.2.0 20160901
> reproduce:
>         # save the attached .config to linux build tree
>         make ARCH=i386 
> 
> All warnings (new ones prefixed by >>):
> 
>    In file included from include/trace/define_trace.h:95:0,
>                     from drivers/hv/hv_trace.h:29,
>                     from drivers/hv/hv_trace.c:4:
>    include/trace/trace_events.h:759:13: warning: 'print_fmt_vmbus_hdr_msg' defined but not used [-Wunused-variable]
>     static char print_fmt_##call[] = print;     \
>                 ^
> >> drivers/hv/./hv_trace.h:9:1: note: in expansion of macro 'DECLARE_EVENT_CLASS'  

Interesting. I'm wondering if this happens because the class "print" is
not used.

Actually, I think the default print should be used by one event, and
if other events need to be made that change the print, it should use
the DEFINE_EVENT_PRINT()

But this may be moot because I think Stephen Hemminger made it back to
DEFINE_EVENT()s.

-- Steve


>     DECLARE_EVENT_CLASS(vmbus_hdr_msg,
>     ^~~~~~~~~~~~~~~~~~~
>    In file included from include/trace/define_trace.h:95:0,
>                     from drivers/hv/hv_trace.h:29,
>                     from drivers/hv/hv_trace.c:4:
>    include/trace/trace_events.h:363:37: warning: 'trace_event_type_funcs_vmbus_hdr_msg' defined but not used [-Wunused-variable]
>     static struct trace_event_functions trace_event_type_funcs_##call = { \
>                                         ^
> >> drivers/hv/./hv_trace.h:9:1: note: in expansion of macro 'DECLARE_EVENT_CLASS'  
>     DECLARE_EVENT_CLASS(vmbus_hdr_msg,
>     ^~~~~~~~~~~~~~~~~~~
> 
> vim +/DECLARE_EVENT_CLASS +9 drivers/hv/./hv_trace.h
> 
>      8	
>    > 9	DECLARE_EVENT_CLASS(vmbus_hdr_msg,  
>     10		TP_PROTO(const struct vmbus_channel_message_header *hdr),
>     11		TP_ARGS(hdr),
>     12		TP_STRUCT__entry(__field(unsigned int, msgtype)),
>     13		TP_fast_assign(__entry->msgtype = hdr->msgtype;),
>     14		TP_printk("msgtype=%d", __entry->msgtype)
>     15	);
>     16	
> 
> ---
> 0-DAY kernel test infrastructure                Open Source Technology Center
> https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

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

[Vitaly Kuznetsov]

Stephen Hemminger <stephen@networkplumber.org> writes:

> I added an additional set of trace points for when channel gets notified or signals host.
>

Will add this in v3, thanks!

> diff -urNp linux-msft/drivers/hv/channel.c msft-4.14-rc3/drivers/hv/channel.c
> --- linux-msft/drivers/hv/channel.c	2017-10-03 10:06:54.893209237 -0700
> +++ msft-4.14-rc3/drivers/hv/channel.c	2017-10-03 10:07:35.501665114 -0700
> @@ -55,6 +55,8 @@ void vmbus_setevent(struct vmbus_channel
>  {
>  	struct hv_monitor_page *monitorpage;
>
> +	trace_vmbus_setevent(channel);
> +
>  	/*
>  	 * For channels marked as in "low latency" mode
>  	 * bypass the monitor page mechanism.
> diff -urNp linux-msft/drivers/hv/connection.c msft-4.14-rc3/drivers/hv/connection.c
> --- linux-msft/drivers/hv/connection.c	2017-10-03 10:06:54.893209237 -0700
> +++ msft-4.14-rc3/drivers/hv/connection.c	2017-10-03 10:07:35.501665114 -0700
> @@ -322,6 +322,8 @@ void vmbus_on_event(unsigned long data)
>  	struct vmbus_channel *channel = (void *) data;
>  	unsigned long time_limit = jiffies + 2;
>
> +	trace_vmbus_on_event(channel);
> +	
>  	do {
>  		void (*callback_fn)(void *);
>
> diff -urNp linux-msft/drivers/hv/hv_trace.h msft-4.14-rc3/drivers/hv/hv_trace.h
> --- linux-msft/drivers/hv/hv_trace.h	2017-10-03 10:08:06.514014019 -0700
> +++ msft-4.14-rc3/drivers/hv/hv_trace.h	2017-10-03 10:07:35.505665159 -0700
> @@ -294,6 +294,29 @@ TRACE_EVENT(vmbus_send_tl_connect_reques
>  		    )
>  	);
>
> +DECLARE_EVENT_CLASS(vmbus_channel,
> +	TP_PROTO(const struct vmbus_channel *channel),
> +	TP_ARGS(channel),
> +	TP_STRUCT__entry(__field(u32, relid)),
> +	TP_fast_assign(__entry->relid = channel->offermsg.child_relid),
> +	TP_printk("relid 0x%x", __entry->relid)
> +);
> +
> +DEFINE_EVENT(vmbus_channel, vmbus_chan_sched,
> +	    TP_PROTO(const struct vmbus_channel *channel),
> +	    TP_ARGS(channel)
> +);
> +
> +DEFINE_EVENT(vmbus_channel, vmbus_setevent,
> +	    TP_PROTO(const struct vmbus_channel *channel),
> +	    TP_ARGS(channel)
> +);
> +
> +DEFINE_EVENT(vmbus_channel, vmbus_on_event,
> +	    TP_PROTO(const struct vmbus_channel *channel),
> +	    TP_ARGS(channel)
> +);
> +
>  #undef TRACE_INCLUDE_PATH
>  #define TRACE_INCLUDE_PATH .
>  #undef TRACE_INCLUDE_FILE
> diff -urNp linux-msft/drivers/hv/vmbus_drv.c msft-4.14-rc3/drivers/hv/vmbus_drv.c
> --- linux-msft/drivers/hv/vmbus_drv.c	2017-10-03 10:06:54.897209282 -0700
> +++ msft-4.14-rc3/drivers/hv/vmbus_drv.c	2017-10-03 10:07:35.505665159 -0700
> @@ -948,6 +948,7 @@ static void vmbus_chan_sched(struct hv_p
>  				continue;
>
>  			++channel->interrupts_in;
> +			trace_vmbus_chan_sched(channel);
>
>  			switch (channel->callback_mode) {
>  			case HV_CALL_ISR:

-- 
  Vitaly