|
[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
|
 |
Lists.xenproject.org is hosted with RackSpace, monitoring our |