From mboxrd@z Thu Jan  1 00:00:00 1970
Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S1752008AbdI2N0H (ORCPT <rfc822;w@1wt.eu>);
        Fri, 29 Sep 2017 09:26:07 -0400
Received: from mx1.redhat.com ([209.132.183.28]:45860 "EHLO mx1.redhat.com"
        rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP
        id S1750877AbdI2N0G (ORCPT <rfc822;linux-kernel@vger.kernel.org>);
        Fri, 29 Sep 2017 09:26:06 -0400
DMARC-Filter: OpenDMARC Filter v1.3.2 mx1.redhat.com 1CD64C04AC4A
Authentication-Results: ext-mx07.extmail.prod.ext.phx2.redhat.com; dmarc=none (p=none dis=none) header.from=redhat.com
Authentication-Results: ext-mx07.extmail.prod.ext.phx2.redhat.com; spf=fail smtp.mailfrom=vkuznets@redhat.com
From: Vitaly Kuznetsov <vkuznets@redhat.com>
To: devel@linuxdriverproject.org
Cc: linux-kernel@vger.kernel.org, "K. Y. Srinivasan" <kys@microsoft.com>,
        Haiyang Zhang <haiyangz@microsoft.com>,
        Stephen Hemminger <sthemmin@microsoft.com>,
        Steven Rostedt <rostedt@goodmis.org>, Dexuan Cui <decui@microsoft.com>
Subject: [PATCH v2 00/16] Hyper-V: add tracing to VMBus module and trace all messages
Date: Fri, 29 Sep 2017 15:25:46 +0200
Message-Id: <20170929132602.24487-1-vkuznets@redhat.com>
X-Greylist: Sender IP whitelisted, not delayed by milter-greylist-4.5.16 (mx1.redhat.com [10.5.110.31]); Fri, 29 Sep 2017 13:26:06 +0000 (UTC)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

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