diff options
author | rn@wyvis.research.intel-research.net <rn@wyvis.research.intel-research.net> | 2003-03-13 15:26:25 +0000 |
---|---|---|
committer | rn@wyvis.research.intel-research.net <rn@wyvis.research.intel-research.net> | 2003-03-13 15:26:25 +0000 |
commit | 0730cd5690317da758f5171bb6e3e556ac938c66 (patch) | |
tree | 114737f9f7f816dfbeae340e149ef6c8dec26740 | |
parent | 064b5bb75988a5fdcc18d4f86d0b0d5656f9c006 (diff) | |
download | xen-0730cd5690317da758f5171bb6e3e556ac938c66.tar.gz xen-0730cd5690317da758f5171bb6e3e556ac938c66.tar.bz2 xen-0730cd5690317da758f5171bb6e3e556ac938c66.zip |
bitkeeper revision 1.122.3.1 (3e70a321BvGVezZroK7FFHJEDihQag)
more perfcounters
-rw-r--r-- | BitKeeper/etc/logging_ok | 1 | ||||
-rw-r--r-- | xen/arch/i386/apic.c | 3 | ||||
-rw-r--r-- | xen/arch/i386/irq.c | 9 | ||||
-rw-r--r-- | xen/common/ac_timer.c | 99 | ||||
-rw-r--r-- | xen/common/keyhandler.c | 2 | ||||
-rw-r--r-- | xen/common/perfc.c | 127 | ||||
-rw-r--r-- | xen/include/xeno/perfc.h | 39 | ||||
-rw-r--r-- | xen/include/xeno/perfc_defn.h | 6 |
8 files changed, 163 insertions, 123 deletions
diff --git a/BitKeeper/etc/logging_ok b/BitKeeper/etc/logging_ok index 4998459b72..84541e8dec 100644 --- a/BitKeeper/etc/logging_ok +++ b/BitKeeper/etc/logging_ok @@ -10,5 +10,6 @@ kaf24@scramble.cl.cam.ac.uk kaf24@striker.cl.cam.ac.uk lynx@idefix.cl.cam.ac.uk rn@wyvis.camb.intel-research.net +rn@wyvis.research.intel-research.net smh22@boulderdash.cl.cam.ac.uk smh22@uridium.cl.cam.ac.uk diff --git a/xen/arch/i386/apic.c b/xen/arch/i386/apic.c index 9b999df951..865a279d8c 100644 --- a/xen/arch/i386/apic.c +++ b/xen/arch/i386/apic.c @@ -48,6 +48,8 @@ #include <xeno/ac_timer.h> +#include <xeno/perfc.h> + #undef APIC_TIME_TRACE #ifdef APIC_TIME_TRACE #define TRC(_x) _x @@ -748,6 +750,7 @@ void smp_apic_timer_interrupt(struct pt_regs * regs) /* call the local handler */ irq_enter(cpu, 0); + perfc_incrc(apic_timer); smp_local_timer_interrupt(regs); irq_exit(cpu, 0); diff --git a/xen/arch/i386/irq.c b/xen/arch/i386/irq.c index e58fb8f2ad..312cfe7970 100644 --- a/xen/arch/i386/irq.c +++ b/xen/arch/i386/irq.c @@ -36,6 +36,7 @@ #include <asm/pgalloc.h> #include <xeno/delay.h> +#include <xeno/perfc.h> /* * Linux has a controller-independent x86 interrupt architecture. @@ -469,6 +470,11 @@ asmlinkage unsigned int do_IRQ(struct pt_regs regs) struct irqaction * action; unsigned int status; + u32 cc_start, cc_end; + + perfc_incra(irqs, cpu); + rdtscl(cc_start); + spin_lock(&desc->lock); desc->handler->ack(irq); /* @@ -530,6 +536,9 @@ asmlinkage unsigned int do_IRQ(struct pt_regs regs) if (softirq_pending(cpu)) do_softirq(); + rdtscl(cc_end); + perfc_adda(irq_time, cpu, cc_end - cc_start); + return 1; } diff --git a/xen/common/ac_timer.c b/xen/common/ac_timer.c index 8f65ff7093..dc70de4e0c 100644 --- a/xen/common/ac_timer.c +++ b/xen/common/ac_timer.c @@ -25,7 +25,8 @@ #include <xeno/lib.h> #include <xeno/config.h> #include <xeno/smp.h> -#include <xeno/init.h> + +#include <xeno/perfc.h> #include <xeno/time.h> #include <xeno/ac_timer.h> @@ -34,10 +35,6 @@ #include <asm/system.h> #include <asm/desc.h> - -#undef AC_TIMER_TRACE -#undef AC_TIMER_STATS - #ifdef AC_TIMER_TRACE #define TRC(_x) _x #else @@ -55,22 +52,10 @@ typedef struct ac_timers_st { spinlock_t lock; struct list_head timers; - struct ac_timer *prev, *curr; + s_time_t max_diff; } __cacheline_aligned ac_timers_t; static ac_timers_t ac_timers[NR_CPUS]; -#ifdef AC_TIMER_STATS -#define BUCKETS 1000 -#define MAX_STATS -typedef struct act_stats_st -{ - u32 count; - u32 times[2*(BUCKETS)]; -} __cacheline_aligned act_stats_t; -static act_stats_t act_stats[NR_CPUS]; - -#endif - /* local prototypes */ static int detach_ac_timer(struct ac_timer *timer); /*static void ac_timer_debug(unsigned long);*/ @@ -172,14 +157,14 @@ static int detach_ac_timer(struct ac_timer *timer) */ int rem_ac_timer(struct ac_timer *timer) { - int cpu = smp_processor_id(); - int res; + int cpu = smp_processor_id(); + int res = 0; unsigned long flags; TRC(printk("ACT [%02d] remove(): timo=%lld \n", cpu, timer->expires)); - spin_lock_irqsave(&ac_timers[cpu].lock, flags); - res = detach_ac_timer(timer); + if (timer->timer_list.next) + res = detach_ac_timer(timer); spin_unlock_irqrestore(&ac_timers[cpu].lock, flags); return res; @@ -207,45 +192,23 @@ int mod_ac_timer(struct ac_timer *timer, s_time_t new_time) */ void do_ac_timer(void) { - int cpu = smp_processor_id(); - unsigned long flags; - struct ac_timer *t; + int cpu = smp_processor_id(); + unsigned long flags; + struct ac_timer *t; + s_time_t diff, now = NOW(); + long max; spin_lock_irqsave(&ac_timers[cpu].lock, flags); do_timer_again: TRC(printk("ACT [%02d] do(): now=%lld\n", cpu, NOW())); - - /* Sanity: is the timer list empty? */ - if ( list_empty(&ac_timers[cpu].timers) ) + + /* Sanity: is the timer list empty? */ + if ( list_empty(&ac_timers[cpu].timers) ) { printk("ACT[%02d] do_ac_timer(): timer irq without timer\n", cpu); - -#ifdef AC_TIMER_STATS - { - s32 diff; - u32 i; - diff = ((s32)(NOW() - t->expires)) / 1000; /* delta in us */ - if (diff < -BUCKETS) - diff = -BUCKETS; - else if (diff > BUCKETS) - diff = BUCKETS; - act_stats[cpu].times[diff+BUCKETS]++; - act_stats[cpu].count++; - - if (act_stats[cpu].count >= 5000) { - printk("ACT Stats\n"); - for (i=0; i < 2*BUCKETS; i++) { - if (act_stats[cpu].times[i] != 0) - printk("ACT [%02d]: %3dus: %5d\n", - cpu,i-BUCKETS, act_stats[cpu].times[i]); - act_stats[cpu].times[i]=0; - } - act_stats[cpu].count = 0; - printk("\n"); - } + return; } -#endif /* Handle all timeouts in the near future. */ while ( !list_empty(&ac_timers[cpu].timers) ) @@ -253,12 +216,19 @@ void do_ac_timer(void) t = list_entry(ac_timers[cpu].timers.next, struct ac_timer, timer_list); if ( t->expires > (NOW() + TIMER_SLOP) ) break; + + /* do some stats */ + diff = (now - t->expires); + if (diff > 0x7fffffff) diff = 0x7fffffff; /* THIS IS BAD! */ + max = perfc_valuea(ac_timer_max, cpu); + if (diff > max) perfc_seta(ac_timer_max, cpu, diff); + detach_ac_timer(t); spin_unlock_irqrestore(&ac_timers[cpu].lock, flags); if ( t->function != NULL ) t->function(t->data); spin_lock_irqsave(&ac_timers[cpu].lock, flags); } - + /* If list not empty then reprogram timer to new head of list */ if ( !list_empty(&ac_timers[cpu].timers) ) { @@ -287,7 +257,7 @@ static void dump_tqueue(struct list_head *queue, char *name) { struct list_head *list; int loop = 0; - struct ac_timer *t; + struct ac_timer *t; printk ("QUEUE %s %lx n: %lx, p: %lx\n", name, (unsigned long)queue, (unsigned long) queue->next, (unsigned long) queue->prev); @@ -303,18 +273,21 @@ static void dump_tqueue(struct list_head *queue, char *name) } -static void dump_timerq(u_char key, void *dev_id, struct pt_regs *regs) +void dump_timerq(u_char key, void *dev_id, struct pt_regs *regs) { u_long flags; s_time_t now = NOW(); + int i; - printk("Dumping ac_timer queues for cpu 0: NOW=0x%08X%08X\n", + printk("Dumping ac_timer queues: NOW=0x%08X%08X\n", (u32)(now>>32), (u32)now); - - spin_lock_irqsave(&ac_timers[0].lock, flags); - dump_tqueue(&ac_timers[0].timers, "ac_time"); - spin_unlock_irqrestore(&ac_timers[0].lock, flags); - printk("\n"); + for (i = 0; i < smp_num_cpus; i++) { + printk("CPU[%02d] ", i); + spin_lock_irqsave(&ac_timers[i].lock, flags); + dump_tqueue(&ac_timers[i].timers, "ac_time"); + spin_unlock_irqrestore(&ac_timers[i].lock, flags); + printk("\n"); + } return; } @@ -330,6 +303,4 @@ void __init ac_timer_init(void) INIT_LIST_HEAD(&ac_timers[i].timers); spin_lock_init(&ac_timers[i].lock); } - - add_key_handler('a', dump_timerq, "dump ac_timer queues"); } diff --git a/xen/common/keyhandler.c b/xen/common/keyhandler.c index 8bb4fecab0..1f8a84ea32 100644 --- a/xen/common/keyhandler.c +++ b/xen/common/keyhandler.c @@ -2,6 +2,7 @@ #include <xeno/reboot.h> extern void perfc_printall (u_char key, void *dev_id, struct pt_regs *regs); +extern void perfc_reset (u_char key, void *dev_id, struct pt_regs *regs); #define KEY_MAX 256 #define STR_MAX 64 @@ -122,6 +123,7 @@ void initialize_keytable() add_key_handler('d', dump_registers, "dump registers"); add_key_handler('h', show_handlers, "show this message"); add_key_handler('p', perfc_printall, "print performance counters"); + add_key_handler('P', perfc_reset, "reset performance counters"); add_key_handler('q', do_task_queues, "dump task queues + guest state"); add_key_handler('R', halt_machine, "reboot machine ungracefully"); diff --git a/xen/common/perfc.c b/xen/common/perfc.c index 6b7e9f2af3..cc277a914a 100644 --- a/xen/common/perfc.c +++ b/xen/common/perfc.c @@ -2,12 +2,19 @@ * xen performance counters */ +#include <xeno/lib.h> +#include <xeno/smp.h> +#include <xeno/time.h> #include <xeno/perfc.h> #include <xeno/keyhandler.h> -#undef PERFCOUNTER -#undef PERFCOUNTER_ARRAY +/* used for different purposes in perfc.h and here */ +#undef PERFCOUNTER +#undef PERFCOUNTER_CPU +#undef PERFCOUNTER_ARRAY + #define PERFCOUNTER( var, name ) "[0]"name"\0", +#define PERFCOUNTER_CPU( var, name ) "C"name"\0", #define PERFCOUNTER_ARRAY( var, name, size ) "["#size"]"name"\0", char* perfc_name[] = { @@ -21,63 +28,89 @@ void __perfc_print (unsigned long counter[], int offset) int loop; int total_size = 0; int element_size = 0; + int cpus = 0; int num = 0; - for (loop = 0; loop < sizeof(perfc_name) / sizeof(char *); loop++) - { - num = sscanf (perfc_name[loop], "[%d]", &element_size); - total_size += element_size == 0 ? 1 : element_size; - if (total_size > offset) break; - } - if (loop == sizeof(perfc_name) / sizeof(char *)) - { - printf ("error: couldn't find variable\n"); - return; + for (loop = 0; loop < sizeof(perfc_name) / sizeof(char *); loop++) { + if (perfc_name[loop][0] == 'C') { + element_size = NR_CPUS; + cpus = 1; + } else { + num = sscanf (perfc_name[loop], "[%d]", &element_size); + } + + total_size += element_size == 0 ? 1 : element_size; + if (total_size > offset) break; } - if (element_size == 0) /* single counter */ - { - printf ("%10ld 0x%08lx %s\n", counter[0], counter[0], - perfc_name[loop] + 2 + num); + if (loop == sizeof(perfc_name) / sizeof(char *)) { + printf ("error: couldn't find variable\n"); + return; } - else /* show entire array */ - { - for (loop = 0; loop < element_size; loop++) - { - printf ("%10ld 0x%08lx %s:%d\n", - counter[loop], counter[loop], - perfc_name[loop] + 2 + num, loop); - } + if (element_size == 0) { /* single counter */ + printf ("%10ld 0x%08lx %s\n", counter[0], counter[0], + perfc_name[loop] + 2 + num); + } else if (cpus) { /* counter per CPU */ + for (loop = 0; loop < smp_num_cpus; loop++) { + printf ("%10ld 0x%08lx cpu[%02d] %s\n", + counter[loop], counter[loop], + loop, perfc_name[loop]); + } + + } else { /* show entire array */ + for (loop = 0; loop < element_size; loop++) { + printf ("%10ld 0x%08lx %s:%d\n", + counter[loop], counter[loop], + perfc_name[loop] + 2 + num, loop); + } } return; } void perfc_printall (u_char key, void *dev_id, struct pt_regs *regs) { - int loop, idx; - int element_size; - int num; - unsigned long *counters = (unsigned long *)&perfcounters; + int loop, idx; + int element_size; + int cpus=0; + int num = 0; + s_time_t now = NOW(); + unsigned long *counters = (unsigned long *)&perfcounters; + + printf ("xen performance counters: now=0x%08X%08X\n", + (u32)(now>>32), (u32)now); + + for (loop = 0; loop < sizeof(perfc_name) / sizeof(char *); loop++) { - printf ("xen performance counters\n"); - for (loop = 0; loop < sizeof(perfc_name) / sizeof(char *); loop++) - { - num = sscanf (perfc_name[loop], "[%d]", &element_size); + if (perfc_name[loop][0] == 'C') { + element_size = NR_CPUS; + cpus = 1; + } else { + num = sscanf (perfc_name[loop], "[%d]", &element_size); + } - for (idx = 0; idx < (element_size ? element_size : 1); idx++) - { - if (element_size) - { - printf ("%10ld 0x%08lx %s:%d\n", - *counters, *counters, perfc_name[loop] + num + 2, idx); - } - else - { - printf ("%10ld 0x%08lx %s\n", - *counters, *counters, perfc_name[loop] + num + 2); - } - counters++; + for (idx = 0; idx < (element_size ? element_size : 1); idx++) { + if (cpus) { + if (idx < smp_num_cpus) + printf ("%10ld 0x%08lx cpu[%02d] %s\n", + *counters, *counters, idx, perfc_name[loop] + 1); + } else if (element_size) { + printf ("%10ld 0x%08lx %s:%d\n", + *counters, *counters, perfc_name[loop] + num + 2, idx); + } else { + printf ("%10ld 0x%08lx %s\n", + *counters, *counters, perfc_name[loop] + num + 2); + } + counters++; + } } - } - return; + return; } + +void perfc_reset (u_char key, void *dev_id, struct pt_regs *regs) +{ + s_time_t now = NOW(); + printk ("xen performance counters reset: now=0x%08X%08X\n", + (u32)(now>>32), (u32)now); + memset (&perfcounters, 0, sizeof(perfcounters)); +} + diff --git a/xen/include/xeno/perfc.h b/xen/include/xeno/perfc.h index 31201eaa6d..4d0164c170 100644 --- a/xen/include/xeno/perfc.h +++ b/xen/include/xeno/perfc.h @@ -3,22 +3,31 @@ */ /* - * NOTE: new counters must be defined in xen_perf_defn.h + * NOTE: new counters must be defined in perfc_defn.h * * PERFCOUNTER (counter, string) define a new performance counter + * PERFCOUNTER_CPU (counter, string, size) define a counter per CPU * PERFCOUNTER_ARRY (counter, string, size) define an array of counters * * unsigned long perfc_value (counter) get value of a counter + * unsigned long perfc_valuec (counter) get value of a per CPU counter * unsigned long perfc_valuea (counter, index) get value of an array counter - * void perfc_incr (counter) increment a counter - * void perfc_incra (counter, index) increment an array counter - * void perfc_add (counter, value) add a value to a counter - * void perfc_adda (counter, index, value) add a value to array counter - * void perfc_print (counter) print out the counter + * unsigned long perfc_set (counter, val) set value of a counter + * unsigned long perfc_setc (counter, val) set value of a per CPU counter + * unsigned long perfc_seta (counter, index, val) set value of an array counter + * void perfc_incr (counter) increment a counter + * void perfc_incrc (counter, index) increment a per CPU counter + * void perfc_incra (counter, index) increment an array counter + * void perfc_add (counter, value) add a value to a counter + * void perfc_addc (counter, value) add a value to a per CPU counter + * void perfc_adda (counter, index, value) add a value to array counter + * void perfc_print (counter) print out the counter */ #define PERFCOUNTER( var, name ) \ unsigned long var[1]; +#define PERFCOUNTER_CPU( var, name ) \ +unsigned long var[NR_CPUS]; #define PERFCOUNTER_ARRAY( var, name, size ) \ unsigned long var[size]; @@ -30,12 +39,18 @@ struct perfcounter_t extern struct perfcounter_t perfcounters; extern char *perfc_name[]; -#define perf_value(x) perfcounters.x[0] -#define perf_valuea(x,y) perfcounters.x[y] -#define perf_incr(x) perfcounters.x[0]++ -#define perf_incra(x,y) perfcounters.x[y]++ -#define perf_add(x,y) perfcounters.x[0]+=(y) -#define perf_adda(x,y,z) perfcounters.x[y]+=(z) +#define perfc_value(x) perfcounters.x[0] +#define perfc_valuec(x) perfcounters.x[smp_processor_id()] +#define perfc_valuea(x,y) perfcounters.x[y] +#define perfc_set(x,v) perfcounters.x[0] = v +#define perfc_setc(x,v) perfcounters.x[smp_processor_id()] = v +#define perfc_seta(x,y,v) perfcounters.x[y] = v +#define perfc_incr(x) perfcounters.x[0]++ +#define perfc_incrc(x) perfcounters.x[smp_processor_id()]++ +#define perfc_incra(x,y) perfcounters.x[y]++ +#define perfc_add(x,y) perfcounters.x[0]+=(y) +#define perfc_addc(x,y) perfcounters.x[smp_processor_id()]+=(y) +#define perfc_adda(x,y,z) perfcounters.x[y]+=(z) #define perf_print(x) \ __perfc_print(perfcounters.x, \ diff --git a/xen/include/xeno/perfc_defn.h b/xen/include/xeno/perfc_defn.h index 16ab4cd8c9..41dd48f73b 100644 --- a/xen/include/xeno/perfc_defn.h +++ b/xen/include/xeno/perfc_defn.h @@ -1,4 +1,10 @@ +PERFCOUNTER_CPU( irqs, "#interrupts" ) +PERFCOUNTER_CPU( irq_time, "cycles spent in irq handler" ) + PERFCOUNTER( blockio_tx, "block io: messages received from tx queue" ) PERFCOUNTER( blockio_rx, "block io: messages sent on rx queue" ) +PERFCOUNTER_CPU( apic_timer, "apic timer interrupts" ) +PERFCOUNTER_CPU( ac_timer_max, "ac_timer max error" ) + |