Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1735953 > unrolled thread
| Started by | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| First post | 2017-09-20 19:30 +0200 |
| Last post | 2017-09-20 19:30 +0200 |
| Articles | 6 — 1 participant |
Back to article view | Back to linux.kernel
[PATCH 00/16] Hyper-V: add tracing to VMBus module and trace all messages Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
[PATCH 03/16] hyper-v: trace vmbus_onoffer() Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
[PATCH 05/16] hyper-v: trace vmbus_onopen_result() Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
[PATCH 10/16] hyper-v: trace vmbus_open() Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
[PATCH 16/16] hyper-v: trace vmbus_send_tl_connect_request() Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
[PATCH 12/16] hyper-v: trace vmbus_establish_gpadl() Vitaly Kuznetsov <vkuznets@redhat.com> - 2017-09-20 19:30 +0200
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 00/16] Hyper-V: add tracing to VMBus module and trace all messages |
| Message-ID | <urQYV-63Y-3@gated-at.bofh.it> |
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
[toc] | [next] | [standalone]
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 03/16] hyper-v: trace vmbus_onoffer() |
| Message-ID | <urQYW-63Y-37@gated-at.bofh.it> |
| In reply to | #1735953 |
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
[toc] | [prev] | [next] | [standalone]
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 05/16] hyper-v: trace vmbus_onopen_result() |
| Message-ID | <urQYX-63Y-41@gated-at.bofh.it> |
| In reply to | #1735953 |
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
[toc] | [prev] | [next] | [standalone]
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 10/16] hyper-v: trace vmbus_open() |
| Message-ID | <urQYX-63Y-43@gated-at.bofh.it> |
| In reply to | #1735953 |
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
[toc] | [prev] | [next] | [standalone]
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 16/16] hyper-v: trace vmbus_send_tl_connect_request() |
| Message-ID | <urQYX-63Y-49@gated-at.bofh.it> |
| In reply to | #1735953 |
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
[toc] | [prev] | [next] | [standalone]
| From | Vitaly Kuznetsov <vkuznets@redhat.com> |
|---|---|
| Date | 2017-09-20 19:30 +0200 |
| Subject | [PATCH 12/16] hyper-v: trace vmbus_establish_gpadl() |
| Message-ID | <urQYX-63Y-51@gated-at.bofh.it> |
| In reply to | #1735953 |
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
[toc] | [prev] | [standalone]
Back to top | Article view | linux.kernel
csiph-web