# HG changeset patch
# User Keir Fraser <keir.fraser@xxxxxxxxxx>
# Date 1242695281 -3600
# Node ID 4e7c5eb717749b043b12a3e8c43487d264276dda
# Parent fad68a77af5c71e36130eea1ec8bf967c9495763
xentrace: Trace IRQs and entry/exit timestamps.
From: Dulloor <dulloor@xxxxxxxxx>
Signed-off-by: Keir Fraser <keir.fraser@xxxxxxxxxx>
---
tools/xentrace/formats | 1 +
tools/xentrace/xentrace_format | 17 +++++++++++++++++
xen/arch/x86/irq.c | 6 ++++++
xen/include/public/trace.h | 1 +
4 files changed, 25 insertions(+)
diff -r fad68a77af5c -r 4e7c5eb71774 tools/xentrace/formats
--- a/tools/xentrace/formats Tue May 19 01:50:00 2009 +0100
+++ b/tools/xentrace/formats Tue May 19 02:08:01 2009 +0100
@@ -3,6 +3,7 @@ 0x0001f001 CPU%(cpu)d %(tsc)d (+%(relt
0x0001f001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) lost_records 0x%(1)08x
0x0001f002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) wrap_buffer 0x%(1)08x
0x0001f003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cpu_change 0x%(1)08x
+0x0001f004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) trace_irq [ vector = %(1)d,
count = %(2)d, tot_cycles = 0x%(3)08x, max_cycles = 0x%(4)08x ]
0x00021011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) running_to_runnable [ dom:vcpu
= 0x%(1)08x ]
0x00021021 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) running_to_blocked [ dom:vcpu
= 0x%(1)08x ]
diff -r fad68a77af5c -r 4e7c5eb71774 tools/xentrace/xentrace_format
--- a/tools/xentrace/xentrace_format Tue May 19 01:50:00 2009 +0100
+++ b/tools/xentrace/xentrace_format Tue May 19 02:08:01 2009 +0100
@@ -110,6 +110,10 @@ D7REC = "IIIIIII"
last_tsc = [0]
+TRC_TRACE_IRQ = 0x1f004
+NR_VECTORS = 256
+irq_measure = [{'count':0, 'tot_cycles':0, 'max_cycles':0}] * NR_VECTORS
+
i=0
while not interrupted:
@@ -179,6 +183,19 @@ while not interrupted:
if event == 0x1f003:
cpu = d1
+ if event == TRC_TRACE_IRQ:
+ # IN - d1:vector, d2:tsc_in, d3:tsc_out
+ # OUT - d1:vector, d2:count, d3:tot_cycles, d4:max_cycles
+ tsc_diff = d3 - d2
+ if tsc_diff < 0:
+ break
+ irq_measure[d1]['count'] += 1
+ irq_measure[d1]['tot_cycles'] += tsc_diff
+ if irq_measure[d1]['max_cycles'] < tsc_diff:
+ irq_measure[d1]['max_cycles'] = tsc_diff
+ d2 = irq_measure[d1]['count']
+ d3 = irq_measure[d1]['tot_cycles']
+ d4 = irq_measure[d1]['max_cycles']
#tsc = (tscH<<32) | tscL
diff -r fad68a77af5c -r 4e7c5eb71774 xen/arch/x86/irq.c
--- a/xen/arch/x86/irq.c Tue May 19 01:50:00 2009 +0100
+++ b/xen/arch/x86/irq.c Tue May 19 02:08:01 2009 +0100
@@ -16,6 +16,7 @@
#include <xen/compat.h>
#include <xen/iocap.h>
#include <xen/iommu.h>
+#include <xen/trace.h>
#include <asm/msi.h>
#include <asm/current.h>
#include <asm/flushtlb.h>
@@ -114,6 +115,7 @@ asmlinkage void do_IRQ(struct cpu_user_r
unsigned int vector = regs->entry_vector;
irq_desc_t *desc = &irq_desc[vector];
struct irqaction *action;
+ uint32_t tsc_in;
perfc_incr(irqs);
@@ -123,7 +125,9 @@ asmlinkage void do_IRQ(struct cpu_user_r
if ( likely(desc->status & IRQ_GUEST) )
{
irq_enter();
+ tsc_in = tb_init_done ? get_cycles() : 0;
__do_IRQ_guest(vector);
+ TRACE_3D(TRC_TRACE_IRQ, vector, tsc_in, get_cycles());
irq_exit();
spin_unlock(&desc->lock);
return;
@@ -147,7 +151,9 @@ asmlinkage void do_IRQ(struct cpu_user_r
desc->status &= ~IRQ_PENDING;
irq_enter();
spin_unlock_irq(&desc->lock);
+ tsc_in = tb_init_done ? get_cycles() : 0;
action->handler(vector_to_irq(vector), action->dev_id, regs);
+ TRACE_3D(TRC_TRACE_IRQ, vector, tsc_in, get_cycles());
spin_lock_irq(&desc->lock);
irq_exit();
}
diff -r fad68a77af5c -r 4e7c5eb71774 xen/include/public/trace.h
--- a/xen/include/public/trace.h Tue May 19 01:50:00 2009 +0100
+++ b/xen/include/public/trace.h Tue May 19 02:08:01 2009 +0100
@@ -59,6 +59,7 @@
#define TRC_LOST_RECORDS (TRC_GEN + 1)
#define TRC_TRACE_WRAP_BUFFER (TRC_GEN + 2)
#define TRC_TRACE_CPU_CHANGE (TRC_GEN + 3)
+#define TRC_TRACE_IRQ (TRC_GEN + 4)
#define TRC_SCHED_RUNSTATE_CHANGE (TRC_SCHED_MIN + 1)
#define TRC_SCHED_CONTINUE_RUNNING (TRC_SCHED_MIN + 2)
_______________________________________________
Xen-changelog mailing list
Xen-changelog@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-changelog
|
Home