* [PATCH net-next 2/2] hv_netvsc: add trace points
2018-03-16 22:44 [PATCH net-next 0/2] hv_netvsc: minor enhancements Stephen Hemminger
2018-03-16 22:44 ` [PATCH net-next 1/2] hv_netvsc: pass netvsc_device to rndis halt Stephen Hemminger
@ 2018-03-16 22:44 ` Stephen Hemminger
2018-03-18 0:10 ` [PATCH net-next 0/2] hv_netvsc: minor enhancements David Miller
2 siblings, 0 replies; 4+ messages in thread
From: Stephen Hemminger @ 2018-03-16 22:44 UTC (permalink / raw)
To: kys, haiyangz, sthemmin; +Cc: devel, netdev
This adds tracepoints to the driver which has proved useful in
debugging startup and shutdown race conditions.
Signed-off-by: Stephen Hemminger <sthemmin@microsoft.com>
---
Note: the standard indentation style of trace files send checkpatch off
into a tantrum. Ignore warnings from that.
drivers/net/hyperv/Makefile | 2 +-
drivers/net/hyperv/netvsc.c | 26 +++++-
drivers/net/hyperv/netvsc_trace.c | 7 ++
drivers/net/hyperv/netvsc_trace.h | 182 ++++++++++++++++++++++++++++++++++++++
drivers/net/hyperv/rndis_filter.c | 5 ++
5 files changed, 220 insertions(+), 2 deletions(-)
create mode 100644 drivers/net/hyperv/netvsc_trace.c
create mode 100644 drivers/net/hyperv/netvsc_trace.h
diff --git a/drivers/net/hyperv/Makefile b/drivers/net/hyperv/Makefile
index c8a66827100c..3f25b9c8ea59 100644
--- a/drivers/net/hyperv/Makefile
+++ b/drivers/net/hyperv/Makefile
@@ -1,3 +1,3 @@
obj-$(CONFIG_HYPERV_NET) += hv_netvsc.o
-hv_netvsc-y := netvsc_drv.o netvsc.o rndis_filter.o
+hv_netvsc-y := netvsc_drv.o netvsc.o rndis_filter.o netvsc_trace.o
diff --git a/drivers/net/hyperv/netvsc.c b/drivers/net/hyperv/netvsc.c
index 0265d703eb03..aa95e81af6e5 100644
--- a/drivers/net/hyperv/netvsc.c
+++ b/drivers/net/hyperv/netvsc.c
@@ -36,6 +36,7 @@
#include <asm/sync_bitops.h>
#include "hyperv_net.h"
+#include "netvsc_trace.h"
/*
* Switch the data path from the synthetic interface to the VF
@@ -57,6 +58,8 @@ void netvsc_switch_datapath(struct net_device *ndev, bool vf)
init_pkt->msg.v4_msg.active_dp.active_datapath =
NVSP_DATAPATH_SYNTHETIC;
+ trace_nvsp_send(ndev, init_pkt);
+
vmbus_sendpacket(dev->channel, init_pkt,
sizeof(struct nvsp_message),
(unsigned long)init_pkt,
@@ -124,6 +127,8 @@ static void netvsc_revoke_buf(struct hv_device *device,
revoke_packet->msg.v1_msg.
revoke_recv_buf.id = NETVSC_RECEIVE_BUFFER_ID;
+ trace_nvsp_send(ndev, revoke_packet);
+
ret = vmbus_sendpacket(device->channel,
revoke_packet,
sizeof(struct nvsp_message),
@@ -164,6 +169,8 @@ static void netvsc_revoke_buf(struct hv_device *device,
revoke_packet->msg.v1_msg.revoke_send_buf.id =
NETVSC_SEND_BUFFER_ID;
+ trace_nvsp_send(ndev, revoke_packet);
+
ret = vmbus_sendpacket(device->channel,
revoke_packet,
sizeof(struct nvsp_message),
@@ -305,6 +312,8 @@ static int netvsc_init_buf(struct hv_device *device,
init_packet->msg.v1_msg.
send_recv_buf.id = NETVSC_RECEIVE_BUFFER_ID;
+ trace_nvsp_send(ndev, init_packet);
+
/* Send the gpadl notification request */
ret = vmbus_sendpacket(device->channel, init_packet,
sizeof(struct nvsp_message),
@@ -384,6 +393,8 @@ static int netvsc_init_buf(struct hv_device *device,
net_device->send_buf_gpadl_handle;
init_packet->msg.v1_msg.send_send_buf.id = NETVSC_SEND_BUFFER_ID;
+ trace_nvsp_send(ndev, init_packet);
+
/* Send the gpadl notification request */
ret = vmbus_sendpacket(device->channel, init_packet,
sizeof(struct nvsp_message),
@@ -452,6 +463,8 @@ static int negotiate_nvsp_ver(struct hv_device *device,
init_packet->msg.init_msg.init.min_protocol_ver = nvsp_ver;
init_packet->msg.init_msg.init.max_protocol_ver = nvsp_ver;
+ trace_nvsp_send(ndev, init_packet);
+
/* Send the init request */
ret = vmbus_sendpacket(device->channel, init_packet,
sizeof(struct nvsp_message),
@@ -484,6 +497,8 @@ static int negotiate_nvsp_ver(struct hv_device *device,
init_packet->msg.v2_msg.send_ndis_config.capability.teaming = 1;
}
+ trace_nvsp_send(ndev, init_packet);
+
ret = vmbus_sendpacket(device->channel, init_packet,
sizeof(struct nvsp_message),
(unsigned long)init_packet,
@@ -496,6 +511,7 @@ static int netvsc_connect_vsp(struct hv_device *device,
struct netvsc_device *net_device,
const struct netvsc_device_info *device_info)
{
+ struct net_device *ndev = hv_get_drvdata(device);
static const u32 ver_list[] = {
NVSP_PROTOCOL_VERSION_1, NVSP_PROTOCOL_VERSION_2,
NVSP_PROTOCOL_VERSION_4, NVSP_PROTOCOL_VERSION_5
@@ -536,6 +552,8 @@ static int netvsc_connect_vsp(struct hv_device *device,
send_ndis_ver.ndis_minor_ver =
ndis_version & 0xFFFF;
+ trace_nvsp_send(ndev, init_packet);
+
/* Send the init request */
ret = vmbus_sendpacket(device->channel, init_packet,
sizeof(struct nvsp_message),
@@ -747,7 +765,7 @@ static inline int netvsc_send_pkt(
struct sk_buff *skb)
{
struct nvsp_message nvmsg;
- struct nvsp_1_message_send_rndis_packet * const rpkt =
+ struct nvsp_1_message_send_rndis_packet *rpkt =
&nvmsg.msg.v1_msg.send_rndis_pkt;
struct netvsc_channel * const nvchan =
&net_device->chan_table[packet->q_idx];
@@ -776,6 +794,8 @@ static inline int netvsc_send_pkt(
if (out_channel->rescind)
return -ENODEV;
+ trace_nvsp_send_pkt(ndev, out_channel, rpkt);
+
if (packet->page_buf_cnt) {
if (packet->cp_partial)
pb += packet->rmsg_pgcnt;
@@ -1079,6 +1099,8 @@ static int netvsc_receive(struct net_device *ndev,
+ vmxferpage_packet->ranges[i].byte_offset;
u32 buflen = vmxferpage_packet->ranges[i].byte_count;
+ trace_rndis_recv(ndev, q_idx, data);
+
/* Pass it to the upper layer */
status = rndis_filter_receive(ndev, net_device,
channel, data, buflen);
@@ -1143,6 +1165,8 @@ static int netvsc_process_raw_pkt(struct hv_device *device,
struct net_device_context *net_device_ctx = netdev_priv(ndev);
struct nvsp_message *nvmsg = hv_pkt_data(desc);
+ trace_nvsp_recv(ndev, channel, nvmsg);
+
switch (desc->type) {
case VM_PKT_COMP:
netvsc_send_completion(net_device, channel, device,
diff --git a/drivers/net/hyperv/netvsc_trace.c b/drivers/net/hyperv/netvsc_trace.c
new file mode 100644
index 000000000000..bb0ce5a2bcd5
--- /dev/null
+++ b/drivers/net/hyperv/netvsc_trace.c
@@ -0,0 +1,7 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#include <linux/netdevice.h>
+
+#include "hyperv_net.h"
+
+#define CREATE_TRACE_POINTS
+#include "netvsc_trace.h"
diff --git a/drivers/net/hyperv/netvsc_trace.h b/drivers/net/hyperv/netvsc_trace.h
new file mode 100644
index 000000000000..f7585563dea5
--- /dev/null
+++ b/drivers/net/hyperv/netvsc_trace.h
@@ -0,0 +1,182 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+
+#if !defined(_NETVSC_TRACE_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _NETVSC_TRACE_H
+
+#include <linux/tracepoint.h>
+
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM netvsc
+#define TRACE_INCLUDE_FILE netvsc_trace
+
+TRACE_DEFINE_ENUM(RNDIS_MSG_PACKET);
+TRACE_DEFINE_ENUM(RNDIS_MSG_INDICATE);
+TRACE_DEFINE_ENUM(RNDIS_MSG_INIT);
+TRACE_DEFINE_ENUM(RNDIS_MSG_INIT_C);
+TRACE_DEFINE_ENUM(RNDIS_MSG_HALT);
+TRACE_DEFINE_ENUM(RNDIS_MSG_QUERY);
+TRACE_DEFINE_ENUM(RNDIS_MSG_QUERY_C);
+TRACE_DEFINE_ENUM(RNDIS_MSG_SET);
+TRACE_DEFINE_ENUM(RNDIS_MSG_SET_C);
+TRACE_DEFINE_ENUM(RNDIS_MSG_RESET);
+TRACE_DEFINE_ENUM(RNDIS_MSG_RESET_C);
+TRACE_DEFINE_ENUM(RNDIS_MSG_KEEPALIVE);
+TRACE_DEFINE_ENUM(RNDIS_MSG_KEEPALIVE_C);
+
+#define show_rndis_type(type) \
+ __print_symbolic(type, \
+ { RNDIS_MSG_PACKET, "PACKET" }, \
+ { RNDIS_MSG_INDICATE, "INDICATE", }, \
+ { RNDIS_MSG_INIT, "INIT", }, \
+ { RNDIS_MSG_INIT_C, "INIT_C", }, \
+ { RNDIS_MSG_HALT, "HALT", }, \
+ { RNDIS_MSG_QUERY, "QUERY", }, \
+ { RNDIS_MSG_QUERY_C, "QUERY_C", }, \
+ { RNDIS_MSG_SET, "SET", }, \
+ { RNDIS_MSG_SET_C, "SET_C", }, \
+ { RNDIS_MSG_RESET, "RESET", }, \
+ { RNDIS_MSG_RESET_C, "RESET_C", }, \
+ { RNDIS_MSG_KEEPALIVE, "KEEPALIVE", }, \
+ { RNDIS_MSG_KEEPALIVE_C, "KEEPALIVE_C", })
+
+DECLARE_EVENT_CLASS(rndis_msg_class,
+ TP_PROTO(const struct net_device *ndev, u16 q,
+ const struct rndis_message *msg),
+ TP_ARGS(ndev, q, msg),
+ TP_STRUCT__entry(
+ __string( name, ndev->name )
+ __field( u16, queue )
+ __field( u32, req_id )
+ __field( u32, msg_type )
+ __field( u32, msg_len )
+ ),
+ TP_fast_assign(
+ __assign_str(name, ndev->name);
+ __entry->queue = q;
+ __entry->req_id = msg->msg.init_req.req_id;
+ __entry->msg_type = msg->ndis_msg_type;
+ __entry->msg_len = msg->msg_len;
+ ),
+ TP_printk("dev=%s q=%u req=%#x type=%s msg_len=%u",
+ __get_str(name), __entry->queue, __entry->req_id,
+ show_rndis_type(__entry->msg_type), __entry->msg_len)
+);
+
+DEFINE_EVENT(rndis_msg_class, rndis_send,
+ TP_PROTO(const struct net_device *ndev, u16 q,
+ const struct rndis_message *msg),
+ TP_ARGS(ndev, q, msg)
+);
+
+DEFINE_EVENT(rndis_msg_class, rndis_recv,
+ TP_PROTO(const struct net_device *ndev, u16 q,
+ const struct rndis_message *msg),
+ TP_ARGS(ndev, q, msg)
+);
+
+TRACE_DEFINE_ENUM(NVSP_MSG_TYPE_INIT);
+TRACE_DEFINE_ENUM(NVSP_MSG_TYPE_INIT_COMPLETE);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_NDIS_VER);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_RECV_BUF);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_RECV_BUF_COMPLETE);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_REVOKE_RECV_BUF);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_SEND_BUF);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_SEND_BUF_COMPLETE);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_REVOKE_SEND_BUF);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_RNDIS_PKT);
+TRACE_DEFINE_ENUM(NVSP_MSG1_TYPE_SEND_RNDIS_PKT_COMPLETE);
+TRACE_DEFINE_ENUM(NVSP_MSG2_TYPE_SEND_NDIS_CONFIG);
+
+TRACE_DEFINE_ENUM(NVSP_MSG4_TYPE_SEND_VF_ASSOCIATION);
+TRACE_DEFINE_ENUM(NVSP_MSG4_TYPE_SWITCH_DATA_PATH);
+
+TRACE_DEFINE_ENUM(NVSP_MSG5_TYPE_SUBCHANNEL);
+TRACE_DEFINE_ENUM(NVSP_MSG5_TYPE_SEND_INDIRECTION_TABLE);
+
+#define show_nvsp_type(type) \
+ __print_symbolic(type, \
+ { NVSP_MSG_TYPE_INIT, "INIT" }, \
+ { NVSP_MSG_TYPE_INIT_COMPLETE, "INIT_COMPLETE" }, \
+ { NVSP_MSG1_TYPE_SEND_NDIS_VER, "SEND_NDIS_VER" }, \
+ { NVSP_MSG1_TYPE_SEND_RECV_BUF, "SEND_RECV_BUF" }, \
+ { NVSP_MSG1_TYPE_SEND_RECV_BUF_COMPLETE, "SEND_RECV_BUF_COMPLETE" }, \
+ { NVSP_MSG1_TYPE_REVOKE_RECV_BUF, "REVOKE_RECV_BUF" }, \
+ { NVSP_MSG1_TYPE_SEND_SEND_BUF, "SEND_SEND_BUF" }, \
+ { NVSP_MSG1_TYPE_SEND_SEND_BUF_COMPLETE, "SEND_SEND_BUF_COMPLETE" }, \
+ { NVSP_MSG1_TYPE_REVOKE_SEND_BUF, "REVOKE_SEND_BUF" }, \
+ { NVSP_MSG1_TYPE_SEND_RNDIS_PKT, "SEND_RNDIS_PKT" }, \
+ { NVSP_MSG1_TYPE_SEND_RNDIS_PKT_COMPLETE, "SEND_RNDIS_PKT_COMPLETE" },\
+ { NVSP_MSG2_TYPE_SEND_NDIS_CONFIG, "SEND_NDIS_CONFIG" }, \
+ { NVSP_MSG4_TYPE_SEND_VF_ASSOCIATION, "SEND_VF_ASSOCIATION" }, \
+ { NVSP_MSG4_TYPE_SWITCH_DATA_PATH, "SWITCH_DATA_PATH" }, \
+ { NVSP_MSG5_TYPE_SUBCHANNEL, "SUBCHANNEL" }, \
+ { NVSP_MSG5_TYPE_SEND_INDIRECTION_TABLE, "SEND_INDIRECTION_TABLE" })
+
+TRACE_EVENT(nvsp_send,
+ TP_PROTO(const struct net_device *ndev,
+ const struct nvsp_message *msg),
+ TP_ARGS(ndev, msg),
+ TP_STRUCT__entry(
+ __string( name, ndev->name )
+ __field( u32, msg_type )
+ ),
+ TP_fast_assign(
+ __assign_str(name, ndev->name);
+ __entry->msg_type = msg->hdr.msg_type;
+ ),
+ TP_printk("dev=%s type=%s",
+ __get_str(name),
+ show_nvsp_type(__entry->msg_type))
+);
+
+TRACE_EVENT(nvsp_send_pkt,
+ TP_PROTO(const struct net_device *ndev,
+ const struct vmbus_channel *chan,
+ const struct nvsp_1_message_send_rndis_packet *rpkt),
+ TP_ARGS(ndev, chan, rpkt),
+ TP_STRUCT__entry(
+ __string( name, ndev->name )
+ __field( u16, qid )
+ __field( u32, channel_type )
+ __field( u32, section_index )
+ __field( u32, section_size )
+ ),
+ TP_fast_assign(
+ __assign_str(name, ndev->name);
+ __entry->qid = chan->offermsg.offer.sub_channel_index;
+ __entry->channel_type = rpkt->channel_type;
+ __entry->section_index = rpkt->send_buf_section_index;
+ __entry->section_size = rpkt->send_buf_section_size;
+ ),
+ TP_printk("dev=%s qid=%u type=%s section=%u size=%d",
+ __get_str(name), __entry->qid,
+ __entry->channel_type ? "CONTROL" : "DATA",
+ __entry->section_index, __entry->section_size)
+);
+
+TRACE_EVENT(nvsp_recv,
+ TP_PROTO(const struct net_device *ndev,
+ const struct vmbus_channel *chan,
+ const struct nvsp_message *msg),
+ TP_ARGS(ndev, chan, msg),
+ TP_STRUCT__entry(
+ __string( name, ndev->name )
+ __field( u16, qid )
+ __field( u32, msg_type )
+ ),
+ TP_fast_assign(
+ __assign_str(name, ndev->name);
+ __entry->qid = chan->offermsg.offer.sub_channel_index;
+ __entry->msg_type = msg->hdr.msg_type;
+ ),
+ TP_printk("dev=%s qid=%u type=%s",
+ __get_str(name), __entry->qid,
+ show_nvsp_type(__entry->msg_type))
+);
+
+#endif /* _NETVSC_TRACE_H */
+
+/* This part must be outside protection */
+#undef TRACE_INCLUDE_PATH
+#define TRACE_INCLUDE_PATH ../../drivers/net/hyperv
+#include <trace/define_trace.h>
diff --git a/drivers/net/hyperv/rndis_filter.c b/drivers/net/hyperv/rndis_filter.c
index 668680abaffb..2dc00f714482 100644
--- a/drivers/net/hyperv/rndis_filter.c
+++ b/drivers/net/hyperv/rndis_filter.c
@@ -31,6 +31,7 @@
#include <linux/rtnetlink.h>
#include "hyperv_net.h"
+#include "netvsc_trace.h"
static void rndis_set_multicast(struct work_struct *w);
@@ -241,6 +242,8 @@ static int rndis_filter_send_request(struct rndis_device *dev,
pb[0].len;
}
+ trace_rndis_send(dev->ndev, 0, &req->request_msg);
+
rcu_read_lock_bh();
ret = netvsc_send(dev->ndev, packet, NULL, pb, NULL);
rcu_read_unlock_bh();
@@ -1087,6 +1090,8 @@ void rndis_set_subchannel(struct work_struct *w)
init_packet->msg.v5_msg.subchn_req.op = NVSP_SUBCHANNEL_ALLOCATE;
init_packet->msg.v5_msg.subchn_req.num_subchannels =
nvdev->num_chn - 1;
+ trace_nvsp_send(ndev, init_packet);
+
ret = vmbus_sendpacket(hv_dev->channel, init_packet,
sizeof(struct nvsp_message),
(unsigned long)init_packet,
--
2.16.2
^ permalink raw reply related [flat|nested] 4+ messages in thread