[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[Xen-devel] [PATCH v5 4/4] xentrace: add support for HVM's PI blocking list operation



In order to analyze PI blocking list operation frequence and obtain
the list length, add some relevant events to xentrace and some
associated code in xenalyze.

Signed-off-by: Chao Gao <chao.gao@xxxxxxxxx>
---
v5:
 - Put pi list operation under HW events and get rid of ASYNC stuff
 - generate scatterplot of pi list length on pcpus to be vivid to
 analyst.
v4:
 - trace part of Patch 1 in v3

---
 tools/xentrace/formats     |   2 +
 tools/xentrace/xenalyze.c  | 116 +++++++++++++++++++++++++++++++++++++++++++++
 xen/arch/x86/hvm/vmx/vmx.c |  17 ++++++-
 xen/include/public/trace.h |   5 ++
 4 files changed, 138 insertions(+), 2 deletions(-)

diff --git a/tools/xentrace/formats b/tools/xentrace/formats
index c1f584f..e926a18 100644
--- a/tools/xentrace/formats
+++ b/tools/xentrace/formats
@@ -205,6 +205,8 @@
 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 ]
+0x00804001  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pi_list_add [ domid = 
0x%(1)04x vcpu = 0x%(2)04x, pcpu = 0x%(3)04x, #entry = 0x%(4)04x ]
+0x00804002  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  pi_list_del [ domid = 
0x%(1)04x vcpu = 0x%(2)04x ]
 
 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 ]
diff --git a/tools/xentrace/xenalyze.c b/tools/xentrace/xenalyze.c
index 24cce2a..2276a23 100644
--- a/tools/xentrace/xenalyze.c
+++ b/tools/xentrace/xenalyze.c
@@ -159,6 +159,7 @@ struct {
         scatterplot_extint_cycles:1,
         scatterplot_rdtsc:1,
         scatterplot_irq:1,
+        scatterplot_pi_list:1,
         histogram_interrupt_eip:1,
         interval_mode:1,
         dump_all:1,
@@ -233,6 +234,7 @@ struct {
     .scatterplot_extint_cycles=0,
     .scatterplot_rdtsc=0,
     .scatterplot_irq=0,
+    .scatterplot_pi_list=0,
     .histogram_interrupt_eip=0,
     .dump_all = 0,
     .dump_raw_process = 0,
@@ -1391,6 +1393,9 @@ struct hvm_data {
 
     /* Historical info */
     tsc_t last_rdtsc;
+
+    /* Destination pcpu of posted interrupt's wakeup interrupt */
+    int pi_cpu;
 };
 
 enum {
@@ -1457,6 +1462,8 @@ void init_hvm_data(struct hvm_data *h, struct vcpu_data 
*v) {
     }
     for(i=0; i<GUEST_INTERRUPT_MAX+1; i++)
         h->summary.guest_interrupt[i].count=0;
+
+    h->pi_cpu = -1;
 }
 
 /* PV data */
@@ -1852,6 +1859,9 @@ struct pcpu_info {
         tsc_t tsc;
         struct cycle_summary idle, running, lost;
     } time;
+
+    /* Posted Interrupt List Length */
+    int pi_list_length;
 };
 
 void __fill_in_record_info(struct pcpu_info *p);
@@ -8581,8 +8591,97 @@ void irq_process(struct pcpu_info *p) {
     }
 }
 
+static void process_pi_list_add(struct record_info *ri)
+{
+    struct {
+        int did;
+        int vid;
+        int pcpu;
+        int len;
+    } *data = (typeof(data))ri->d;
+    struct vcpu_data *v;
+
+    v = vcpu_find(data->did, data->vid);
+    if ( !v->hvm.init )
+        init_hvm_data(&v->hvm, v);
+
+    if ( opt.dump_all )
+        printf("d%uv%u is added to pi blocking list of pcpu%u. "
+               "The list length is now %d\n",
+               data->did, data->vid, data->pcpu, data->len);
+
+    v->hvm.pi_cpu = data->pcpu;
+    /* Calibrate pi list length */
+    P.pcpu[data->pcpu].pi_list_length = data->len;
+
+    if ( opt.scatterplot_pi_list )
+    {
+        struct time_struct t;
+
+        abs_cycles_to_time(ri->tsc, &t);
+        printf("%d %u.%09u %d\n", data->pcpu, t.s, t.ns,
+               P.pcpu[data->pcpu].pi_list_length);
+    }
+}
+
+static void process_pi_list_del(struct record_info *ri)
+{
+    struct {
+        int did;
+        int vid;
+    } *data = (typeof(data))ri->d;
+    struct vcpu_data *v;
+
+    v = vcpu_find(data->did, data->vid);
+    if ( !v->hvm.init )
+        init_hvm_data(&v->hvm, v);
+
+    if ( opt.dump_all )
+    {
+        if ( v->hvm.pi_cpu != -1 )
+            printf("d%uv%u is removed from pi blocking list of pcpu%u\n",
+                   data->did, data->vid, v->hvm.pi_cpu);
+        else
+            printf("d%uv%u is removed from pi blocking list\n",
+                   data->did, data->vid);
+    }
+
+    if ( (v->hvm.pi_cpu != -1) && (P.pcpu[v->hvm.pi_cpu].pi_list_length != -1) 
)
+    {
+        P.pcpu[v->hvm.pi_cpu].pi_list_length--;
+
+        if ( opt.scatterplot_pi_list )
+        {
+            struct time_struct t;
+
+            abs_cycles_to_time(ri->tsc, &t);
+            printf("%d %u.%09u %d\n", v->hvm.pi_cpu, t.s, t.ns,
+                   P.pcpu[v->hvm.pi_cpu].pi_list_length);
+        }
+    }
+    v->hvm.pi_cpu = -1;
+}
+
+
+static void vtd_process(struct pcpu_info *p) {
+    struct record_info *ri = &p->ri;
+
+    switch (ri->event)
+    {
+    case TRC_VTD_PI_LIST_ADD:
+        process_pi_list_add(ri);
+        break;
+    case TRC_VTD_PI_LIST_DEL:
+        process_pi_list_del(ri);
+        break;
+    default:
+        process_generic(&p->ri);
+    }
+}
+
 #define TRC_HW_SUB_PM 1
 #define TRC_HW_SUB_IRQ 2
+#define TRC_HW_SUB_VTD 4
 void hw_process(struct pcpu_info *p)
 {
     struct record_info *ri = &p->ri;
@@ -8595,6 +8694,11 @@ void hw_process(struct pcpu_info *p)
     case TRC_HW_SUB_IRQ:
         irq_process(p);
         break;
+    case TRC_HW_SUB_VTD:
+        vtd_process(p);
+        break;
+    default:
+        process_generic(&p->ri);
     }
 
 }
@@ -9027,6 +9131,7 @@ off_t scan_for_new_pcpu(off_t offset) {
 
         p->file_offset = offset;
         p->next_cpu_change_offset = offset;
+        p->pi_list_length = -1;
 
         record_order_insert(p);
 
@@ -9255,6 +9360,7 @@ void process_cpu_change(struct pcpu_info *p) {
         p2->ri.d = p2->ri.rec.u.notsc.data;
         p2->file_offset = p->file_offset;
         p2->next_cpu_change_offset = p->file_offset;
+        p2->pi_list_length = -1;
 
         fprintf(warn, "%s: Activating pcpu %d at offset %lld\n",
                 __func__, r->cpu, (unsigned long long)p->file_offset);
@@ -10015,6 +10121,7 @@ enum {
     OPT_SCATTERPLOT_EXTINT_CYCLES,
     OPT_SCATTERPLOT_RDTSC,
     OPT_SCATTERPLOT_IRQ,
+    OPT_SCATTERPLOT_PI_LIST,
     OPT_HISTOGRAM_INTERRUPT_EIP,
     /* Interval options */
     OPT_INTERVAL_CR3_SCHEDULE_TIME,
@@ -10304,6 +10411,10 @@ error_t cmd_parser(int key, char *arg, struct 
argp_state *state)
         G.output_defined = 1;
         opt.scatterplot_pcpu=1;
         break;
+    case OPT_SCATTERPLOT_PI_LIST:
+        G.output_defined = 1;
+        opt.scatterplot_pi_list=1;
+        break;
     case OPT_HISTOGRAM_INTERRUPT_EIP:
     {
         char * inval, *p;
@@ -10679,6 +10790,11 @@ const struct argp_option cmd_opts[] =  {
       .group = OPT_GROUP_EXTRA,
       .doc = "Output scatterplot of irqs on pcpus.", },
 
+    { .name = "scatterplot-pi-list",
+      .key = OPT_SCATTERPLOT_PI_LIST,
+      .group = OPT_GROUP_EXTRA,
+      .doc = "Output scatterplot of pi blocking list length on pcpus.", },
+
     { .name = "histogram-interrupt-eip",
       .key = OPT_HISTOGRAM_INTERRUPT_EIP,
       .arg = "vector[,increment]",
diff --git a/xen/arch/x86/hvm/vmx/vmx.c b/xen/arch/x86/hvm/vmx/vmx.c
index 646f409..3f71681 100644
--- a/xen/arch/x86/hvm/vmx/vmx.c
+++ b/xen/arch/x86/hvm/vmx/vmx.c
@@ -210,6 +210,8 @@ static void vmx_vcpu_block(struct vcpu *v)
 
     vmx_pi_add_vcpu(&v->arch.hvm_vmx.pi_blocking,
                     &per_cpu(vmx_pi_blocking, pi_cpu));
+    TRACE_4D(TRC_VTD_PI_LIST_ADD, v->domain->domain_id, v->vcpu_id, pi_cpu,
+             read_atomic(&per_cpu(vmx_pi_blocking, pi_cpu).counter));
     spin_unlock_irqrestore(pi_blocking_list_lock, flags);
 
     ASSERT(!pi_test_sn(pi_desc));
@@ -291,6 +293,7 @@ static void vmx_pi_unblock_vcpu(struct vcpu *v)
     if ( v->arch.hvm_vmx.pi_blocking.lock != NULL )
     {
         ASSERT(v->arch.hvm_vmx.pi_blocking.lock == pi_blocking_list_lock);
+        TRACE_2D(TRC_VTD_PI_LIST_DEL, v->domain->domain_id, v->vcpu_id);
         vmx_pi_del_vcpu(&v->arch.hvm_vmx.pi_blocking,
                         container_of(pi_blocking_list_lock,
                                      struct vmx_pi_blocking_vcpu, lock));
@@ -328,6 +331,8 @@ void vmx_pi_desc_fixup(unsigned int cpu)
 
     list_for_each_entry_safe(vmx, tmp, blocked_vcpus, pi_blocking.list)
     {
+        struct vcpu *v = container_of(vmx, struct vcpu, arch.hvm_vmx);
+
         /*
          * Suppress notification or we may miss an interrupt when the
          * target cpu is dying.
@@ -341,9 +346,10 @@ void vmx_pi_desc_fixup(unsigned int cpu)
          */
         if ( pi_test_on(&vmx->pi_desc) )
         {
+            TRACE_2D(TRC_VTD_PI_LIST_DEL, v->domain->domain_id, v->vcpu_id);
             vmx_pi_del_vcpu(&vmx->pi_blocking, &per_cpu(vmx_pi_blocking, cpu));
             vmx->pi_blocking.lock = NULL;
-            vcpu_unblock(container_of(vmx, struct vcpu, arch.hvm_vmx));
+            vcpu_unblock(v);
         }
         else
         {
@@ -363,9 +369,13 @@ void vmx_pi_desc_fixup(unsigned int cpu)
             write_atomic(&vmx->pi_desc.ndst,
                          x2apic_enabled ? dest : MASK_INSR(dest, 
PI_xAPIC_NDST_MASK));
 
+            TRACE_2D(TRC_VTD_PI_LIST_DEL, v->domain->domain_id, v->vcpu_id);
             vmx_pi_del_vcpu(&vmx->pi_blocking, &per_cpu(vmx_pi_blocking, cpu));
             vmx_pi_add_vcpu(&vmx->pi_blocking, &per_cpu(vmx_pi_blocking,
                                                         new_cpu));
+            TRACE_4D(TRC_VTD_PI_LIST_ADD, v->domain->domain_id, v->vcpu_id,
+                     new_cpu,
+                     read_atomic(&per_cpu(vmx_pi_blocking, new_cpu).counter));
             vmx->pi_blocking.lock = new_lock;
 
             spin_unlock(new_lock);
@@ -2476,10 +2486,13 @@ static void pi_wakeup_interrupt(struct cpu_user_regs 
*regs)
     {
         if ( pi_test_on(&vmx->pi_desc) )
         {
+            struct vcpu *v = container_of(vmx, struct vcpu, arch.hvm_vmx);
+
+            TRACE_2D(TRC_VTD_PI_LIST_DEL, v->domain->domain_id, v->vcpu_id);
             vmx_pi_del_vcpu(&vmx->pi_blocking, &per_cpu(vmx_pi_blocking, cpu));
             ASSERT(vmx->pi_blocking.lock == lock);
             vmx->pi_blocking.lock = NULL;
-            vcpu_unblock(container_of(vmx, struct vcpu, arch.hvm_vmx));
+            vcpu_unblock(v);
         }
     }
 
diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h
index 3746bff..5eeb8ee 100644
--- a/xen/include/public/trace.h
+++ b/xen/include/public/trace.h
@@ -92,6 +92,7 @@
 /* Trace classes for Hardware */
 #define TRC_HW_PM           0x00801000   /* Power management traces */
 #define TRC_HW_IRQ          0x00802000   /* Traces relating to the handling of 
IRQs */
+#define TRC_HW_VTD          0x00804000   /* Traces relating to VTD */
 
 /* Trace events per class */
 #define TRC_LOST_RECORDS        (TRC_GEN + 1)
@@ -273,6 +274,10 @@
 #define TRC_HW_IRQ_UNMAPPED_VECTOR    (TRC_HW_IRQ + 0x7)
 #define TRC_HW_IRQ_HANDLED            (TRC_HW_IRQ + 0x8)
 
+/* Trace events relating to VT-d */
+#define TRC_VTD_PI_LIST_ADD     (TRC_HW_VTD + 0x1)
+#define TRC_VTD_PI_LIST_DEL     (TRC_HW_VTD + 0x2)
+
 /*
  * Event Flags
  *
-- 
1.8.3.1


_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
https://lists.xen.org/xen-devel

 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.