hv_netvsc: add trace points

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>
Signed-off-by: David S. Miller <davem@davemloft.net>

diff --git a/drivers/net/hyperv/Makefile b/drivers/net/hyperv/Makefile
index c8a66827100cbb5460f07eba41ddee73346ab57a..3f25b9c8ea593c8d6e3f04170a52070488033d01 100644 (file)
--- 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 0265d703eb030515dacab7a83e84c169f89250dd..aa95e81af6e5784abfa0249634772be157d6344a 100644 (file)
--- 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 (file)
index 0000000..bb0ce5a
--- /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 (file)
index 0000000..f758556
--- /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 668680abaffb08111562c8f26f77e86fcd571278..2dc00f714482a70afb1a1d7aaa8a490614fe6b26 100644 (file)
--- 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,