[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [Xen-changelog] Revamp xentrace. Clean up Xen scheduler tracings.
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
|
Lists.xenproject.org is hosted with RackSpace, monitoring our |