[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


 


Rackspace

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