xen-devel.lists.xenproject.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v3 0/2] xentrace: Add TRC_HVM_EMUL (was xentrace: Add TRC_HW_VCHIP or TRC_HVM_VCHIP).
@ 2014-04-07 22:38 Don Slutz
  2014-04-07 22:38 ` [PATCH v3 1/2] Add emacs local variables to all files changed Don Slutz
  2014-04-07 22:38 ` [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL Don Slutz
  0 siblings, 2 replies; 9+ messages in thread
From: Don Slutz @ 2014-04-07 22:38 UTC (permalink / raw)
  To: xen-devel, Jan Beulich, Tim Deegan
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, George Dunlap,
	Ian Jackson, Don Slutz

Changes v2 to v3:
  Tim Deegan:
    #2 "xentrace: Add TRC_HVM_EMUL":
       Reviewed-by
  George Dunlap:
    #1 "Add emacs local variables to all files changed":
       Drop xentrace from subject.
    #2 "xentrace: Add TRC_HVM_EMUL":
        Use TRC_HVM_EMUL instead of TRC_HVM_VCHIP.
        Handle 64 bit correctly.

Note: xentrace_format only supports 64bit output in hex.

Changes v1 to v2:
  Tim Deegan:
    Switch from TRC_HW_VCHIP to TRC_HVM_VCHIP.
    Drop get_cycles()
    Fix coding style issues.
    Drop code that should not have been included.
    Use names not numbers.

Split in 2 patches for simpler review.

Here is a subset of sample output:

CPU3  16608354366030 (+    4152)  pit create [ delta = 0x0000000003461859, period = 0x0000000003461859 ]
CPU6  16640926832754 (+    4464)  hpet create [ tn = 0, irq = 0, delta = 0x00000000000cd150, period = 0x00000000000f4240 ]
CPU5  16642822511400 (+   16458)  vlapic create [ delta = 0x00000009ffffff60 , period = 0x00000009ffffff60, irq = 239 ]
CPU7  16643253002928 (+   16920)  vlapic create [ delta = 0x0000009fffffff60 , period = 0x0000009fffffff60, irq = 239 ]
CPU7  16643253077976 (+   16410)  vlapic create [ delta = 0x00000000000f41a0 , period = 0x00000000000f41a0, irq = 239 ]
CPU0  16643576192019 (+   10665)  vlapic create [ delta = 0x00000013ffffffec , period = 0x0000000000000000, irq = 239 ]
CPU0  16643576242947 (+   10443)  vlapic create [ delta = 0x00000000000f41a0 , period = 0x00000000000f41a0, irq = 239 ]
CPU1  16646772521592 (+   23130)  vlapic create [ delta = 0x000000000005b720 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646772577374 (+   22674)  vlapic create [ delta = 0x0000000000055b40 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646772651612 (+   17190)  vlapic create [ delta = 0x000000004ffffec0 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646772694074 (+   16980)  vlapic create [ delta = 0x000000004ffffec0 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646871198096 (+   36381)  vlapic create [ delta = 0x0000000000039bc0 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646872042662 (+   18360)  vlapic create [ delta = 0x00000000000d6380 , period = 0x0000000000000000, irq = 239 ]
CPU1  16646874292818 (+   19128)  vlapic create [ delta = 0x00000000000e5b00 , period = 0x0000000000000000, irq = 239 ]
CPU6  16646772412644 (+    1710)  hpet create [ tn = 0, irq = 0, delta = 0x0000000ff88fd980, period = 0x0000000000000000 ]
CPU6  16646772522486 (+   23322)  vlapic create [ delta = 0x000000000005a640 , period = 0x0000000000000000, irq = 239 ]
CPU6  16646772578898 (+   23154)  vlapic create [ delta = 0x0000000000054a60 , period = 0x0000000000000000, irq = 239 ]
CPU6  16646773660782 (+   18258)  vlapic create [ delta = 0x00000000000da480 , period = 0x0000000000000000, irq = 239 ]
CPU6  16646776073694 (+   17796)  vlapic create [ delta = 0x00000000000d8e00 , period = 0x0000000000000000, irq = 239 ]
CPU6  16646778473160 (+   17760)  vlapic create [ delta = 0x00000000000d8f40 , period = 0x0000000000000000, irq = 239 ]

Don Slutz (2):
  Add emacs local variables to all files changed.
  xentrace: Add TRC_HVM_EMUL

 tools/xentrace/formats          | 18 ++++++++++++++++++
 xen/arch/x86/hvm/hpet.c         | 16 ++++++++++++++++
 xen/arch/x86/hvm/i8254.c        | 18 ++++++++++++++++++
 xen/arch/x86/hvm/rtc.c          | 18 ++++++++++++++++++
 xen/arch/x86/hvm/vlapic.c       | 28 ++++++++++++++++++++++++++++
 xen/arch/x86/hvm/vpic.c         | 20 ++++++++++++++++++++
 xen/include/asm-x86/hvm/trace.h |  7 +++++++
 xen/include/public/trace.h      | 24 ++++++++++++++++++++++--
 8 files changed, 147 insertions(+), 2 deletions(-)

-- 
1.8.4

^ permalink raw reply	[flat|nested] 9+ messages in thread

* [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-07 22:38 [PATCH v3 0/2] xentrace: Add TRC_HVM_EMUL (was xentrace: Add TRC_HW_VCHIP or TRC_HVM_VCHIP) Don Slutz
@ 2014-04-07 22:38 ` Don Slutz
  2014-04-08  9:36   ` Jan Beulich
  2014-04-07 22:38 ` [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL Don Slutz
  1 sibling, 1 reply; 9+ messages in thread
From: Don Slutz @ 2014-04-07 22:38 UTC (permalink / raw)
  To: xen-devel, Jan Beulich, Tim Deegan
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, George Dunlap,
	Ian Jackson, Don Slutz

This is per CODING_STYLE.

Signed-off-by: Don Slutz <dslutz@verizon.com>
---
v3:
    Drop xentrace from subject.

 xen/arch/x86/hvm/hpet.c   | 9 +++++++++
 xen/arch/x86/hvm/i8254.c  | 9 +++++++++
 xen/arch/x86/hvm/rtc.c    | 9 +++++++++
 xen/arch/x86/hvm/vlapic.c | 9 +++++++++
 xen/arch/x86/hvm/vpic.c   | 9 +++++++++
 5 files changed, 45 insertions(+)

diff --git a/xen/arch/x86/hvm/hpet.c b/xen/arch/x86/hvm/hpet.c
index 4324b52..e1e769a 100644
--- a/xen/arch/x86/hvm/hpet.c
+++ b/xen/arch/x86/hvm/hpet.c
@@ -622,3 +622,12 @@ void hpet_reset(struct domain *d)
     hpet_deinit(d);
     hpet_init(d->vcpu[0]);
 }
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
diff --git a/xen/arch/x86/hvm/i8254.c b/xen/arch/x86/hvm/i8254.c
index f7493b8..6e66b49 100644
--- a/xen/arch/x86/hvm/i8254.c
+++ b/xen/arch/x86/hvm/i8254.c
@@ -556,3 +556,12 @@ int pv_pit_handler(int port, int data, int write)
 
     return !write ? ioreq.data : 0;
 }
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
diff --git a/xen/arch/x86/hvm/rtc.c b/xen/arch/x86/hvm/rtc.c
index 639b4c5..7cd0cf4 100644
--- a/xen/arch/x86/hvm/rtc.c
+++ b/xen/arch/x86/hvm/rtc.c
@@ -827,3 +827,12 @@ void rtc_update_clock(struct domain *d)
     s->current_tm = gmtime(get_localtime(d));
     spin_unlock(&s->lock);
 }
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
diff --git a/xen/arch/x86/hvm/vlapic.c b/xen/arch/x86/hvm/vlapic.c
index bc06010..fc307c0 100644
--- a/xen/arch/x86/hvm/vlapic.c
+++ b/xen/arch/x86/hvm/vlapic.c
@@ -1279,3 +1279,12 @@ void vlapic_destroy(struct vcpu *v)
     unmap_domain_page_global(vlapic->regs);
     free_domheap_page(vlapic->regs_page);
 }
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
diff --git a/xen/arch/x86/hvm/vpic.c b/xen/arch/x86/hvm/vpic.c
index fea3f68..5ca513c 100644
--- a/xen/arch/x86/hvm/vpic.c
+++ b/xen/arch/x86/hvm/vpic.c
@@ -473,3 +473,12 @@ int vpic_ack_pending_irq(struct vcpu *v)
     vector = vpic[irq >> 3].irq_base + (irq & 7);
     return vector;
 }
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
-- 
1.8.4

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL
  2014-04-07 22:38 [PATCH v3 0/2] xentrace: Add TRC_HVM_EMUL (was xentrace: Add TRC_HW_VCHIP or TRC_HVM_VCHIP) Don Slutz
  2014-04-07 22:38 ` [PATCH v3 1/2] Add emacs local variables to all files changed Don Slutz
@ 2014-04-07 22:38 ` Don Slutz
  2014-04-08  9:53   ` George Dunlap
  1 sibling, 1 reply; 9+ messages in thread
From: Don Slutz @ 2014-04-07 22:38 UTC (permalink / raw)
  To: xen-devel, Jan Beulich, Tim Deegan
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, George Dunlap,
	Ian Jackson, Don Slutz

This add a set of trace events that track the setup of various
emulated devices related to timers in domU.

This set is hpet, pit (i8253, i8254), rtc (MC146818), apic (lapic),
and pic (i8259).  The pmtimer is not traced since it does not have a
changeable rate.

Signed-off-by: Don Slutz <dslutz@verizon.com>
Reviewed-by: Tim Deegan <tim@xen.org>
---
v3:
  Use TRC_HVM_EMUL instead of TRC_HVM_VCHIP.
  Handle 64 bit correctly.

Note: xentrace_format only supports 64bit output in hex.

 tools/xentrace/formats          | 18 ++++++++++++++++++
 xen/arch/x86/hvm/hpet.c         |  7 +++++++
 xen/arch/x86/hvm/i8254.c        |  9 +++++++++
 xen/arch/x86/hvm/rtc.c          |  9 +++++++++
 xen/arch/x86/hvm/vlapic.c       | 19 +++++++++++++++++++
 xen/arch/x86/hvm/vpic.c         | 11 +++++++++++
 xen/include/asm-x86/hvm/trace.h |  7 +++++++
 xen/include/public/trace.h      | 24 ++++++++++++++++++++++--
 8 files changed, 102 insertions(+), 2 deletions(-)

diff --git a/tools/xentrace/formats b/tools/xentrace/formats
index 67fd42d..da658bf 100644
--- a/tools/xentrace/formats
+++ b/tools/xentrace/formats
@@ -152,3 +152,21 @@
 0x00802006  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  assign_vector [ irq = %(1)d = vector 0x%(2)x, CPU mask: 0x%(3)08x ]
 0x00802007  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  bogus_vector [ 0x%(1)x ]
 0x00802008  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  do_irq [ irq = %(1)d, began = %(2)dus, ended = %(3)dus ]
+
+0x00084001  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  hpet create [ tn = %(1)d, irq = %(2)d, delta = 0x%(4)08x%(3)08x, period = 0x%(6)08x%(5)08x ]
+0x00084002  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit create [ delta = 0x%(1)016x, period = 0x%(2)016x ]
+0x00084003  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtc create [ delta = 0x%(1)016x , period = 0x%(2)016x ]
+0x00084004  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic create [ delta = 0x%(2)08x%(1)08x , period = 0x%(4)08x%(3)08x, irq = %(5)d ]
+0x00084005  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  hpet destroy [ tn = %(1)d ]
+0x00084006  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit destroy  [ ]
+0x00084007  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtc destroy [ ]
+0x00084008  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic destroy [ ]
+0x00084009  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit callback [ ]
+0x0008400a  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic callback [ ]
+0x0008400b  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_update_int_output [ int_output = %(1)d, is_master = %(2)d, irq = %(3)d ]
+0x0008400c  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic vcpu_kick [ irq = %(1)d ]
+0x0008400d  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  __vpic_intack [ is_master = %(1)d, irq = %(2)d ]
+0x0008400e  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_irq_positive_edge [ irq = %(1)d ]
+0x0008400f  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_irq_negative_edge [ irq = %(1)d ]
+0x00084010  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_ack_pending_irq [ accept_pic_intr = %(1)d, int_output = %(2)d ]
+0x00084011  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic_accept_pic_intr [ i8259_target = %(1)d, accept_pic_int = %(2)d ]
diff --git a/xen/arch/x86/hvm/hpet.c b/xen/arch/x86/hvm/hpet.c
index e1e769a..42c93f3 100644
--- a/xen/arch/x86/hvm/hpet.c
+++ b/xen/arch/x86/hvm/hpet.c
@@ -20,10 +20,12 @@
 #include <asm/hvm/vpt.h>
 #include <asm/hvm/io.h>
 #include <asm/hvm/support.h>
+#include <asm/hvm/trace.h>
 #include <asm/current.h>
 #include <asm/hpet.h>
 #include <xen/sched.h>
 #include <xen/event.h>
+#include <xen/trace.h>
 
 #define domain_vhpet(x) (&(x)->arch.hvm_domain.pl_time.vhpet)
 #define vcpu_vhpet(x)   (domain_vhpet((x)->domain))
@@ -191,6 +193,7 @@ static void hpet_stop_timer(HPETState *h, unsigned int tn)
 {
     ASSERT(tn < HPET_TIMER_NUM);
     ASSERT(spin_is_locked(&h->lock));
+    TRACE_1D(TRC_HVM_EMUL_HPET_STOP_TIMER, tn);
     destroy_periodic_time(&h->pt[tn]);
     /* read the comparator to get it updated so a read while stopped will
      * return the expected value. */
@@ -255,6 +258,10 @@ static void hpet_set_timer(HPETState *h, unsigned int tn)
      * being enabled (now).
      */
     oneshot = !timer_is_periodic(h, tn);
+    TRACE_2_LONG_4D(TRC_HVM_EMUL_HPET_START_TIMER, tn, irq,
+                    TRC_PAR_LONG(hpet_tick_to_ns(h, diff)),
+                    TRC_PAR_LONG(oneshot ? 0LL :
+                                 hpet_tick_to_ns(h, h->hpet.period[tn])));
     create_periodic_time(vhpet_vcpu(h), &h->pt[tn],
                          hpet_tick_to_ns(h, diff),
                          oneshot ? 0 : hpet_tick_to_ns(h, h->hpet.period[tn]),
diff --git a/xen/arch/x86/hvm/i8254.c b/xen/arch/x86/hvm/i8254.c
index 6e66b49..c4f7527 100644
--- a/xen/arch/x86/hvm/i8254.c
+++ b/xen/arch/x86/hvm/i8254.c
@@ -31,6 +31,7 @@
 #include <xen/lib.h>
 #include <xen/errno.h>
 #include <xen/sched.h>
+#include <xen/trace.h>
 #include <asm/time.h>
 #include <asm/hvm/hvm.h>
 #include <asm/hvm/io.h>
@@ -159,6 +160,7 @@ static int pit_get_gate(PITState *pit, int channel)
 static void pit_time_fired(struct vcpu *v, void *priv)
 {
     uint64_t *count_load_time = priv;
+    TRACE_0D(TRC_HVM_EMUL_PIT_TIMER_CB);
     *count_load_time = get_guest_time(v);
 }
 
@@ -188,16 +190,19 @@ static void pit_load_count(PITState *pit, int channel, int val)
     case 2:
     case 3:
         /* Periodic timer. */
+        TRACE_2D(TRC_HVM_EMUL_PIT_START_TIMER, period, period);
         create_periodic_time(v, &pit->pt0, period, period, 0, pit_time_fired, 
                              &pit->count_load_time[channel]);
         break;
     case 1:
     case 4:
         /* One-shot timer. */
+        TRACE_2D(TRC_HVM_EMUL_PIT_START_TIMER, period, 0);
         create_periodic_time(v, &pit->pt0, period, 0, 0, pit_time_fired,
                              &pit->count_load_time[channel]);
         break;
     default:
+        TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
         destroy_periodic_time(&pit->pt0);
         break;
     }
@@ -377,6 +382,7 @@ static uint32_t pit_ioport_read(struct PITState *pit, uint32_t addr)
 
 void pit_stop_channel0_irq(PITState *pit)
 {
+    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
     spin_lock(&pit->lock);
     destroy_periodic_time(&pit->pt0);
     spin_unlock(&pit->lock);
@@ -431,6 +437,7 @@ void pit_reset(struct domain *d)
     struct hvm_hw_pit_channel *s;
     int i;
 
+    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
     destroy_periodic_time(&pit->pt0);
     pit->pt0.source = PTSRC_isa;
 
@@ -465,6 +472,8 @@ void pit_init(struct domain *d, unsigned long cpu_khz)
 void pit_deinit(struct domain *d)
 {
     PITState *pit = domain_vpit(d);
+
+    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
     destroy_periodic_time(&pit->pt0);
 }
 
diff --git a/xen/arch/x86/hvm/rtc.c b/xen/arch/x86/hvm/rtc.c
index 7cd0cf4..3fab660 100644
--- a/xen/arch/x86/hvm/rtc.c
+++ b/xen/arch/x86/hvm/rtc.c
@@ -27,6 +27,7 @@
 #include <asm/hvm/io.h>
 #include <asm/hvm/support.h>
 #include <asm/current.h>
+#include <xen/trace.h>
 
 #define USEC_PER_SEC    1000000UL
 #define NS_PER_USEC     1000UL
@@ -91,6 +92,7 @@ static void rtc_pf_callback(struct vcpu *v, void *opaque)
          && ++(s->pt_dead_ticks) >= 10 )
     {
         /* VM is ignoring its RTC; no point in running the timer */
+        TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
         destroy_periodic_time(&s->pt);
         s->period = 0;
     }
@@ -152,8 +154,11 @@ static void rtc_timer_update(RTCState *s)
                 else
                     delta = period - ((now - s->start_time) % period);
                 if ( s->hw.cmos_data[RTC_REG_B] & RTC_PIE )
+                {
+                    TRACE_2D(TRC_HVM_EMUL_RTC_START_TIMER, delta, period);
                     create_periodic_time(v, &s->pt, delta, period,
                                          RTC_IRQ, rtc_pf_callback, s);
+                }
                 else
                     s->check_ticks_since = now;
             }
@@ -161,6 +166,7 @@ static void rtc_timer_update(RTCState *s)
         }
         /* fall through */
     default:
+        TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
         destroy_periodic_time(&s->pt);
         s->period = 0;
         break;
@@ -513,6 +519,7 @@ static int rtc_ioport_write(void *opaque, uint32_t addr, uint32_t data)
         rtc_update_irq(s);
         if ( (data ^ orig) & RTC_PIE )
         {
+            TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
             destroy_periodic_time(&s->pt);
             s->period = 0;
             rtc_timer_update(s);
@@ -772,6 +779,7 @@ void rtc_reset(struct domain *d)
 {
     RTCState *s = domain_vrtc(d);
 
+    TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
     destroy_periodic_time(&s->pt);
     s->period = 0;
     s->pt.source = PTSRC_isa;
@@ -813,6 +821,7 @@ void rtc_deinit(struct domain *d)
 
     spin_barrier(&s->lock);
 
+    TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
     destroy_periodic_time(&s->pt);
     kill_timer(&s->update_timer);
     kill_timer(&s->update_timer2);
diff --git a/xen/arch/x86/hvm/vlapic.c b/xen/arch/x86/hvm/vlapic.c
index fc307c0..cd7e872 100644
--- a/xen/arch/x86/hvm/vlapic.c
+++ b/xen/arch/x86/hvm/vlapic.c
@@ -611,6 +611,7 @@ int hvm_x2apic_msr_read(struct vcpu *v, unsigned int msr, uint64_t *msr_content)
 
 static void vlapic_pt_cb(struct vcpu *v, void *data)
 {
+    TRACE_0D(TRC_HVM_EMUL_LAPIC_TIMER_CB);
     *(s_time_t *)data = hvm_get_guest_time(v);
 }
 
@@ -712,6 +713,7 @@ static int vlapic_reg_write(struct vcpu *v,
         if ( (vlapic_get_reg(vlapic, offset) & APIC_TIMER_MODE_MASK) !=
              (val & APIC_TIMER_MODE_MASK) )
         {
+            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
             destroy_periodic_time(&vlapic->pt);
             vlapic_set_reg(vlapic, APIC_TMICT, 0);
             vlapic_set_reg(vlapic, APIC_TMCCT, 0);
@@ -746,12 +748,16 @@ static int vlapic_reg_write(struct vcpu *v,
         vlapic_set_reg(vlapic, APIC_TMICT, val);
         if ( val == 0 )
         {
+            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
             destroy_periodic_time(&vlapic->pt);
             break;
         }
 
         period = ((uint64_t)APIC_BUS_CYCLE_NS *
                   (uint32_t)val * vlapic->hw.timer_divisor);
+        TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(period),
+                 TRC_PAR_LONG(vlapic_lvtt_period(vlapic) ? period : 0LL),
+                 vlapic->pt.irq);
         create_periodic_time(current, &vlapic->pt, period, 
                              vlapic_lvtt_period(vlapic) ? period : 0,
                              vlapic->pt.irq,
@@ -950,6 +956,8 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
 
         vlapic->hw.tdt_msr = value;
         /* .... reprogram tdt timer */
+        TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(delta),
+                        TRC_PAR_LONG(0LL), vlapic->pt.irq);
         create_periodic_time(v, &vlapic->pt, delta, 0,
                              vlapic->pt.irq, vlapic_tdt_pt_cb,
                              &vlapic->timer_last_update);
@@ -962,6 +970,8 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
         /* trigger a timer event if needed */
         if ( value > 0 )
         {
+            TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(0LL),
+                            TRC_PAR_LONG(0LL), vlapic->pt.irq);
             create_periodic_time(v, &vlapic->pt, 0, 0,
                                  vlapic->pt.irq, vlapic_tdt_pt_cb,
                                  &vlapic->timer_last_update);
@@ -970,6 +980,7 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
         else
         {
             /* .... stop tdt timer */
+            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
             destroy_periodic_time(&vlapic->pt);
         }
 
@@ -1003,6 +1014,10 @@ static int __vlapic_accept_pic_intr(struct vcpu *v)
 
 int vlapic_accept_pic_intr(struct vcpu *v)
 {
+    TRACE_2D(TRC_HVM_EMUL_LAPIC_PIC_INTR,
+             (v == v->domain->arch.hvm_domain.i8259_target),
+             v ? __vlapic_accept_pic_intr(v) : -1);
+
     return ((v == v->domain->arch.hvm_domain.i8259_target) &&
             __vlapic_accept_pic_intr(v));
 }
@@ -1106,6 +1121,7 @@ void vlapic_reset(struct vlapic *vlapic)
     vlapic_set_reg(vlapic, APIC_SPIV, 0xff);
     vlapic->hw.disabled |= VLAPIC_SW_DISABLED;
 
+    TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
     destroy_periodic_time(&vlapic->pt);
 }
 
@@ -1129,6 +1145,8 @@ static void lapic_rearm(struct vlapic *s)
 
     period = ((uint64_t)APIC_BUS_CYCLE_NS *
               (uint32_t)tmict * s->hw.timer_divisor);
+    TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(period),
+             TRC_PAR_LONG(vlapic_lvtt_period(s) ? period : 0LL), s->pt.irq);
     create_periodic_time(vlapic_vcpu(s), &s->pt, period,
                          vlapic_lvtt_period(s) ? period : 0,
                          s->pt.irq,
@@ -1275,6 +1293,7 @@ void vlapic_destroy(struct vcpu *v)
     struct vlapic *vlapic = vcpu_vlapic(v);
 
     tasklet_kill(&vlapic->init_sipi.tasklet);
+    TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
     destroy_periodic_time(&vlapic->pt);
     unmap_domain_page_global(vlapic->regs);
     free_domheap_page(vlapic->regs_page);
diff --git a/xen/arch/x86/hvm/vpic.c b/xen/arch/x86/hvm/vpic.c
index 5ca513c..2c6e6e5 100644
--- a/xen/arch/x86/hvm/vpic.c
+++ b/xen/arch/x86/hvm/vpic.c
@@ -30,6 +30,7 @@
 #include <xen/lib.h>
 #include <xen/errno.h>
 #include <xen/sched.h>
+#include <xen/trace.h>
 #include <asm/hvm/hvm.h>
 #include <asm/hvm/io.h>
 #include <asm/hvm/support.h>
@@ -99,6 +100,8 @@ static void vpic_update_int_output(struct hvm_hw_vpic *vpic)
     ASSERT(vpic_is_locked(vpic));
 
     irq = vpic_get_highest_priority_irq(vpic);
+    TRACE_3D(TRC_HVM_EMUL_PIC_INT_OUTPUT, vpic->int_output, vpic->is_master,
+             irq);
     if ( vpic->int_output == (irq >= 0) )
         return;
 
@@ -112,7 +115,10 @@ static void vpic_update_int_output(struct hvm_hw_vpic *vpic)
             /* Master INT line is connected in Virtual Wire Mode. */
             struct vcpu *v = vpic_domain(vpic)->arch.hvm_domain.i8259_target;
             if ( v != NULL )
+            {
+                TRACE_1D(TRC_HVM_EMUL_PIC_KICK, irq);
                 vcpu_kick(v);
+            }
         }
         else
         {
@@ -135,6 +141,7 @@ static void __vpic_intack(struct hvm_hw_vpic *vpic, int irq)
 
     ASSERT(vpic_is_locked(vpic));
 
+    TRACE_2D(TRC_HVM_EMUL_PIC_INTACK, vpic->is_master, irq);
     /* Edge-triggered: clear the IRR (forget the edge). */
     if ( !(vpic->elcr & mask) )
         vpic->irr &= ~mask;
@@ -434,6 +441,7 @@ void vpic_irq_positive_edge(struct domain *d, int irq)
     ASSERT(irq <= 15);
     ASSERT(vpic_is_locked(vpic));
 
+    TRACE_1D(TRC_HVM_EMUL_PIC_POSEDGE, irq);
     if ( irq == 2 )
         return;
 
@@ -450,6 +458,7 @@ void vpic_irq_negative_edge(struct domain *d, int irq)
     ASSERT(irq <= 15);
     ASSERT(vpic_is_locked(vpic));
 
+    TRACE_1D(TRC_HVM_EMUL_PIC_NEGEDGE, irq);
     if ( irq == 2 )
         return;
 
@@ -463,6 +472,8 @@ int vpic_ack_pending_irq(struct vcpu *v)
     int irq, vector;
     struct hvm_hw_vpic *vpic = &v->domain->arch.hvm_domain.vpic[0];
 
+    TRACE_2D(TRC_HVM_EMUL_PIC_PEND_IRQ_CALL, vlapic_accept_pic_intr(v),
+             vpic->int_output);
     if ( !vlapic_accept_pic_intr(v) || !vpic->int_output )
         return -1;
 
diff --git a/xen/include/asm-x86/hvm/trace.h b/xen/include/asm-x86/hvm/trace.h
index 9d7e00b..de802a6 100644
--- a/xen/include/asm-x86/hvm/trace.h
+++ b/xen/include/asm-x86/hvm/trace.h
@@ -58,6 +58,13 @@
 
 #define TRC_PAR_LONG(par) ((par)&0xFFFFFFFF),((par)>>32)
 
+#define TRACE_2_LONG_2D(_e, d1, d2, ...) \
+    TRACE_4D(_e, d1, d2)
+#define TRACE_2_LONG_3D(_e, d1, d2, d3, ...) \
+    TRACE_5D(_e, d1, d2, d3)
+#define TRACE_2_LONG_4D(_e, d1, d2, d3, d4, ...) \
+    TRACE_6D(_e, d1, d2, d3, d4)
+
 #define HVMTRACE_ND(evt, modifier, cycles, count, d1, d2, d3, d4, d5, d6) \
     do {                                                                  \
         if ( unlikely(tb_init_done) && DO_TRC_HVM_ ## evt )               \
diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h
index e2f60a6..cfcf4aa 100644
--- a/xen/include/public/trace.h
+++ b/xen/include/public/trace.h
@@ -50,8 +50,9 @@
 #define TRC_SUBCLS_SHIFT 12
 
 /* trace subclasses for SVM */
-#define TRC_HVM_ENTRYEXIT 0x00081000   /* VMENTRY and #VMEXIT       */
-#define TRC_HVM_HANDLER   0x00082000   /* various HVM handlers      */
+#define TRC_HVM_ENTRYEXIT   0x00081000   /* VMENTRY and #VMEXIT       */
+#define TRC_HVM_HANDLER     0x00082000   /* various HVM handlers      */
+#define TRC_HVM_EMUL        0x00084000   /* emulated devices */
 
 #define TRC_SCHED_MIN       0x00021000   /* Just runstate changes */
 #define TRC_SCHED_CLASS     0x00022000   /* Scheduler-specific    */
@@ -229,6 +230,25 @@
 #define TRC_HVM_IOPORT_WRITE    (TRC_HVM_HANDLER + 0x216)
 #define TRC_HVM_IOMEM_WRITE     (TRC_HVM_HANDLER + 0x217)
 
+/* Trace events for emulated devices */
+#define TRC_HVM_EMUL_HPET_START_TIMER  (TRC_HVM_EMUL + 0x1)
+#define TRC_HVM_EMUL_PIT_START_TIMER   (TRC_HVM_EMUL + 0x2)
+#define TRC_HVM_EMUL_RTC_START_TIMER   (TRC_HVM_EMUL + 0x3)
+#define TRC_HVM_EMUL_LAPIC_START_TIMER (TRC_HVM_EMUL + 0x4)
+#define TRC_HVM_EMUL_HPET_STOP_TIMER   (TRC_HVM_EMUL + 0x5)
+#define TRC_HVM_EMUL_PIT_STOP_TIMER    (TRC_HVM_EMUL + 0x6)
+#define TRC_HVM_EMUL_RTC_STOP_TIMER    (TRC_HVM_EMUL + 0x7)
+#define TRC_HVM_EMUL_LAPIC_STOP_TIMER  (TRC_HVM_EMUL + 0x8)
+#define TRC_HVM_EMUL_PIT_TIMER_CB      (TRC_HVM_EMUL + 0x9)
+#define TRC_HVM_EMUL_LAPIC_TIMER_CB    (TRC_HVM_EMUL + 0xA)
+#define TRC_HVM_EMUL_PIC_INT_OUTPUT    (TRC_HVM_EMUL + 0xB)
+#define TRC_HVM_EMUL_PIC_KICK          (TRC_HVM_EMUL + 0xC)
+#define TRC_HVM_EMUL_PIC_INTACK        (TRC_HVM_EMUL + 0xD)
+#define TRC_HVM_EMUL_PIC_POSEDGE       (TRC_HVM_EMUL + 0xE)
+#define TRC_HVM_EMUL_PIC_NEGEDGE       (TRC_HVM_EMUL + 0xF)
+#define TRC_HVM_EMUL_PIC_PEND_IRQ_CALL (TRC_HVM_EMUL + 0x10)
+#define TRC_HVM_EMUL_LAPIC_PIC_INTR    (TRC_HVM_EMUL + 0x11)
+
 /* trace events for per class */
 #define TRC_PM_FREQ_CHANGE      (TRC_HW_PM + 0x01)
 #define TRC_PM_IDLE_ENTRY       (TRC_HW_PM + 0x02)
-- 
1.8.4

^ permalink raw reply related	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-07 22:38 ` [PATCH v3 1/2] Add emacs local variables to all files changed Don Slutz
@ 2014-04-08  9:36   ` Jan Beulich
  2014-04-08  9:36     ` George Dunlap
  0 siblings, 1 reply; 9+ messages in thread
From: Jan Beulich @ 2014-04-08  9:36 UTC (permalink / raw)
  To: Don Slutz
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, George Dunlap,
	Tim Deegan, Ian Jackson, xen-devel

>>> On 08.04.14 at 00:38, <dslutz@verizon.com> wrote:
> This is per CODING_STYLE.

But the patch title is rather meaningless now without the 0/2 and/or
2/2 as context.

Jan

> Signed-off-by: Don Slutz <dslutz@verizon.com>
> ---
> v3:
>     Drop xentrace from subject.
> 
>  xen/arch/x86/hvm/hpet.c   | 9 +++++++++
>  xen/arch/x86/hvm/i8254.c  | 9 +++++++++
>  xen/arch/x86/hvm/rtc.c    | 9 +++++++++
>  xen/arch/x86/hvm/vlapic.c | 9 +++++++++
>  xen/arch/x86/hvm/vpic.c   | 9 +++++++++
>  5 files changed, 45 insertions(+)
> 
> diff --git a/xen/arch/x86/hvm/hpet.c b/xen/arch/x86/hvm/hpet.c
> index 4324b52..e1e769a 100644
> --- a/xen/arch/x86/hvm/hpet.c
> +++ b/xen/arch/x86/hvm/hpet.c
> @@ -622,3 +622,12 @@ void hpet_reset(struct domain *d)
>      hpet_deinit(d);
>      hpet_init(d->vcpu[0]);
>  }
> +
> +/*
> + * Local variables:
> + * mode: C
> + * c-file-style: "BSD"
> + * c-basic-offset: 4
> + * indent-tabs-mode: nil
> + * End:
> + */
> diff --git a/xen/arch/x86/hvm/i8254.c b/xen/arch/x86/hvm/i8254.c
> index f7493b8..6e66b49 100644
> --- a/xen/arch/x86/hvm/i8254.c
> +++ b/xen/arch/x86/hvm/i8254.c
> @@ -556,3 +556,12 @@ int pv_pit_handler(int port, int data, int write)
>  
>      return !write ? ioreq.data : 0;
>  }
> +
> +/*
> + * Local variables:
> + * mode: C
> + * c-file-style: "BSD"
> + * c-basic-offset: 4
> + * indent-tabs-mode: nil
> + * End:
> + */
> diff --git a/xen/arch/x86/hvm/rtc.c b/xen/arch/x86/hvm/rtc.c
> index 639b4c5..7cd0cf4 100644
> --- a/xen/arch/x86/hvm/rtc.c
> +++ b/xen/arch/x86/hvm/rtc.c
> @@ -827,3 +827,12 @@ void rtc_update_clock(struct domain *d)
>      s->current_tm = gmtime(get_localtime(d));
>      spin_unlock(&s->lock);
>  }
> +
> +/*
> + * Local variables:
> + * mode: C
> + * c-file-style: "BSD"
> + * c-basic-offset: 4
> + * indent-tabs-mode: nil
> + * End:
> + */
> diff --git a/xen/arch/x86/hvm/vlapic.c b/xen/arch/x86/hvm/vlapic.c
> index bc06010..fc307c0 100644
> --- a/xen/arch/x86/hvm/vlapic.c
> +++ b/xen/arch/x86/hvm/vlapic.c
> @@ -1279,3 +1279,12 @@ void vlapic_destroy(struct vcpu *v)
>      unmap_domain_page_global(vlapic->regs);
>      free_domheap_page(vlapic->regs_page);
>  }
> +
> +/*
> + * Local variables:
> + * mode: C
> + * c-file-style: "BSD"
> + * c-basic-offset: 4
> + * indent-tabs-mode: nil
> + * End:
> + */
> diff --git a/xen/arch/x86/hvm/vpic.c b/xen/arch/x86/hvm/vpic.c
> index fea3f68..5ca513c 100644
> --- a/xen/arch/x86/hvm/vpic.c
> +++ b/xen/arch/x86/hvm/vpic.c
> @@ -473,3 +473,12 @@ int vpic_ack_pending_irq(struct vcpu *v)
>      vector = vpic[irq >> 3].irq_base + (irq & 7);
>      return vector;
>  }
> +
> +/*
> + * Local variables:
> + * mode: C
> + * c-file-style: "BSD"
> + * c-basic-offset: 4
> + * indent-tabs-mode: nil
> + * End:
> + */
> -- 
> 1.8.4

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-08  9:36   ` Jan Beulich
@ 2014-04-08  9:36     ` George Dunlap
  2014-04-08  9:37       ` Ian Campbell
  2014-04-08  9:52       ` Jan Beulich
  0 siblings, 2 replies; 9+ messages in thread
From: George Dunlap @ 2014-04-08  9:36 UTC (permalink / raw)
  To: Jan Beulich, Don Slutz
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, Ian Jackson,
	Tim Deegan, xen-devel

On 04/08/2014 10:36 AM, Jan Beulich wrote:
>>>> On 08.04.14 at 00:38, <dslutz@verizon.com> wrote:
>> This is per CODING_STYLE.
>
> But the patch title is rather meaningless now without the 0/2 and/or
> 2/2 as context.

And so your suggestion would be...?

  -George

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-08  9:36     ` George Dunlap
@ 2014-04-08  9:37       ` Ian Campbell
  2014-04-08  9:52       ` Jan Beulich
  1 sibling, 0 replies; 9+ messages in thread
From: Ian Campbell @ 2014-04-08  9:37 UTC (permalink / raw)
  To: George Dunlap
  Cc: Keir Fraser, Stefano Stabellini, Tim Deegan, Ian Jackson,
	Don Slutz, xen-devel, Jan Beulich

On Tue, 2014-04-08 at 10:36 +0100, George Dunlap wrote:
> On 04/08/2014 10:36 AM, Jan Beulich wrote:
> >>>> On 08.04.14 at 00:38, <dslutz@verizon.com> wrote:
> >> This is per CODING_STYLE.
> >
> > But the patch title is rather meaningless now without the 0/2 and/or
> > 2/2 as context.
> 
> And so your suggestion would be...?

"Add emacs local variables to (some) files which are currently missing
them" ?

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-08  9:36     ` George Dunlap
  2014-04-08  9:37       ` Ian Campbell
@ 2014-04-08  9:52       ` Jan Beulich
  2014-04-08  9:52         ` George Dunlap
  1 sibling, 1 reply; 9+ messages in thread
From: Jan Beulich @ 2014-04-08  9:52 UTC (permalink / raw)
  To: George Dunlap, Don Slutz
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, Ian Jackson,
	Tim Deegan, xen-devel

>>> On 08.04.14 at 11:36, <george.dunlap@eu.citrix.com> wrote:
> On 04/08/2014 10:36 AM, Jan Beulich wrote:
>>>>> On 08.04.14 at 00:38, <dslutz@verizon.com> wrote:
>>> This is per CODING_STYLE.
>>
>> But the patch title is rather meaningless now without the 0/2 and/or
>> 2/2 as context.
> 
> And so your suggestion would be...?

x86/HVM: add emacs local variables to a couple of files

Jan

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 1/2] Add emacs local variables to all files changed.
  2014-04-08  9:52       ` Jan Beulich
@ 2014-04-08  9:52         ` George Dunlap
  0 siblings, 0 replies; 9+ messages in thread
From: George Dunlap @ 2014-04-08  9:52 UTC (permalink / raw)
  To: Jan Beulich, Don Slutz
  Cc: Keir Fraser, Ian Campbell, Stefano Stabellini, Ian Jackson,
	Tim Deegan, xen-devel

On 04/08/2014 10:52 AM, Jan Beulich wrote:
>>>> On 08.04.14 at 11:36, <george.dunlap@eu.citrix.com> wrote:
>> On 04/08/2014 10:36 AM, Jan Beulich wrote:
>>>>>> On 08.04.14 at 00:38, <dslutz@verizon.com> wrote:
>>>> This is per CODING_STYLE.
>>>
>>> But the patch title is rather meaningless now without the 0/2 and/or
>>> 2/2 as context.
>>
>> And so your suggestion would be...?
>
> x86/HVM: add emacs local variables to a couple of files

That sounds good to me. :-)

  -George

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL
  2014-04-07 22:38 ` [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL Don Slutz
@ 2014-04-08  9:53   ` George Dunlap
  0 siblings, 0 replies; 9+ messages in thread
From: George Dunlap @ 2014-04-08  9:53 UTC (permalink / raw)
  To: Don Slutz, xen-devel, Jan Beulich, Tim Deegan
  Cc: Keir Fraser, Ian Jackson, Ian Campbell, Stefano Stabellini

On 04/07/2014 11:38 PM, Don Slutz wrote:
> This add a set of trace events that track the setup of various
> emulated devices related to timers in domU.
>
> This set is hpet, pit (i8253, i8254), rtc (MC146818), apic (lapic),
> and pic (i8259).  The pmtimer is not traced since it does not have a
> changeable rate.
>
> Signed-off-by: Don Slutz <dslutz@verizon.com>
> Reviewed-by: Tim Deegan <tim@xen.org>

Acked-by: George Dunlap <george.dunlap@eu.citrix.com>

Thanks!


> ---
> v3:
>    Use TRC_HVM_EMUL instead of TRC_HVM_VCHIP.
>    Handle 64 bit correctly.
>
> Note: xentrace_format only supports 64bit output in hex.
>
>   tools/xentrace/formats          | 18 ++++++++++++++++++
>   xen/arch/x86/hvm/hpet.c         |  7 +++++++
>   xen/arch/x86/hvm/i8254.c        |  9 +++++++++
>   xen/arch/x86/hvm/rtc.c          |  9 +++++++++
>   xen/arch/x86/hvm/vlapic.c       | 19 +++++++++++++++++++
>   xen/arch/x86/hvm/vpic.c         | 11 +++++++++++
>   xen/include/asm-x86/hvm/trace.h |  7 +++++++
>   xen/include/public/trace.h      | 24 ++++++++++++++++++++++--
>   8 files changed, 102 insertions(+), 2 deletions(-)
>
> diff --git a/tools/xentrace/formats b/tools/xentrace/formats
> index 67fd42d..da658bf 100644
> --- a/tools/xentrace/formats
> +++ b/tools/xentrace/formats
> @@ -152,3 +152,21 @@
>   0x00802006  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  assign_vector [ irq = %(1)d = vector 0x%(2)x, CPU mask: 0x%(3)08x ]
>   0x00802007  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  bogus_vector [ 0x%(1)x ]
>   0x00802008  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  do_irq [ irq = %(1)d, began = %(2)dus, ended = %(3)dus ]
> +
> +0x00084001  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  hpet create [ tn = %(1)d, irq = %(2)d, delta = 0x%(4)08x%(3)08x, period = 0x%(6)08x%(5)08x ]
> +0x00084002  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit create [ delta = 0x%(1)016x, period = 0x%(2)016x ]
> +0x00084003  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtc create [ delta = 0x%(1)016x , period = 0x%(2)016x ]
> +0x00084004  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic create [ delta = 0x%(2)08x%(1)08x , period = 0x%(4)08x%(3)08x, irq = %(5)d ]
> +0x00084005  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  hpet destroy [ tn = %(1)d ]
> +0x00084006  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit destroy  [ ]
> +0x00084007  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  rtc destroy [ ]
> +0x00084008  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic destroy [ ]
> +0x00084009  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pit callback [ ]
> +0x0008400a  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic callback [ ]
> +0x0008400b  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_update_int_output [ int_output = %(1)d, is_master = %(2)d, irq = %(3)d ]
> +0x0008400c  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic vcpu_kick [ irq = %(1)d ]
> +0x0008400d  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  __vpic_intack [ is_master = %(1)d, irq = %(2)d ]
> +0x0008400e  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_irq_positive_edge [ irq = %(1)d ]
> +0x0008400f  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_irq_negative_edge [ irq = %(1)d ]
> +0x00084010  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vpic_ack_pending_irq [ accept_pic_intr = %(1)d, int_output = %(2)d ]
> +0x00084011  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  vlapic_accept_pic_intr [ i8259_target = %(1)d, accept_pic_int = %(2)d ]
> diff --git a/xen/arch/x86/hvm/hpet.c b/xen/arch/x86/hvm/hpet.c
> index e1e769a..42c93f3 100644
> --- a/xen/arch/x86/hvm/hpet.c
> +++ b/xen/arch/x86/hvm/hpet.c
> @@ -20,10 +20,12 @@
>   #include <asm/hvm/vpt.h>
>   #include <asm/hvm/io.h>
>   #include <asm/hvm/support.h>
> +#include <asm/hvm/trace.h>
>   #include <asm/current.h>
>   #include <asm/hpet.h>
>   #include <xen/sched.h>
>   #include <xen/event.h>
> +#include <xen/trace.h>
>
>   #define domain_vhpet(x) (&(x)->arch.hvm_domain.pl_time.vhpet)
>   #define vcpu_vhpet(x)   (domain_vhpet((x)->domain))
> @@ -191,6 +193,7 @@ static void hpet_stop_timer(HPETState *h, unsigned int tn)
>   {
>       ASSERT(tn < HPET_TIMER_NUM);
>       ASSERT(spin_is_locked(&h->lock));
> +    TRACE_1D(TRC_HVM_EMUL_HPET_STOP_TIMER, tn);
>       destroy_periodic_time(&h->pt[tn]);
>       /* read the comparator to get it updated so a read while stopped will
>        * return the expected value. */
> @@ -255,6 +258,10 @@ static void hpet_set_timer(HPETState *h, unsigned int tn)
>        * being enabled (now).
>        */
>       oneshot = !timer_is_periodic(h, tn);
> +    TRACE_2_LONG_4D(TRC_HVM_EMUL_HPET_START_TIMER, tn, irq,
> +                    TRC_PAR_LONG(hpet_tick_to_ns(h, diff)),
> +                    TRC_PAR_LONG(oneshot ? 0LL :
> +                                 hpet_tick_to_ns(h, h->hpet.period[tn])));
>       create_periodic_time(vhpet_vcpu(h), &h->pt[tn],
>                            hpet_tick_to_ns(h, diff),
>                            oneshot ? 0 : hpet_tick_to_ns(h, h->hpet.period[tn]),
> diff --git a/xen/arch/x86/hvm/i8254.c b/xen/arch/x86/hvm/i8254.c
> index 6e66b49..c4f7527 100644
> --- a/xen/arch/x86/hvm/i8254.c
> +++ b/xen/arch/x86/hvm/i8254.c
> @@ -31,6 +31,7 @@
>   #include <xen/lib.h>
>   #include <xen/errno.h>
>   #include <xen/sched.h>
> +#include <xen/trace.h>
>   #include <asm/time.h>
>   #include <asm/hvm/hvm.h>
>   #include <asm/hvm/io.h>
> @@ -159,6 +160,7 @@ static int pit_get_gate(PITState *pit, int channel)
>   static void pit_time_fired(struct vcpu *v, void *priv)
>   {
>       uint64_t *count_load_time = priv;
> +    TRACE_0D(TRC_HVM_EMUL_PIT_TIMER_CB);
>       *count_load_time = get_guest_time(v);
>   }
>
> @@ -188,16 +190,19 @@ static void pit_load_count(PITState *pit, int channel, int val)
>       case 2:
>       case 3:
>           /* Periodic timer. */
> +        TRACE_2D(TRC_HVM_EMUL_PIT_START_TIMER, period, period);
>           create_periodic_time(v, &pit->pt0, period, period, 0, pit_time_fired,
>                                &pit->count_load_time[channel]);
>           break;
>       case 1:
>       case 4:
>           /* One-shot timer. */
> +        TRACE_2D(TRC_HVM_EMUL_PIT_START_TIMER, period, 0);
>           create_periodic_time(v, &pit->pt0, period, 0, 0, pit_time_fired,
>                                &pit->count_load_time[channel]);
>           break;
>       default:
> +        TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
>           destroy_periodic_time(&pit->pt0);
>           break;
>       }
> @@ -377,6 +382,7 @@ static uint32_t pit_ioport_read(struct PITState *pit, uint32_t addr)
>
>   void pit_stop_channel0_irq(PITState *pit)
>   {
> +    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
>       spin_lock(&pit->lock);
>       destroy_periodic_time(&pit->pt0);
>       spin_unlock(&pit->lock);
> @@ -431,6 +437,7 @@ void pit_reset(struct domain *d)
>       struct hvm_hw_pit_channel *s;
>       int i;
>
> +    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
>       destroy_periodic_time(&pit->pt0);
>       pit->pt0.source = PTSRC_isa;
>
> @@ -465,6 +472,8 @@ void pit_init(struct domain *d, unsigned long cpu_khz)
>   void pit_deinit(struct domain *d)
>   {
>       PITState *pit = domain_vpit(d);
> +
> +    TRACE_0D(TRC_HVM_EMUL_PIT_STOP_TIMER);
>       destroy_periodic_time(&pit->pt0);
>   }
>
> diff --git a/xen/arch/x86/hvm/rtc.c b/xen/arch/x86/hvm/rtc.c
> index 7cd0cf4..3fab660 100644
> --- a/xen/arch/x86/hvm/rtc.c
> +++ b/xen/arch/x86/hvm/rtc.c
> @@ -27,6 +27,7 @@
>   #include <asm/hvm/io.h>
>   #include <asm/hvm/support.h>
>   #include <asm/current.h>
> +#include <xen/trace.h>
>
>   #define USEC_PER_SEC    1000000UL
>   #define NS_PER_USEC     1000UL
> @@ -91,6 +92,7 @@ static void rtc_pf_callback(struct vcpu *v, void *opaque)
>            && ++(s->pt_dead_ticks) >= 10 )
>       {
>           /* VM is ignoring its RTC; no point in running the timer */
> +        TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
>           destroy_periodic_time(&s->pt);
>           s->period = 0;
>       }
> @@ -152,8 +154,11 @@ static void rtc_timer_update(RTCState *s)
>                   else
>                       delta = period - ((now - s->start_time) % period);
>                   if ( s->hw.cmos_data[RTC_REG_B] & RTC_PIE )
> +                {
> +                    TRACE_2D(TRC_HVM_EMUL_RTC_START_TIMER, delta, period);
>                       create_periodic_time(v, &s->pt, delta, period,
>                                            RTC_IRQ, rtc_pf_callback, s);
> +                }
>                   else
>                       s->check_ticks_since = now;
>               }
> @@ -161,6 +166,7 @@ static void rtc_timer_update(RTCState *s)
>           }
>           /* fall through */
>       default:
> +        TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
>           destroy_periodic_time(&s->pt);
>           s->period = 0;
>           break;
> @@ -513,6 +519,7 @@ static int rtc_ioport_write(void *opaque, uint32_t addr, uint32_t data)
>           rtc_update_irq(s);
>           if ( (data ^ orig) & RTC_PIE )
>           {
> +            TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
>               destroy_periodic_time(&s->pt);
>               s->period = 0;
>               rtc_timer_update(s);
> @@ -772,6 +779,7 @@ void rtc_reset(struct domain *d)
>   {
>       RTCState *s = domain_vrtc(d);
>
> +    TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
>       destroy_periodic_time(&s->pt);
>       s->period = 0;
>       s->pt.source = PTSRC_isa;
> @@ -813,6 +821,7 @@ void rtc_deinit(struct domain *d)
>
>       spin_barrier(&s->lock);
>
> +    TRACE_0D(TRC_HVM_EMUL_RTC_STOP_TIMER);
>       destroy_periodic_time(&s->pt);
>       kill_timer(&s->update_timer);
>       kill_timer(&s->update_timer2);
> diff --git a/xen/arch/x86/hvm/vlapic.c b/xen/arch/x86/hvm/vlapic.c
> index fc307c0..cd7e872 100644
> --- a/xen/arch/x86/hvm/vlapic.c
> +++ b/xen/arch/x86/hvm/vlapic.c
> @@ -611,6 +611,7 @@ int hvm_x2apic_msr_read(struct vcpu *v, unsigned int msr, uint64_t *msr_content)
>
>   static void vlapic_pt_cb(struct vcpu *v, void *data)
>   {
> +    TRACE_0D(TRC_HVM_EMUL_LAPIC_TIMER_CB);
>       *(s_time_t *)data = hvm_get_guest_time(v);
>   }
>
> @@ -712,6 +713,7 @@ static int vlapic_reg_write(struct vcpu *v,
>           if ( (vlapic_get_reg(vlapic, offset) & APIC_TIMER_MODE_MASK) !=
>                (val & APIC_TIMER_MODE_MASK) )
>           {
> +            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
>               destroy_periodic_time(&vlapic->pt);
>               vlapic_set_reg(vlapic, APIC_TMICT, 0);
>               vlapic_set_reg(vlapic, APIC_TMCCT, 0);
> @@ -746,12 +748,16 @@ static int vlapic_reg_write(struct vcpu *v,
>           vlapic_set_reg(vlapic, APIC_TMICT, val);
>           if ( val == 0 )
>           {
> +            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
>               destroy_periodic_time(&vlapic->pt);
>               break;
>           }
>
>           period = ((uint64_t)APIC_BUS_CYCLE_NS *
>                     (uint32_t)val * vlapic->hw.timer_divisor);
> +        TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(period),
> +                 TRC_PAR_LONG(vlapic_lvtt_period(vlapic) ? period : 0LL),
> +                 vlapic->pt.irq);
>           create_periodic_time(current, &vlapic->pt, period,
>                                vlapic_lvtt_period(vlapic) ? period : 0,
>                                vlapic->pt.irq,
> @@ -950,6 +956,8 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
>
>           vlapic->hw.tdt_msr = value;
>           /* .... reprogram tdt timer */
> +        TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(delta),
> +                        TRC_PAR_LONG(0LL), vlapic->pt.irq);
>           create_periodic_time(v, &vlapic->pt, delta, 0,
>                                vlapic->pt.irq, vlapic_tdt_pt_cb,
>                                &vlapic->timer_last_update);
> @@ -962,6 +970,8 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
>           /* trigger a timer event if needed */
>           if ( value > 0 )
>           {
> +            TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(0LL),
> +                            TRC_PAR_LONG(0LL), vlapic->pt.irq);
>               create_periodic_time(v, &vlapic->pt, 0, 0,
>                                    vlapic->pt.irq, vlapic_tdt_pt_cb,
>                                    &vlapic->timer_last_update);
> @@ -970,6 +980,7 @@ void vlapic_tdt_msr_set(struct vlapic *vlapic, uint64_t value)
>           else
>           {
>               /* .... stop tdt timer */
> +            TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
>               destroy_periodic_time(&vlapic->pt);
>           }
>
> @@ -1003,6 +1014,10 @@ static int __vlapic_accept_pic_intr(struct vcpu *v)
>
>   int vlapic_accept_pic_intr(struct vcpu *v)
>   {
> +    TRACE_2D(TRC_HVM_EMUL_LAPIC_PIC_INTR,
> +             (v == v->domain->arch.hvm_domain.i8259_target),
> +             v ? __vlapic_accept_pic_intr(v) : -1);
> +
>       return ((v == v->domain->arch.hvm_domain.i8259_target) &&
>               __vlapic_accept_pic_intr(v));
>   }
> @@ -1106,6 +1121,7 @@ void vlapic_reset(struct vlapic *vlapic)
>       vlapic_set_reg(vlapic, APIC_SPIV, 0xff);
>       vlapic->hw.disabled |= VLAPIC_SW_DISABLED;
>
> +    TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
>       destroy_periodic_time(&vlapic->pt);
>   }
>
> @@ -1129,6 +1145,8 @@ static void lapic_rearm(struct vlapic *s)
>
>       period = ((uint64_t)APIC_BUS_CYCLE_NS *
>                 (uint32_t)tmict * s->hw.timer_divisor);
> +    TRACE_2_LONG_3D(TRC_HVM_EMUL_LAPIC_START_TIMER, TRC_PAR_LONG(period),
> +             TRC_PAR_LONG(vlapic_lvtt_period(s) ? period : 0LL), s->pt.irq);
>       create_periodic_time(vlapic_vcpu(s), &s->pt, period,
>                            vlapic_lvtt_period(s) ? period : 0,
>                            s->pt.irq,
> @@ -1275,6 +1293,7 @@ void vlapic_destroy(struct vcpu *v)
>       struct vlapic *vlapic = vcpu_vlapic(v);
>
>       tasklet_kill(&vlapic->init_sipi.tasklet);
> +    TRACE_0D(TRC_HVM_EMUL_LAPIC_STOP_TIMER);
>       destroy_periodic_time(&vlapic->pt);
>       unmap_domain_page_global(vlapic->regs);
>       free_domheap_page(vlapic->regs_page);
> diff --git a/xen/arch/x86/hvm/vpic.c b/xen/arch/x86/hvm/vpic.c
> index 5ca513c..2c6e6e5 100644
> --- a/xen/arch/x86/hvm/vpic.c
> +++ b/xen/arch/x86/hvm/vpic.c
> @@ -30,6 +30,7 @@
>   #include <xen/lib.h>
>   #include <xen/errno.h>
>   #include <xen/sched.h>
> +#include <xen/trace.h>
>   #include <asm/hvm/hvm.h>
>   #include <asm/hvm/io.h>
>   #include <asm/hvm/support.h>
> @@ -99,6 +100,8 @@ static void vpic_update_int_output(struct hvm_hw_vpic *vpic)
>       ASSERT(vpic_is_locked(vpic));
>
>       irq = vpic_get_highest_priority_irq(vpic);
> +    TRACE_3D(TRC_HVM_EMUL_PIC_INT_OUTPUT, vpic->int_output, vpic->is_master,
> +             irq);
>       if ( vpic->int_output == (irq >= 0) )
>           return;
>
> @@ -112,7 +115,10 @@ static void vpic_update_int_output(struct hvm_hw_vpic *vpic)
>               /* Master INT line is connected in Virtual Wire Mode. */
>               struct vcpu *v = vpic_domain(vpic)->arch.hvm_domain.i8259_target;
>               if ( v != NULL )
> +            {
> +                TRACE_1D(TRC_HVM_EMUL_PIC_KICK, irq);
>                   vcpu_kick(v);
> +            }
>           }
>           else
>           {
> @@ -135,6 +141,7 @@ static void __vpic_intack(struct hvm_hw_vpic *vpic, int irq)
>
>       ASSERT(vpic_is_locked(vpic));
>
> +    TRACE_2D(TRC_HVM_EMUL_PIC_INTACK, vpic->is_master, irq);
>       /* Edge-triggered: clear the IRR (forget the edge). */
>       if ( !(vpic->elcr & mask) )
>           vpic->irr &= ~mask;
> @@ -434,6 +441,7 @@ void vpic_irq_positive_edge(struct domain *d, int irq)
>       ASSERT(irq <= 15);
>       ASSERT(vpic_is_locked(vpic));
>
> +    TRACE_1D(TRC_HVM_EMUL_PIC_POSEDGE, irq);
>       if ( irq == 2 )
>           return;
>
> @@ -450,6 +458,7 @@ void vpic_irq_negative_edge(struct domain *d, int irq)
>       ASSERT(irq <= 15);
>       ASSERT(vpic_is_locked(vpic));
>
> +    TRACE_1D(TRC_HVM_EMUL_PIC_NEGEDGE, irq);
>       if ( irq == 2 )
>           return;
>
> @@ -463,6 +472,8 @@ int vpic_ack_pending_irq(struct vcpu *v)
>       int irq, vector;
>       struct hvm_hw_vpic *vpic = &v->domain->arch.hvm_domain.vpic[0];
>
> +    TRACE_2D(TRC_HVM_EMUL_PIC_PEND_IRQ_CALL, vlapic_accept_pic_intr(v),
> +             vpic->int_output);
>       if ( !vlapic_accept_pic_intr(v) || !vpic->int_output )
>           return -1;
>
> diff --git a/xen/include/asm-x86/hvm/trace.h b/xen/include/asm-x86/hvm/trace.h
> index 9d7e00b..de802a6 100644
> --- a/xen/include/asm-x86/hvm/trace.h
> +++ b/xen/include/asm-x86/hvm/trace.h
> @@ -58,6 +58,13 @@
>
>   #define TRC_PAR_LONG(par) ((par)&0xFFFFFFFF),((par)>>32)
>
> +#define TRACE_2_LONG_2D(_e, d1, d2, ...) \
> +    TRACE_4D(_e, d1, d2)
> +#define TRACE_2_LONG_3D(_e, d1, d2, d3, ...) \
> +    TRACE_5D(_e, d1, d2, d3)
> +#define TRACE_2_LONG_4D(_e, d1, d2, d3, d4, ...) \
> +    TRACE_6D(_e, d1, d2, d3, d4)
> +
>   #define HVMTRACE_ND(evt, modifier, cycles, count, d1, d2, d3, d4, d5, d6) \
>       do {                                                                  \
>           if ( unlikely(tb_init_done) && DO_TRC_HVM_ ## evt )               \
> diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h
> index e2f60a6..cfcf4aa 100644
> --- a/xen/include/public/trace.h
> +++ b/xen/include/public/trace.h
> @@ -50,8 +50,9 @@
>   #define TRC_SUBCLS_SHIFT 12
>
>   /* trace subclasses for SVM */
> -#define TRC_HVM_ENTRYEXIT 0x00081000   /* VMENTRY and #VMEXIT       */
> -#define TRC_HVM_HANDLER   0x00082000   /* various HVM handlers      */
> +#define TRC_HVM_ENTRYEXIT   0x00081000   /* VMENTRY and #VMEXIT       */
> +#define TRC_HVM_HANDLER     0x00082000   /* various HVM handlers      */
> +#define TRC_HVM_EMUL        0x00084000   /* emulated devices */
>
>   #define TRC_SCHED_MIN       0x00021000   /* Just runstate changes */
>   #define TRC_SCHED_CLASS     0x00022000   /* Scheduler-specific    */
> @@ -229,6 +230,25 @@
>   #define TRC_HVM_IOPORT_WRITE    (TRC_HVM_HANDLER + 0x216)
>   #define TRC_HVM_IOMEM_WRITE     (TRC_HVM_HANDLER + 0x217)
>
> +/* Trace events for emulated devices */
> +#define TRC_HVM_EMUL_HPET_START_TIMER  (TRC_HVM_EMUL + 0x1)
> +#define TRC_HVM_EMUL_PIT_START_TIMER   (TRC_HVM_EMUL + 0x2)
> +#define TRC_HVM_EMUL_RTC_START_TIMER   (TRC_HVM_EMUL + 0x3)
> +#define TRC_HVM_EMUL_LAPIC_START_TIMER (TRC_HVM_EMUL + 0x4)
> +#define TRC_HVM_EMUL_HPET_STOP_TIMER   (TRC_HVM_EMUL + 0x5)
> +#define TRC_HVM_EMUL_PIT_STOP_TIMER    (TRC_HVM_EMUL + 0x6)
> +#define TRC_HVM_EMUL_RTC_STOP_TIMER    (TRC_HVM_EMUL + 0x7)
> +#define TRC_HVM_EMUL_LAPIC_STOP_TIMER  (TRC_HVM_EMUL + 0x8)
> +#define TRC_HVM_EMUL_PIT_TIMER_CB      (TRC_HVM_EMUL + 0x9)
> +#define TRC_HVM_EMUL_LAPIC_TIMER_CB    (TRC_HVM_EMUL + 0xA)
> +#define TRC_HVM_EMUL_PIC_INT_OUTPUT    (TRC_HVM_EMUL + 0xB)
> +#define TRC_HVM_EMUL_PIC_KICK          (TRC_HVM_EMUL + 0xC)
> +#define TRC_HVM_EMUL_PIC_INTACK        (TRC_HVM_EMUL + 0xD)
> +#define TRC_HVM_EMUL_PIC_POSEDGE       (TRC_HVM_EMUL + 0xE)
> +#define TRC_HVM_EMUL_PIC_NEGEDGE       (TRC_HVM_EMUL + 0xF)
> +#define TRC_HVM_EMUL_PIC_PEND_IRQ_CALL (TRC_HVM_EMUL + 0x10)
> +#define TRC_HVM_EMUL_LAPIC_PIC_INTR    (TRC_HVM_EMUL + 0x11)
> +
>   /* trace events for per class */
>   #define TRC_PM_FREQ_CHANGE      (TRC_HW_PM + 0x01)
>   #define TRC_PM_IDLE_ENTRY       (TRC_HW_PM + 0x02)
>

^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2014-04-08  9:53 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-04-07 22:38 [PATCH v3 0/2] xentrace: Add TRC_HVM_EMUL (was xentrace: Add TRC_HW_VCHIP or TRC_HVM_VCHIP) Don Slutz
2014-04-07 22:38 ` [PATCH v3 1/2] Add emacs local variables to all files changed Don Slutz
2014-04-08  9:36   ` Jan Beulich
2014-04-08  9:36     ` George Dunlap
2014-04-08  9:37       ` Ian Campbell
2014-04-08  9:52       ` Jan Beulich
2014-04-08  9:52         ` George Dunlap
2014-04-07 22:38 ` [PATCH v3 2/2] xentrace: Add TRC_HVM_EMUL Don Slutz
2014-04-08  9:53   ` George Dunlap

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).