bitkeeper revision 1.911.1.1 (40abd5b2mqoey54uZKqDJrA-dD05Xw)

bandaid for xentrace. Really needs a Xen-visible trace buffer consumer 
index, and a way of kicking the trace deamon...

4 files changed, 109 insertions, 50 deletions

diff --git a/tools/xentrace/Makefile b/tools/xentrace/Makefile
index 4a63ae2b3e..d64d2a5a36 100644
--- a/tools/xentrace/Makefile
+++ b/tools/xentrace/Makefile
@@ -1,6 +1,6 @@
 
 CC       = gcc
-CFLAGS   = -Wall -O3 
+CFLAGS   = -Wall -O3 -Werror
 CFLAGS  += -I../../xen/include/hypervisor-ifs
 CFLAGS  += -I../../xenolinux-sparse/include
 CFLAGS  += -I../xend/lib
diff --git a/tools/xentrace/formats b/tools/xentrace/formats
index 726c199bd9..9a5b157f47 100644
--- a/tools/xentrace/formats
+++ b/tools/xentrace/formats
@@ -1,14 +1,35 @@
-0x00010000	CPU%(cpu)d 0x%(tsc)x sched_add_domain(0x%(3)08x)            [ dom id = 0x%(1)x%(2)08x   ]
-0x00010001	CPU%(cpu)d 0x%(tsc)x sched_rem_domain(0x%08(3)x)            [ dom id = 0x%(1)x%(2)08x   ]
-0x00010002	CPU%(cpu)d 0x%(tsc)x __wake_up(0x%(3)08x)                   [ dom id = 0x%(1)x%(2)08x   ]
-0x00010003	CPU%(cpu)d 0x%(tsc)x do_block()                             [ current = 0x%(2)08x         ]
-0x00010004	CPU%(cpu)d 0x%(tsc)x do_yield()		                    [ current = %(2)08x         ]
-0x00010005	CPU%(cpu)d 0x%(tsc)x do_set_timer_op(0x%(4)08x, 0x%(5)08x)  [ current = 0x%(3)08x ]
-0x00010006	CPU%(cpu)d 0x%(tsc)x sched_ctl(0x%(1)08x)
-0x00010007	CPU%(cpu)d 0x%(tsc)x sched_adjdom(params)                   [ dom id = 0x%(1)x%(2)08x   ]
-0x00010008	CPU%(cpu)d 0x%(tsc)x __reschedule(0x%(3)08x)                [ dom id = 0x%(1)x%(2)08x   ]
-0x00010009	CPU%(cpu)d 0x%(tsc)x switching to task_struct 0x%(1)08x     [ dom id = 0x%(1)x     ]
-0x0001000A	CPU%(cpu)d 0x%(tsc)x s_timer_fn(unused)
-0x0001000B	CPU%(cpu)d 0x%(tsc)x t_timer_fn(unused)
-0x0001000C	CPU%(cpu)d 0x%(tsc)x dom_timer_fn(data)
-0x0001000D	CPU%(cpu)d 0x%(tsc)x fallback_timer_fn(unused)
+#0x00010000	CPU%(cpu)d %(tsc).6f sched_add_domain(0x%(3)08x)            [ dom id = 0x%(1)x%(2)08x   ]
+#0x00010001	CPU%(cpu)d %(tsc).6f sched_rem_domain(0x%08(3)x)            [ dom id = 0x%(1)x%(2)08x   ]
+#0x00010002	CPU%(cpu)d %(tsc).6f __wake_up(0x%(3)08x)                   [ dom id = 0x%(1)x%(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%(1)x%(2)08x   ]
+#0x00010008	CPU%(cpu)d %(tsc).6f __reschedule(0x%(3)08x)                [ dom id = 0x%(1)x%(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
diff --git a/tools/xentrace/xentrace.c b/tools/xentrace/xentrace.c
index 157435baa0..dae9b67d80 100644
--- a/tools/xentrace/xentrace.c
+++ b/tools/xentrace/xentrace.c
@@ -227,10 +227,10 @@ struct t_rec **init_rec_ptrs(unsigned long tbufs_phys,
  * trace buffer.  Each entry in this table corresponds to the tail index for a
  * particular trace buffer.
  */
-int *init_tail_idxs(struct t_buf **bufs, unsigned int num)
+unsigned long *init_tail_idxs(struct t_buf **bufs, unsigned int num)
 {
     int i;
-    int *tails = calloc(num, sizeof(unsigned int));
+    unsigned long *tails = calloc(num, sizeof(unsigned int));
  
     if ( tails == NULL )
     {
@@ -276,16 +276,19 @@ unsigned int get_num_cpus()
  */
 int monitor_tbufs(FILE *logfile)
 {
-    int i, j;
+    int i;
+
     void *tbufs_mapped;          /* pointer to where the tbufs are mapped    */
     struct t_buf **meta;         /* pointers to the trace buffer metadata    */
     struct t_rec **data;         /* pointers to the trace buffer data areas
                                   * where they are mapped into user space.   */
-    int *tails;                  /* store tail indexes for the trace buffers */
+    unsigned long *cons;         /* store tail indexes for the trace buffers */
     unsigned long tbufs_phys;    /* physical address of the tbufs            */
     unsigned int  num;           /* number of trace buffers / logical CPUS   */
     unsigned long size;          /* size of a single trace buffer            */
 
+    int size_in_recs;
+
     /* get number of logical CPUs (and therefore number of trace buffers) */
     num = get_num_cpus();
 
@@ -293,39 +296,32 @@ int monitor_tbufs(FILE *logfile)
     get_tbufs(&tbufs_phys, &size);
     tbufs_mapped = map_tbufs(tbufs_phys, num, size);
 
+    size_in_recs = (size / sizeof(struct t_rec) )-1;
+
     /* build arrays of convenience ptrs */
     meta  = init_bufs_ptrs (tbufs_mapped, num, size);
     data  = init_rec_ptrs  (tbufs_phys, tbufs_mapped, meta, num);
-    tails = init_tail_idxs (meta, num);
+    cons  = init_tail_idxs (meta, num);
 
     /* now, scan buffers for events */
     while ( !interrupted )
     {
         for ( i = 0; ( i < num ) && !interrupted; i++ )
-        {
-            signed long newdata = meta[i]->head - tails[i];
-            signed long prewrap = newdata;
-
-	    /* correct newdata and prewrap in case of a pointer wrap */
-            if ( newdata < 0 )
-            {
-                newdata += meta[i]->size;
-                prewrap  = meta[i]->size - tails[i];
-            }
-
-            if ( newdata >= opts.new_data_thresh )
-            {
-                /* output pre-wrap data */
-                for(j = 0; j < prewrap; j++)
-                    write_rec(i, data[i] + tails[i] + j, logfile);
-                
-                /* output post-wrap data, if any */                    
-                for(j = 0; j < (newdata - prewrap); j++)
-                    write_rec(i, data[i] + j, logfile);  
-                
-                tails[i] += newdata;
-                if(tails[i] >= meta[i]->size) tails[i] = 0;
-            }
+        {	    
+/*	    printf("XX%d: cons=%ld head=%ld  %p\n", i,
+		   cons[i], meta[i]->head, data[i] + (cons[i] % size_in_recs) );
+		   */
+	    while( cons[i] < meta[i]->head )
+	    {
+/*
+		if( (cons[i] % 6  ) == 0 )
+		    printf("%d: cons=%ld head=%ld  %p\n", i,
+		       cons[i], meta[i]->head, data[i] + (cons[i] % size_in_recs) );
+		       */
+		write_rec(i, data[i] + (cons[i] % size_in_recs), logfile);
+		cons[i]++;
+	    }
+
         }
         nanosleep(&opts.poll_sleep, NULL);
     }
@@ -333,7 +329,7 @@ int monitor_tbufs(FILE *logfile)
     /* cleanup */
     free(meta);
     free(data);
-    free(tails);
+    free(cons);
     /* don't need to munmap - cleanup is automatic */
     fclose(logfile);
 
diff --git a/tools/xentrace/xentrace_format b/tools/xentrace/xentrace_format
index 4014811249..d2e51265d4 100644
--- a/tools/xentrace/xentrace_format
+++ b/tools/xentrace/xentrace_format
@@ -4,7 +4,7 @@
 
 # Program for reformatting trace buffer output according to user-supplied rules
 
-import re, sys, string, signal, struct
+import re, sys, string, signal, struct, os, getopt
 
 def usage():
     print >> sys.stderr, \
@@ -43,6 +43,9 @@ def read_defs(defs_file):
         line = fd.readline()
         if not line:
             break
+	
+	if line[0] == '#' or line[0] == '\n':
+	    continue
         
         m = reg.match(line)
 
@@ -58,29 +61,61 @@ def sighand(x,y):
 
 ##### Main code
 
+mhz = 0
+
 if len(sys.argv) < 2:
     usage()
 
+try:
+    opts, arg = getopt.getopt(sys.argv[1:], "c:" )
+
+    for opt in opts:
+	if opt[0] == '-c' : mhz = int(opt[1])
+
+except getopt.GetoptError:
+    usage()
+
+print mhz
+
 signal.signal(signal.SIGTERM, sighand)
 signal.signal(signal.SIGHUP,  sighand)
 signal.signal(signal.SIGINT,  sighand)
 
 interrupted = 0
 
-defs = read_defs(sys.argv[1])
+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)
 TRCREC = "IQLLLLLL"
 
+last_tsc = [0,0,0,0,0,0,0,0]
+
+i=0
+
 while not interrupted:
     try:
+	i=i+1
         line = sys.stdin.read(struct.calcsize(TRCREC))
         if not line:
             break
 
         (cpu, tsc, event, d1, d2, d3, d4, d5) = struct.unpack(TRCREC, line)
 
+	#tsc = (tscH<<32) | tscL
+
+	#print i, tsc
+
+	if tsc < last_tsc[cpu]:
+	    print "TSC stepped backward cpu %d !  %d %d" % (cpu,tsc,last_tsc[cpu])
+
+	last_tsc[cpu] = tsc
+
+	if mhz:
+	    tsc = tsc / (mhz*1000000.0)
+
         args = {'cpu'   : cpu,
                 'tsc'   : tsc,
                 'event' : event,
@@ -90,8 +125,15 @@ while not interrupted:
                 '4'     : d4,
                 '5'     : d5    }
 
-        if defs.has_key(str(event)): print defs[str(event)] % args
-        # silently skip lines we don't have a format for - a 'complain' option
-        # should be added if needed
+	try:
+
+	    if defs.has_key(str(event)): 
+		print defs[str(event)] % args
+	    else: 
+		if defs.has_key(str(0)): print defs[str(0)] % args
+	except TypeError:
+	    print defs[str(event)]
+	    print args
+	    
 
     except IOError, struct.error: sys.exit()