ChangeSet 1.1273.1.1, 2005/04/05 18:16:03+01:00, bren@xxxxxxxxxxxxxxxxxxxxxxx
Revamp xentrace. Clean up Xen scheduler tracings.
Signed-off-by: bin.ren@xxxxxxxxxxxx
tools/xentrace/formats | 69 ++++++++++++++++++++---------------------
tools/xentrace/xentrace_format | 4 --
xen/common/dom0_ops.c | 8 ----
xen/common/schedule.c | 66 ++++++++++++++++++---------------------
xen/include/public/dom0_ops.h | 18 +++++-----
5 files changed, 74 insertions(+), 91 deletions(-)
diff -Nru a/tools/xentrace/formats b/tools/xentrace/formats
--- a/tools/xentrace/formats 2005-04-05 14:03:11 -04:00
+++ b/tools/xentrace/formats 2005-04-05 14:03:11 -04:00
@@ -1,35 +1,34 @@
-0x00010000 CPU%(cpu)d %(tsc).6f sched_add_domain(0x%(3)08x) [
dom id = 0x%(2)08x ]
-0x00010001 CPU%(cpu)d %(tsc).6f sched_rem_domain(0x%08(3)x) [
dom id = 0x%(2)08x ]
-0x00010002 CPU%(cpu)d %(tsc).6f __wake_up(0x%(3)08x) [
dom id = 0x%(2)08x ]
-0x00010003 CPU%(cpu)d %(tsc).6f do_block() [
current = 0x%(2)08x ]
-0x00010004 CPU%(cpu)d %(tsc).6f do_yield() [
current = %(2)08x ]
-0x00010005 CPU%(cpu)d %(tsc).6f do_set_timer_op(0x%(4)08x, 0x%(5)08x) [
current = 0x%(3)08x ]
-0x00010006 CPU%(cpu)d %(tsc).6f sched_ctl(0x%(1)08x)
-0x00010007 CPU%(cpu)d %(tsc).6f sched_adjdom(params) [
dom id = 0x%(2)08x ]
-0x00010008 CPU%(cpu)d %(tsc).6f __reschedule(0x%(3)08x) [
dom id = 0x(2)08x ]
-0x00010009 CPU%(cpu)d %(tsc).6f switching to task_struct 0x%(1)08x [
dom id = 0x%(1)x ]
-0x0001000A CPU%(cpu)d %(tsc).6f s_timer_fn(unused)
-0x0001000B CPU%(cpu)d %(tsc).6f t_timer_fn(unused)
-0x0001000C CPU%(cpu)d %(tsc).6f dom_timer_fn(data)
-0x0001000D CPU%(cpu)d %(tsc).6f fallback_timer_fn(unused)
-
-
-0x00020008 CPU%(cpu)d %(tsc).6f enter: dom0_create_dom ( )
-0x00030008 CPU%(cpu)d %(tsc).6f leave: dom0_create_dom ( )
-
-0x00020009 CPU%(cpu)d %(tsc).6f enter: dom0_destroy_dom ( dom=0x%(2)x )
-0x00030009 CPU%(cpu)d %(tsc).6f leave: dom0_destroy_dom ( dom=0x%(2)x ) =
%(1)d
-
-0x0002000A CPU%(cpu)d %(tsc).6f enter: dom0_start_dom ( dom=0x%(2)x )
-0x0003000A CPU%(cpu)d %(tsc).6f leave: dom0_start_dom ( dom=0x%(2)x ) =
%(1)d
-0x0002000B CPU%(cpu)d %(tsc).6f enter: dom0_stop_dom ( dom=0x%(2)x )
-0x0003000B CPU%(cpu)d %(tsc).6f leave: dom0_stop_dom ( dom=0x%(2)x ) =
%(1)d
-0x0002000C CPU%(cpu)d %(tsc).6f enter: dom0_getinfo ( dom=0x%(2)x )
-0x0003000C CPU%(cpu)d %(tsc).6f leave: dom0_getinfo ( dom=0x%(2)x ) = %(1)d
-0x0002000D CPU%(cpu)d %(tsc).6f enter: dom0_build ( dom=0x%(2)x )
-0x0003000D CPU%(cpu)d %(tsc).6f leave: dom0_build ( dom=0x%(2)x ) = %(1)d
-
-0x00020019 CPU%(cpu)d %(tsc).6f enter: dom0_shadow_op ( dom=0x%(2)x, %(3)d
)
-0x00030019 CPU%(cpu)d %(tsc).6f leave: dom0_shadow_op ( dom=0x%(2)x, %(3)d
) = %(1)d
-
-#0x0 CPU%(cpu)d %(tsc).6f %(event)x
+0x00010000 CPU%(cpu)d %(tsc)d sched_add_domain [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010001 CPU%(cpu)d %(tsc)d sched_rem_domain [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010002 CPU%(cpu)d %(tsc)d domain_sleep [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010003 CPU%(cpu)d %(tsc)d domain_wake [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010004 CPU%(cpu)d %(tsc)d do_yield [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010005 CPU%(cpu)d %(tsc)d do_block [ domid
= 0x%(1)08x, edomid = 0x%(2)08x ]
+0x00010006 CPU%(cpu)d %(tsc)d domain_shutdown [ domid
= 0x%(1)08x, edomid = 0x%(2)08x, reason = 0x%(3)08x ]
+0x00010007 CPU%(cpu)d %(tsc)d sched_ctl
+0x00010008 CPU%(cpu)d %(tsc)d sched_adjdom [ domid
= 0x%(1)08x ]
+0x00010009 CPU%(cpu)d %(tsc)d __enter_scheduler [
prev<domid:edomid> = 0x%(1)08x : 0x%(2)08x, next<domid:edomid> = 0x%(3)08x :
0x%(4)08x ]
+0x0001000A CPU%(cpu)d %(tsc)d s_timer_fn
+0x0001000B CPU%(cpu)d %(tsc)d t_timer_fn
+0x0001000C CPU%(cpu)d %(tsc)d dom_timer_fn
+
+
+0x00020008 CPU%(cpu)d %(tsc)d enter: dom0_create_dom
+0x00030008 CPU%(cpu)d %(tsc)d leave: dom0_create_dom
+0x00020009 CPU%(cpu)d %(tsc)d enter: dom0_destroy_dom
+0x00030009 CPU%(cpu)d %(tsc)d leave: dom0_destroy_dom
+0x0002000A CPU%(cpu)d %(tsc)d enter: dom0_start_dom
+0x0003000A CPU%(cpu)d %(tsc)d leave: dom0_start_dom
+0x0002000B CPU%(cpu)d %(tsc)d enter: dom0_stop_dom
+0x0003000B CPU%(cpu)d %(tsc)d leave: dom0_stop_dom
+0x0002000C CPU%(cpu)d %(tsc)d enter: dom0_getinfo
+0x0003000C CPU%(cpu)d %(tsc)d leave: dom0_getinfo
+0x0002000D CPU%(cpu)d %(tsc)d enter: dom0_build
+0x0003000D CPU%(cpu)d %(tsc)d leave: dom0_build
+0x00020019 CPU%(cpu)d %(tsc)d enter: dom0_shadow_op
+0x00030019 CPU%(cpu)d %(tsc)d leave: dom0_shadow_op
+
+
+0x00040001 CPU%(cpu)d %(tsc)d VMX_VMEXIT [ domid
= 0x%(1)08x, eip = 0x%(2)08x, reason = 0x%(3)08x ]
+0x00040002 CPU%(cpu)d %(tsc)d VMX_VECTOR [ domid
= 0x%(1)08x, eip = 0x%(2)08x, vector = 0x%(3)08x ]
+0x00040003 CPU%(cpu)d %(tsc)d VMX_INT [ domid
= 0x%(1)08x, trap = 0x%(2)08x, va = 0x%(3)08x ]
\ No newline at end of file
diff -Nru a/tools/xentrace/xentrace_format b/tools/xentrace/xentrace_format
--- a/tools/xentrace/xentrace_format 2005-04-05 14:03:11 -04:00
+++ b/tools/xentrace/xentrace_format 2005-04-05 14:03:11 -04:00
@@ -75,8 +75,6 @@
except getopt.GetoptError:
usage()
-print mhz
-
signal.signal(signal.SIGTERM, sighand)
signal.signal(signal.SIGHUP, sighand)
signal.signal(signal.SIGINT, sighand)
@@ -84,8 +82,6 @@
interrupted = 0
defs = read_defs(arg[0])
-
-print defs
# structure of trace record + prepended CPU id (as output by xentrace):
# CPU(I) TSC(Q) EVENT(L) D1(L) D2(L) D3(L) D4(L) D5(L)
diff -Nru a/xen/common/dom0_ops.c b/xen/common/dom0_ops.c
--- a/xen/common/dom0_ops.c 2005-04-05 14:03:11 -04:00
+++ b/xen/common/dom0_ops.c 2005-04-05 14:03:11 -04:00
@@ -105,10 +105,6 @@
if ( op->interface_version != DOM0_INTERFACE_VERSION )
return -EACCES;
- TRACE_5D(TRC_DOM0OP_ENTER_BASE + op->cmd,
- 0, op->u.dummy[0], op->u.dummy[1],
- op->u.dummy[2], op->u.dummy[3] );
-
switch ( op->cmd )
{
@@ -471,10 +467,6 @@
ret = arch_do_dom0_op(op,u_dom0_op);
}
-
- TRACE_5D(TRC_DOM0OP_LEAVE_BASE + op->cmd, ret,
- op->u.dummy[0], op->u.dummy[1], op->u.dummy[2], op->u.dummy[3]);
-
return ret;
}
diff -Nru a/xen/common/schedule.c b/xen/common/schedule.c
--- a/xen/common/schedule.c 2005-04-05 14:03:11 -04:00
+++ b/xen/common/schedule.c 2005-04-05 14:03:11 -04:00
@@ -48,13 +48,13 @@
*/
#define TRC_SCHED_DOM_ADD 0x00010000
#define TRC_SCHED_DOM_REM 0x00010001
-#define TRC_SCHED_WAKE 0x00010002
-#define TRC_SCHED_BLOCK 0x00010003
+#define TRC_SCHED_SLEEP 0x00010002
+#define TRC_SCHED_WAKE 0x00010003
#define TRC_SCHED_YIELD 0x00010004
-#define TRC_SCHED_SET_TIMER 0x00010005
-#define TRC_SCHED_CTL 0x00010006
-#define TRC_SCHED_ADJDOM 0x00010007
-#define TRC_SCHED_RESCHED 0x00010008
+#define TRC_SCHED_BLOCK 0x00010005
+#define TRC_SCHED_SHUTDOWN 0x00010006
+#define TRC_SCHED_CTL 0x00010007
+#define TRC_SCHED_ADJDOM 0x00010008
#define TRC_SCHED_SWITCH 0x00010009
#define TRC_SCHED_S_TIMER_FN 0x0001000A
#define TRC_SCHED_T_TIMER_FN 0x0001000B
@@ -186,15 +186,14 @@
}
SCHED_OP(add_task, ed);
-
- TRACE_2D(TRC_SCHED_DOM_ADD, d->id, ed);
+ TRACE_2D(TRC_SCHED_DOM_ADD, d->id, ed->eid);
}
void sched_rem_domain(struct exec_domain *ed)
{
rem_ac_timer(&ed->timer);
SCHED_OP(rem_task, ed);
- TRACE_3D(TRC_SCHED_DOM_REM, ed->domain->id, ed->eid, ed);
+ TRACE_2D(TRC_SCHED_DOM_REM, ed->domain->id, ed->eid);
}
void init_idle_task(void)
@@ -203,19 +202,19 @@
BUG();
}
-void domain_sleep(struct exec_domain *d)
+void domain_sleep(struct exec_domain *ed)
{
unsigned long flags;
- spin_lock_irqsave(&schedule_data[d->processor].schedule_lock, flags);
-
- if ( likely(!domain_runnable(d)) )
- SCHED_OP(sleep, d);
+ spin_lock_irqsave(&schedule_data[ed->processor].schedule_lock, flags);
+ if ( likely(!domain_runnable(ed)) )
+ SCHED_OP(sleep, ed);
+ spin_unlock_irqrestore(&schedule_data[ed->processor].schedule_lock, flags);
- spin_unlock_irqrestore(&schedule_data[d->processor].schedule_lock, flags);
+ TRACE_2D(TRC_SCHED_SLEEP, ed->domain->id, ed->eid);
/* Synchronous. */
- while ( test_bit(EDF_RUNNING, &d->ed_flags) && !domain_runnable(d) )
+ while ( test_bit(EDF_RUNNING, &ed->ed_flags) && !domain_runnable(ed) )
cpu_relax();
}
@@ -224,19 +223,17 @@
unsigned long flags;
spin_lock_irqsave(&schedule_data[ed->processor].schedule_lock, flags);
-
if ( likely(domain_runnable(ed)) )
{
- TRACE_2D(TRC_SCHED_WAKE, ed->domain->id, ed);
SCHED_OP(wake, ed);
#ifdef WAKE_HISTO
ed->wokenup = NOW();
#endif
}
-
clear_bit(EDF_MIGRATED, &ed->ed_flags);
-
spin_unlock_irqrestore(&schedule_data[ed->processor].schedule_lock, flags);
+
+ TRACE_2D(TRC_SCHED_WAKE, ed->domain->id, ed->eid);
}
/* Block the currently-executing domain until a pertinent event occurs. */
@@ -244,8 +241,6 @@
{
struct exec_domain *ed = current;
- TRACE_2D(TRC_SCHED_BLOCK, ed->domain->id, ed);
-
ed->vcpu_info->evtchn_upcall_mask = 0;
set_bit(EDF_BLOCKED, &ed->ed_flags);
@@ -253,7 +248,10 @@
if ( event_pending(ed) )
clear_bit(EDF_BLOCKED, &ed->ed_flags);
else
+ {
+ TRACE_2D(TRC_SCHED_BLOCK, ed->domain->id, ed->eid);
__enter_scheduler();
+ }
return 0;
}
@@ -261,7 +259,7 @@
/* Voluntarily yield the processor for this allocation. */
static long do_yield(void)
{
- TRACE_2D(TRC_SCHED_YIELD, current->domain->id, current);
+ TRACE_2D(TRC_SCHED_YIELD, current->domain->id, current->eid);
__enter_scheduler();
return 0;
}
@@ -290,6 +288,8 @@
case SCHEDOP_shutdown:
{
+ TRACE_3D(TRC_SCHED_SHUTDOWN, current->domain->id, current->eid,
+ (op >> SCHEDOP_reasonshift));
domain_shutdown((u8)(op >> SCHEDOP_reasonshift));
break;
}
@@ -322,12 +322,12 @@
_______________________________________________
Xen-changelog mailing list
Xen-changelog@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-changelog
|