Masaki Kanno
2009-Oct-14 23:47 UTC
[Xen-devel] Re: [Xen-changelog] [xen-unstable] Spinlock profiling (enable in buildwith lock_profile=y)
Hi, I got the following error. gcc -O1 -fno-omit-frame-pointer -fno-optimize-sibling-calls -m32 -march =i686 -g -fno-strict-aliasing -std=gnu99 -Wall -Wstrict-prototypes -Wno- unused-value -Wdeclaration-after-statement -D__XEN_TOOLS__ -MMD -MF . xenlockprof.o.d -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 - D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -mno-tls-direct-seg-refs - Werror -I ../../tools/python/xen/lowlevel/xc -I ../../tools/libxc -I ../.. /tools/include -c -o xenlockprof.o xenlockprof.c cc1: warnings being treated as errors xenlockprof.c: In function ‘main’: xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, but argument 3 has type ‘uint64_t’ xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, but argument 5 has type ‘uint64_t’ make[4]: *** [xenlockprof.o] Error 1 make[4]: Leaving directory `/xen/xen-unstable.hg/tools/misc'' make[3]: *** [subdir-install-misc] Error 2 make[3]: Leaving directory `/xen/xen-unstable.hg/tools'' make[2]: *** [subdirs-install] Error 2 make[2]: Leaving directory `/xen/xen-unstable.hg/tools'' make[1]: *** [install-tools] Error 2 make[1]: Leaving directory `/xen/xen-unstable.hg'' make: *** [world] Error 2 Best regards, Kan Wed, 14 Oct 2009 01:15:19 -0700, Xen patchbot-unstable wrote:># HG changeset patch ># User Keir Fraser <keir.fraser@citrix.com> ># Date 1255507671 -3600 ># Node ID 10c0942ed2409b740f516b41781e6051e206c984 ># Parent 71c859535c6bb7ba543ae3d483c830ca88cf4022 >Spinlock profiling (enable in build with lock_profile=y) > >Adds new tool xenlockprof to run from dom0. > >From: Juergen Gross <juergen.gross@ts.fujitsu.com> >Signed-off-by: Keir Fraser <keir.fraser@citrix.com> >--- > tools/libxc/xc_misc.c | 24 ++++ > tools/libxc/xenctrl.h | 8 + > tools/misc/Makefile | 6 - > tools/misc/xenlockprof.c | 136 +++++++++++++++++++++++ > xen/Rules.mk | 7 - > xen/arch/x86/domain.c | 2 > xen/arch/x86/xen.lds.S | 7 + > xen/common/domain.c | 7 - > xen/common/keyhandler.c | 20 +++ > xen/common/spinlock.c | 258 +++++++++++++++++++++++++++++++++++++++ >+++++ > xen/common/sysctl.c | 12 ++ > xen/include/public/sysctl.h | 35 +++++ > xen/include/xen/sched.h | 2 > xen/include/xen/spinlock.h | 97 ++++++++++++++++ > 14 files changed, 609 insertions(+), 12 deletions(-) > >diff -r 71c859535c6b -r 10c0942ed240 tools/libxc/xc_misc.c >--- a/tools/libxc/xc_misc.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/tools/libxc/xc_misc.c Wed Oct 14 09:07:51 2009 +0100 >@@ -117,6 +117,30 @@ int xc_perfc_control(int xc_handle, > *nbr_desc = sysctl.u.perfc_op.nr_counters; > if ( nbr_val ) > *nbr_val = sysctl.u.perfc_op.nr_vals; >+ >+ return rc; >+} >+ >+int xc_lockprof_control(int xc_handle, >+ uint32_t opcode, >+ uint32_t *n_elems, >+ uint64_t *time, >+ xc_lockprof_data_t *data) >+{ >+ int rc; >+ DECLARE_SYSCTL; >+ >+ sysctl.cmd = XEN_SYSCTL_lockprof_op; >+ sysctl.u.lockprof_op.cmd = opcode; >+ sysctl.u.lockprof_op.max_elem = n_elems ? *n_elems : 0; >+ set_xen_guest_handle(sysctl.u.lockprof_op.data, data); >+ >+ rc = do_sysctl(xc_handle, &sysctl); >+ >+ if (n_elems) >+ *n_elems = sysctl.u.lockprof_op.nr_elem; >+ if (time) >+ *time = sysctl.u.lockprof_op.time; > > return rc; > } >diff -r 71c859535c6b -r 10c0942ed240 tools/libxc/xenctrl.h >--- a/tools/libxc/xenctrl.h Wed Oct 14 08:58:47 2009 +0100 >+++ b/tools/libxc/xenctrl.h Wed Oct 14 09:07:51 2009 +0100 >@@ -700,6 +700,14 @@ int xc_perfc_control(int xc_handle, > int *nbr_desc, > int *nbr_val); > >+typedef xen_sysctl_lockprof_data_t xc_lockprof_data_t; >+/* IMPORTANT: The caller is responsible for mlock()''ing the @data array. */ >+int xc_lockprof_control(int xc_handle, >+ uint32_t opcode, >+ uint32_t *n_elems, >+ uint64_t *time, >+ xc_lockprof_data_t *data); >+ > /** > * Memory maps a range within one domain to a local address range. Mappings > * should be unmapped with munmap and should follow the same rules as mmap >diff -r 71c859535c6b -r 10c0942ed240 tools/misc/Makefile >--- a/tools/misc/Makefile Wed Oct 14 08:58:47 2009 +0100 >+++ b/tools/misc/Makefile Wed Oct 14 09:07:51 2009 +0100 >@@ -10,7 +10,7 @@ CFLAGS += $(INCLUDES) > > HDRS = $(wildcard *.h) > >-TARGETS-y := xenperf xenpm xen-tmem-list-parse gtraceview gtracestat >+TARGETS-y := xenperf xenpm xen-tmem-list-parse gtraceview gtracestat >xenlockprof > TARGETS-$(CONFIG_X86) += xen-detect xen-hvmctx > TARGETS := $(TARGETS-y) > >@@ -22,7 +22,7 @@ INSTALL_BIN-$(CONFIG_X86) += xen-detect > INSTALL_BIN-$(CONFIG_X86) += xen-detect > INSTALL_BIN := $(INSTALL_BIN-y) > >-INSTALL_SBIN-y := xm xen-bugtool xen-python-path xend xenperf xsview xenpm > xen-tmem-list-parse gtraceview gtracestat >+INSTALL_SBIN-y := xm xen-bugtool xen-python-path xend xenperf xsview xenpm > xen-tmem-list-parse gtraceview gtracestat xenlockprof > INSTALL_SBIN-$(CONFIG_X86) += xen-hvmctx > INSTALL_SBIN := $(INSTALL_SBIN-y) > >@@ -49,7 +49,7 @@ clean: > %.o: %.c $(HDRS) Makefile > $(CC) -c $(CFLAGS) -o $@ $< > >-xen-hvmctx xenperf xenpm gtracestat: %: %.o Makefile >+xen-hvmctx xenperf xenpm gtracestat xenlockprof: %: %.o Makefile > $(CC) $(CFLAGS) -o $@ $< $(LDFLAGS) $(LDFLAGS_libxenctrl) > > gtraceview: %: %.o Makefile >diff -r 71c859535c6b -r 10c0942ed240 tools/misc/xenlockprof.c >--- /dev/null Thu Jan 01 00:00:00 1970 +0000 >+++ b/tools/misc/xenlockprof.c Wed Oct 14 09:07:51 2009 +0100 >@@ -0,0 +1,136 @@ >+/* -*- Mode:C; c-basic-offset:4; tab-width:4 -*- >+ ************************************************************************* >*** >+ * (C) 2009 - Juergen Gross - Fujitsu Technology Solutions >+ ************************************************************************* >*** >+ * >+ * File: xenlockprof.c >+ * Author: Juergen Gross (juergen.gross@ts.fujitsu.com) >+ * Date: Oct 2009 >+ * >+ * Description: >+ */ >+ >+#include <xenctrl.h> >+#include <stdio.h> >+#include <stdlib.h> >+#include <sys/mman.h> >+#include <errno.h> >+#include <string.h> >+ >+static int lock_pages(void *addr, size_t len) >+{ >+ int e = 0; >+#ifndef __sun__ >+ e = mlock(addr, len); >+#endif >+ return (e); >+} >+ >+static void unlock_pages(void *addr, size_t len) >+{ >+#ifndef __sun__ >+ munlock(addr, len); >+#endif >+} >+ >+int main(int argc, char *argv[]) >+{ >+ int xc_handle; >+ uint32_t i, j, n; >+ uint64_t time; >+ double l, b, sl, sb; >+ char name[60]; >+ xc_lockprof_data_t *data; >+ >+ if ((argc > 2) || ((argc == 2) && (strcmp(argv[1], "-r") != 0))) >+ { >+ printf("%s: [-r]\n", argv[0]); >+ printf("no args: print lock profile data\n"); >+ printf(" -r : reset profile data\n"); >+ return 1; >+ } >+ >+ if ((xc_handle = xc_interface_open()) == -1) >+ { >+ fprintf(stderr, "Error opening xc interface: %d (%s)\n", >+ errno, strerror(errno)); >+ return 1; >+ } >+ >+ if (argc > 1) >+ { >+ if (xc_lockprof_control(xc_handle, XEN_SYSCTL_LOCKPROF_reset, NULL, >+ NULL, NULL) != 0) >+ { >+ fprintf(stderr, "Error reseting profile data: %d (%s)\n", >+ errno, strerror(errno)); >+ return 1; >+ } >+ return 1; >+ } >+ >+ n = 0; >+ if (xc_lockprof_control(xc_handle, XEN_SYSCTL_LOCKPROF_query, &n, >+ NULL, NULL) != 0) >+ { >+ fprintf(stderr, "Error getting number of profile records: %d (%s)\ >n", >+ errno, strerror(errno)); >+ return 1; >+ } >+ >+ n += 32; /* just to be sure */ >+ data = malloc(sizeof(*data) * n); >+ if ((data == NULL) || (lock_pages(data, sizeof(*data) * n) != 0)) >+ { >+ fprintf(stderr, "Could not alloc or lock buffers: %d (%s)\n", >+ errno, strerror(errno)); >+ return 1; >+ } >+ >+ i = n; >+ if ( xc_lockprof_control(xc_handle, XEN_SYSCTL_LOCKPROF_query, &i, >+ &time, data) != 0) >+ { >+ fprintf(stderr, "Error getting profile records: %d (%s)\n", >+ errno, strerror(errno)); >+ return 1; >+ } >+ >+ unlock_pages(data, sizeof(*data) * n); >+ >+ if (i > n) >+ { >+ printf("data incomplete, %d records are missing!\n\n", i - n); >+ i = n; >+ } >+ sl = 0; >+ sb = 0; >+ for (j = 0; j < i; j++) >+ { >+ switch (data[j].type) >+ { >+ case LOCKPROF_TYPE_GLOBAL: >+ sprintf(name, "global lock %s", data[j].name); >+ break; >+ case LOCKPROF_TYPE_PERDOM: >+ sprintf(name, "domain %d lock %s", data[j].idx, data[j].name); >+ break; >+ default: >+ sprintf(name, "unknown type(%d) %d lock %s", data[j].type, >+ data[j].idx, data[j].name); >+ break; >+ } >+ l = (double)(data[j].lock_time) / 1E+09; >+ b = (double)(data[j].block_time) / 1E+09; >+ sl += l; >+ sb += b; >+ printf("%-50s: lock:%12ld(%20.9fs), block:%12ld(%20.9fs)\n", >+ name, data[j].lock_cnt, l, data[j].block_cnt, b); >+ } >+ l = (double)time / 1E+09; >+ printf("total profiling time: %20.9fs\n", l); >+ printf("total locked time: %20.9fs\n", sl); >+ printf("total blocked time: %20.9fs\n", sb); >+ >+ return 0; >+} >diff -r 71c859535c6b -r 10c0942ed240 xen/Rules.mk >--- a/xen/Rules.mk Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/Rules.mk Wed Oct 14 09:07:51 2009 +0100 >@@ -6,6 +6,7 @@ verbose ?= n > verbose ?= n > perfc ?= n > perfc_arrays ?= n >+lock_profile ?= n > crash_debug ?= n > frame_pointer ?= n > >@@ -52,17 +53,15 @@ CFLAGS-$(crash_debug) += -DCRASH_DEBUG > CFLAGS-$(crash_debug) += -DCRASH_DEBUG > CFLAGS-$(perfc) += -DPERF_COUNTERS > CFLAGS-$(perfc_arrays) += -DPERF_ARRAYS >+CFLAGS-$(lock_profile) += -DLOCK_PROFILE > CFLAGS-$(frame_pointer) += -fno-omit-frame-pointer -DCONFIG_FRAME_POINTER >+CFLAGS-$(privileged_stubdoms) += -DPRIVILEGED_STUBDOMS > > ifneq ($(max_phys_cpus),) > CFLAGS-y += -DMAX_PHYS_CPUS=$(max_phys_cpus) > endif > ifneq ($(max_phys_irqs),) > CFLAGS-y += -DMAX_PHYS_IRQS=$(max_phys_irqs) >-endif >- >-ifeq ($(privileged_stubdoms),y) >-CFLAGS += -DPRIVILEGED_STUBDOMS > endif > > AFLAGS-y += -D__ASSEMBLY__ >diff -r 71c859535c6b -r 10c0942ed240 xen/arch/x86/domain.c >--- a/xen/arch/x86/domain.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/arch/x86/domain.c Wed Oct 14 09:07:51 2009 +0100 >@@ -32,6 +32,7 @@ > #include <xen/acpi.h> > #include <xen/pci.h> > #include <xen/paging.h> >+#include <public/sysctl.h> > #include <asm/regs.h> > #include <asm/mc146818rtc.h> > #include <asm/system.h> >@@ -185,6 +186,7 @@ struct domain *alloc_domain_struct(void) > > void free_domain_struct(struct domain *d) > { >+ lock_profile_deregister_struct(LOCKPROF_TYPE_PERDOM, d); > free_xenheap_pages(d, get_order_from_bytes(sizeof(*d))); > } > >diff -r 71c859535c6b -r 10c0942ed240 xen/arch/x86/xen.lds.S >--- a/xen/arch/x86/xen.lds.S Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/arch/x86/xen.lds.S Wed Oct 14 09:07:51 2009 +0100 >@@ -61,6 +61,13 @@ SECTIONS > .data.read_mostly : { > *(.data.read_mostly) > } :text >+ >+#ifdef LOCK_PROFILE >+ . = ALIGN(32); >+ __lock_profile_start = .; >+ .lockprofile.data : { *(.lockprofile.data) } :text >+ __lock_profile_end = .; >+#endif > > . = ALIGN(4096); /* Init code and data */ > __init_begin = .; >diff -r 71c859535c6b -r 10c0942ed240 xen/common/domain.c >--- a/xen/common/domain.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/common/domain.c Wed Oct 14 09:07:51 2009 +0100 >@@ -29,6 +29,7 @@ > #include <acpi/cpufreq/cpufreq.h> > #include <asm/debugger.h> > #include <public/sched.h> >+#include <public/sysctl.h> > #include <public/vcpu.h> > #include <xsm/xsm.h> > #include <xen/trace.h> >@@ -221,13 +222,15 @@ struct domain *domain_create( > memset(d, 0, sizeof(*d)); > d->domain_id = domid; > >+ lock_profile_register_struct(LOCKPROF_TYPE_PERDOM, d, domid, "Domain"); >+ > if ( xsm_alloc_security_domain(d) != 0 ) > goto fail; > init_status |= INIT_xsm; > > atomic_set(&d->refcnt, 1); >- spin_lock_init(&d->domain_lock); >- spin_lock_init(&d->page_alloc_lock); >+ spin_lock_init_prof(d, domain_lock); >+ spin_lock_init_prof(d, page_alloc_lock); > spin_lock_init(&d->shutdown_lock); > spin_lock_init(&d->hypercall_deadlock_mutex); > INIT_PAGE_LIST_HEAD(&d->page_list); >diff -r 71c859535c6b -r 10c0942ed240 xen/common/keyhandler.c >--- a/xen/common/keyhandler.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/common/keyhandler.c Wed Oct 14 09:07:51 2009 +0100 >@@ -347,6 +347,20 @@ static struct keyhandler perfc_reset_key > }; > #endif > >+#ifdef LOCK_PROFILE >+extern void spinlock_profile_printall(unsigned char key); >+static struct keyhandler spinlock_printall_keyhandler = { >+ .diagnostic = 1, >+ .u.fn = spinlock_profile_printall, >+ .desc = "print lock profile info" >+}; >+extern void spinlock_profile_reset(unsigned char key); >+static struct keyhandler spinlock_reset_keyhandler = { >+ .u.fn = spinlock_profile_reset, >+ .desc = "reset lock profile info" >+}; >+#endif >+ > static void run_all_nonirq_keyhandlers(unsigned long unused) > { > /* Fire all the non-IRQ-context diagnostic keyhandlers */ >@@ -428,6 +442,12 @@ void __init initialize_keytable(void) > register_keyhandler(''p'', &perfc_printall_keyhandler); > register_keyhandler(''P'', &perfc_reset_keyhandler); > #endif >+ >+#ifdef LOCK_PROFILE >+ register_keyhandler(''l'', &spinlock_printall_keyhandler); >+ register_keyhandler(''L'', &spinlock_reset_keyhandler); >+#endif >+ > } > > /* >diff -r 71c859535c6b -r 10c0942ed240 xen/common/spinlock.c >--- a/xen/common/spinlock.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/common/spinlock.c Wed Oct 14 09:07:51 2009 +0100 >@@ -1,7 +1,11 @@ >+#include <xen/lib.h> > #include <xen/config.h> > #include <xen/irq.h> > #include <xen/smp.h> >+#include <xen/time.h> > #include <xen/spinlock.h> >+#include <xen/guest_access.h> >+#include <public/sysctl.h> > #include <asm/processor.h> > > #ifndef NDEBUG >@@ -41,56 +45,97 @@ void spin_debug_disable(void) > > #endif > >+#ifdef LOCK_PROFILE >+ >+#define LOCK_PROFILE_REL \ >+ lock->profile.time_hold += NOW() - lock->profile.time_locked; \ >+ lock->profile.lock_cnt++; >+#define LOCK_PROFILE_VAR s_time_t block = 0 >+#define LOCK_PROFILE_BLOCK block = block ? : NOW(); >+#define LOCK_PROFILE_GOT \ >+ lock->profile.time_locked = NOW(); \ >+ if (block) \ >+ { \ >+ lock->profile.time_block += lock->profile.time_locked - block; \ >+ lock->profile.block_cnt++; \ >+ } >+ >+#else >+ >+#define LOCK_PROFILE_REL >+#define LOCK_PROFILE_VAR >+#define LOCK_PROFILE_BLOCK >+#define LOCK_PROFILE_GOT >+ >+#endif >+ > void _spin_lock(spinlock_t *lock) > { >+ LOCK_PROFILE_VAR; >+ > check_lock(&lock->debug); > while ( unlikely(!_raw_spin_trylock(&lock->raw)) ) >+ { >+ LOCK_PROFILE_BLOCK; > while ( likely(_raw_spin_is_locked(&lock->raw)) ) > cpu_relax(); >+ } >+ LOCK_PROFILE_GOT; > } > > void _spin_lock_irq(spinlock_t *lock) > { >+ LOCK_PROFILE_VAR; >+ > ASSERT(local_irq_is_enabled()); > local_irq_disable(); > check_lock(&lock->debug); > while ( unlikely(!_raw_spin_trylock(&lock->raw)) ) > { >+ LOCK_PROFILE_BLOCK; > local_irq_enable(); > while ( likely(_raw_spin_is_locked(&lock->raw)) ) > cpu_relax(); > local_irq_disable(); > } >+ LOCK_PROFILE_GOT; > } > > unsigned long _spin_lock_irqsave(spinlock_t *lock) > { > unsigned long flags; >+ LOCK_PROFILE_VAR; >+ > local_irq_save(flags); > check_lock(&lock->debug); > while ( unlikely(!_raw_spin_trylock(&lock->raw)) ) > { >+ LOCK_PROFILE_BLOCK; > local_irq_restore(flags); > while ( likely(_raw_spin_is_locked(&lock->raw)) ) > cpu_relax(); > local_irq_save(flags); > } >+ LOCK_PROFILE_GOT; > return flags; > } > > void _spin_unlock(spinlock_t *lock) > { >+ LOCK_PROFILE_REL; > _raw_spin_unlock(&lock->raw); > } > > void _spin_unlock_irq(spinlock_t *lock) > { >+ LOCK_PROFILE_REL; > _raw_spin_unlock(&lock->raw); > local_irq_enable(); > } > > void _spin_unlock_irqrestore(spinlock_t *lock, unsigned long flags) > { >+ LOCK_PROFILE_REL; > _raw_spin_unlock(&lock->raw); > local_irq_restore(flags); > } >@@ -104,13 +149,32 @@ int _spin_trylock(spinlock_t *lock) > int _spin_trylock(spinlock_t *lock) > { > check_lock(&lock->debug); >+#ifndef LOCK_PROFILE > return _raw_spin_trylock(&lock->raw); >+#else >+ if (!_raw_spin_trylock(&lock->raw)) return 0; >+ lock->profile.time_locked = NOW(); >+ return 1; >+#endif > } > > void _spin_barrier(spinlock_t *lock) > { >+#ifdef LOCK_PROFILE >+ s_time_t block = NOW(); >+ u64 loop = 0; >+ >+ check_lock(&lock->debug); >+ do { mb(); loop++;} while ( _raw_spin_is_locked(&lock->raw) ); >+ if (loop > 1) >+ { >+ lock->profile.time_block += NOW() - block; >+ lock->profile.block_cnt++; >+ } >+#else > check_lock(&lock->debug); > do { mb(); } while ( _raw_spin_is_locked(&lock->raw) ); >+#endif > mb(); > } > >@@ -248,3 +312,197 @@ int _rw_is_write_locked(rwlock_t *lock) > check_lock(&lock->debug); > return _raw_rw_is_write_locked(&lock->raw); > } >+ >+#ifdef LOCK_PROFILE >+struct lock_profile_anc { >+ struct lock_profile_qhead *head_q; /* first head of this type */ >+ char *name; /* descriptive string for print */ >+}; >+ >+typedef void lock_profile_subfunc(struct lock_profile *, int32_t, int32_t, >+ void *); >+ >+extern struct lock_profile *__lock_profile_start; >+extern struct lock_profile *__lock_profile_end; >+ >+static s_time_t lock_profile_start = 0; >+static struct lock_profile_anc lock_profile_ancs[LOCKPROF_TYPE_N]; >+static struct lock_profile_qhead lock_profile_glb_q; >+static spinlock_t lock_profile_lock = SPIN_LOCK_UNLOCKED; >+ >+static void spinlock_profile_iterate(lock_profile_subfunc *sub, void *par) >+{ >+ int i; >+ struct lock_profile_qhead *hq; >+ struct lock_profile *eq; >+ >+ spin_lock(&lock_profile_lock); >+ for (i = 0; i < LOCKPROF_TYPE_N; i++) >+ { >+ for (hq = lock_profile_ancs[i].head_q; hq; hq = hq->head_q) >+ { >+ for (eq = hq->elem_q; eq; eq = eq->next) >+ { >+ sub(eq, i, hq->idx, par); >+ } >+ } >+ } >+ spin_unlock(&lock_profile_lock); >+ return; >+} >+ >+static void spinlock_profile_print_elem(struct lock_profile *data, >+ int32_t type, int32_t idx, void *par) >+{ >+ if (type == LOCKPROF_TYPE_GLOBAL) >+ printk("%s %s:\n", lock_profile_ancs[idx].name, data->name); >+ else >+ printk("%s %d %s:\n", lock_profile_ancs[idx].name, idx, data->name); >+ printk(" lock:%12ld(%08X:%08X), block:%12ld(%08X:%08X)\n", >+ data->lock_cnt, (u32)(data->time_hold >> 32), (u32)data->time_hold, >+ data->block_cnt, (u32)(data->time_block >> 32), (u32)data-> >time_block); >+ return; >+} >+ >+void spinlock_profile_printall(unsigned char key) >+{ >+ s_time_t now = NOW(); >+ s_time_t diff; >+ >+ diff = now - lock_profile_start; >+ printk("Xen lock profile info SHOW (now = %08X:%08X, " >+ "total = %08X:%08X)\n", (u32)(now>>32), (u32)now, >+ (u32)(diff>>32), (u32)diff); >+ spinlock_profile_iterate(spinlock_profile_print_elem, NULL); >+ return; >+} >+ >+static void spinlock_profile_reset_elem(struct lock_profile *data, >+ int32_t type, int32_t idx, void *par) >+{ >+ data->lock_cnt = 0; >+ data->block_cnt = 0; >+ data->time_hold = 0; >+ data->time_block = 0; >+ return; >+} >+ >+void spinlock_profile_reset(unsigned char key) >+{ >+ s_time_t now = NOW(); >+ >+ if ( key != ''\0'' ) >+ printk("Xen lock profile info RESET (now = %08X:%08X)\n", >+ (u32)(now>>32), (u32)now); >+ lock_profile_start = now; >+ spinlock_profile_iterate(spinlock_profile_reset_elem, NULL); >+ return; >+} >+ >+typedef struct { >+ xen_sysctl_lockprof_op_t *pc; >+ int rc; >+} spinlock_profile_ucopy_t; >+ >+static void spinlock_profile_ucopy_elem(struct lock_profile *data, >+ int32_t type, int32_t idx, void *par) >+{ >+ spinlock_profile_ucopy_t *p; >+ xen_sysctl_lockprof_data_t elem; >+ >+ p = (spinlock_profile_ucopy_t *)par; >+ if (p->rc) >+ return; >+ >+ if (p->pc->nr_elem < p->pc->max_elem) >+ { >+ safe_strcpy(elem.name, data->name); >+ elem.type = type; >+ elem.idx = idx; >+ elem.lock_cnt = data->lock_cnt; >+ elem.block_cnt = data->block_cnt; >+ elem.lock_time = data->time_hold; >+ elem.block_time = data->time_block; >+ if (copy_to_guest_offset(p->pc->data, p->pc->nr_elem, &elem, 1)) >+ { >+ p->rc = -EFAULT; >+ return; >+ } >+ } >+ p->pc->nr_elem++; >+ >+ return; >+} >+ >+/* Dom0 control of lock profiling */ >+int spinlock_profile_control(xen_sysctl_lockprof_op_t *pc) >+{ >+ int rc; >+ spinlock_profile_ucopy_t par; >+ >+ rc = 0; >+ switch (pc->cmd) >+ { >+ case XEN_SYSCTL_LOCKPROF_reset: >+ spinlock_profile_reset(''\0''); >+ break; >+ case XEN_SYSCTL_LOCKPROF_query: >+ pc->nr_elem = 0; >+ par.rc = 0; >+ par.pc = pc; >+ spinlock_profile_iterate(spinlock_profile_ucopy_elem, &par); >+ pc->time = NOW() - lock_profile_start; >+ rc = par.rc; >+ break; >+ default: >+ rc = -EINVAL; >+ break; >+ } >+ return rc; >+} >+ >+void _lock_profile_register_struct(int32_t type, >+ struct lock_profile_qhead *qhead, int32_t idx, char *name) >+{ >+ qhead->idx = idx; >+ spin_lock(&lock_profile_lock); >+ qhead->head_q = lock_profile_ancs[type].head_q; >+ lock_profile_ancs[type].head_q = qhead; >+ lock_profile_ancs[type].name = name; >+ spin_unlock(&lock_profile_lock); >+ return; >+} >+ >+void _lock_profile_deregister_struct(int32_t type, >+ struct lock_profile_qhead *qhead) >+{ >+ struct lock_profile_qhead **q; >+ >+ spin_lock(&lock_profile_lock); >+ for (q = &lock_profile_ancs[type].head_q; *q; q = &((*q)->head_q)) >+ { >+ if (*q == qhead) >+ { >+ *q = qhead->head_q; >+ break; >+ } >+ } >+ spin_unlock(&lock_profile_lock); >+ return; >+} >+ >+static int __init lock_prof_init(void) >+{ >+ struct lock_profile **q; >+ >+ for (q = &__lock_profile_start; q < &__lock_profile_end; q++) >+ { >+ (*q)->next = lock_profile_glb_q.elem_q; >+ lock_profile_glb_q.elem_q = *q; >+ } >+ _lock_profile_register_struct(LOCKPROF_TYPE_GLOBAL, &lock_profile_glb_q, >+ 0, "Global lock"); >+ return 0; >+} >+__initcall(lock_prof_init); >+#endif >diff -r 71c859535c6b -r 10c0942ed240 xen/common/sysctl.c >--- a/xen/common/sysctl.c Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/common/sysctl.c Wed Oct 14 09:07:51 2009 +0100 >@@ -29,6 +29,9 @@ > > extern long arch_do_sysctl( > struct xen_sysctl *op, XEN_GUEST_HANDLE(xen_sysctl_t) u_sysctl); >+#ifdef LOCK_PROFILE >+extern int spinlock_profile_control(xen_sysctl_lockprof_op_t *pc); >+#endif > > long do_sysctl(XEN_GUEST_HANDLE(xen_sysctl_t) u_sysctl) > { >@@ -144,6 +147,15 @@ long do_sysctl(XEN_GUEST_HANDLE(xen_sysc > break; > #endif > >+#ifdef LOCK_PROFILE >+ case XEN_SYSCTL_lockprof_op: >+ { >+ ret = spinlock_profile_control(&op->u.lockprof_op); >+ if ( copy_to_guest(u_sysctl, op, 1) ) >+ ret = -EFAULT; >+ } >+ break; >+#endif > case XEN_SYSCTL_debug_keys: > { > char c; >diff -r 71c859535c6b -r 10c0942ed240 xen/include/public/sysctl.h >--- a/xen/include/public/sysctl.h Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/include/public/sysctl.h Wed Oct 14 09:07:51 2009 +0100 >@@ -396,7 +396,7 @@ struct xen_sysctl_pm_op { > struct xen_get_cpufreq_para get_para; > struct xen_set_cpufreq_gov set_gov; > struct xen_set_cpufreq_para set_para; >- uint64_t get_avgfreq; >+ uint64_aligned_t get_avgfreq; > struct xen_get_cputopo get_topo; > uint32_t set_sched_opt_smt; > uint32_t get_max_cstate; >@@ -453,6 +453,38 @@ struct xen_sysctl_page_offline_op { > #define PG_ONLINE_BROKEN PG_OFFLINE_BROKEN > > #define PG_OFFLINE_OWNER_SHIFT 16 >+ >+#define XEN_SYSCTL_lockprof_op 11 >+/* Sub-operations: */ >+#define XEN_SYSCTL_LOCKPROF_reset 1 /* Reset all profile data to zero. */ >+#define XEN_SYSCTL_LOCKPROF_query 2 /* Get lock profile information. */ >+/* Record-type: */ >+#define LOCKPROF_TYPE_GLOBAL 0 /* global lock, idx meaningless */ >+#define LOCKPROF_TYPE_PERDOM 1 /* per-domain lock, idx is domid */ >+#define LOCKPROF_TYPE_N 2 /* number of types */ >+struct xen_sysctl_lockprof_data { >+ char name[40]; /* lock name (may include up to 2 %d specifiers >) */ >+ int32_t type; /* LOCKPROF_TYPE_??? */ >+ int32_t idx; /* index (e.g. domain id) */ >+ uint64_aligned_t lock_cnt; /* # of locking succeeded */ >+ uint64_aligned_t block_cnt; /* # of wait for lock */ >+ uint64_aligned_t lock_time; /* nsecs lock held */ >+ uint64_aligned_t block_time; /* nsecs waited for lock */ >+}; >+typedef struct xen_sysctl_lockprof_data xen_sysctl_lockprof_data_t; >+DEFINE_XEN_GUEST_HANDLE(xen_sysctl_lockprof_data_t); >+struct xen_sysctl_lockprof_op { >+ /* IN variables. */ >+ uint32_t cmd; /* XEN_SYSCTL_LOCKPROF_??? */ >+ uint32_t max_elem; /* size of output buffer */ >+ /* OUT variables (query only). */ >+ uint32_t nr_elem; /* number of elements available */ >+ uint64_aligned_t time; /* nsecs of profile measurement */ >+ /* profile information (or NULL) */ >+ XEN_GUEST_HANDLE_64(xen_sysctl_lockprof_data_t) data; >+}; >+typedef struct xen_sysctl_lockprof_op xen_sysctl_lockprof_op_t; >+DEFINE_XEN_GUEST_HANDLE(xen_sysctl_lockprof_op_t); > > struct xen_sysctl { > uint32_t cmd; >@@ -471,6 +503,7 @@ struct xen_sysctl { > struct xen_sysctl_cpu_hotplug cpu_hotplug; > struct xen_sysctl_pm_op pm_op; > struct xen_sysctl_page_offline_op page_offline; >+ struct xen_sysctl_lockprof_op lockprof_op; > uint8_t pad[128]; > } u; > }; >diff -r 71c859535c6b -r 10c0942ed240 xen/include/xen/sched.h >--- a/xen/include/xen/sched.h Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/include/xen/sched.h Wed Oct 14 09:07:51 2009 +0100 >@@ -276,6 +276,8 @@ struct domain > > /* transcendent memory, auto-allocated on first tmem op by each domain > */ > void *tmem; >+ >+ struct lock_profile_qhead profile_head; > }; > > struct domain_setup_info >diff -r 71c859535c6b -r 10c0942ed240 xen/include/xen/spinlock.h >--- a/xen/include/xen/spinlock.h Wed Oct 14 08:58:47 2009 +0100 >+++ b/xen/include/xen/spinlock.h Wed Oct 14 09:07:51 2009 +0100 >@@ -19,16 +19,109 @@ struct lock_debug { }; > #define spin_debug_disable() ((void)0) > #endif > >+#ifdef LOCK_PROFILE >+/* >+ lock profiling on: >+ >+ Global locks which should be subject to profiling must be declared via >+ DEFINE_SPINLOCK. >+ >+ For locks in structures further measures are necessary: >+ - the structure definition must include a profile_head with exactly this >+ name: >+ >+ struct lock_profile_qhead profile_head; >+ >+ - the single locks which are subject to profiling have to be initialized >+ via >+ >+ spin_lock_init_prof(ptr, lock); >+ >+ with ptr being the main structure pointer and lock the spinlock field >+ >+ - each structure has to be added to profiling with >+ >+ lock_profile_register_struct(type, ptr, idx, print); >+ >+ with: >+ type: something like LOCKPROF_TYPE_PERDOM >+ ptr: pointer to the structure >+ idx: index of that structure, e.g. domid >+ print: descriptive string like "domain" >+ >+ - removing of a structure is done via >+ >+ lock_profile_deregister_struct(type, ptr); >+*/ >+ >+struct lock_profile { >+ struct lock_profile *next; /* forward link */ >+ char *name; /* lock name */ >+ u64 lock_cnt; /* # of complete locking ops */ >+ u64 block_cnt; /* # of complete wait for lock */ >+ s64 time_hold; /* cumulated lock time */ >+ s64 time_block; /* cumulated wait time */ >+ s64 time_locked; /* system time of last locking */ >+}; >+ >+struct lock_profile_qhead { >+ struct lock_profile_qhead *head_q; /* next head of this type */ >+ struct lock_profile *elem_q; /* first element in q */ >+ int32_t idx; /* index for printout */ >+}; >+ >+#define _LOCK_PROFILE(name) { 0, name, 0, 0, 0, 0, 0 } >+#define _LOCK_NO_PROFILE _LOCK_PROFILE(NULL) >+#define _LOCK_PROFILE_PTR(name) > \ >+ static struct lock_profile *__lock_profile_##name __attribute_used__ > \ >+ __attribute__ ((__section__(".lockprofile.data"))) = &name.profile >+#define _SPIN_LOCK_UNLOCKED(x) { _RAW_SPIN_LOCK_UNLOCKED, 0xfffu, 0, > \ >+ _LOCK_DEBUG, x } >+#define SPIN_LOCK_UNLOCKED _SPIN_LOCK_UNLOCKED(_LOCK_NO_PROFILE) >+#define DEFINE_SPINLOCK(l) > \ >+ spinlock_t l = _SPIN_LOCK_UNLOCKED(_LOCK_PROFILE(#l)); > \ >+ _LOCK_PROFILE_PTR(l) >+ >+#define spin_lock_init_prof(s, l) > \ >+ do { > \ >+ (s)->l = (spinlock_t)_SPIN_LOCK_UNLOCKED(_LOCK_PROFILE(#l)); > \ >+ (s)->l.profile.next = (s)->profile_head.elem_q; \>+ (s)->profile_head.elem_q = &((s)->l.profile); \>+ } while(0) >+ >+void _lock_profile_register_struct(int32_t, struct lock_profile_qhead *, > \ >+ int32_t, char *); >+void _lock_profile_deregister_struct(int32_t, struct lock_profile_qhead *); >+ >+#define lock_profile_register_struct(type, ptr, idx, print) > \ >+ _lock_profile_register_struct(type, &((ptr)->profile_head), idx, print) >+#define lock_profile_deregister_struct(type, ptr) > \ >+ _lock_profile_deregister_struct(type, &((ptr)->profile_head)) >+ >+#else >+ >+struct lock_profile { }; >+struct lock_profile_qhead { }; >+ >+#define SPIN_LOCK_UNLOCKED > \ >+ { _RAW_SPIN_LOCK_UNLOCKED, 0xfffu, 0, _LOCK_DEBUG, { } } >+#define DEFINE_SPINLOCK(l) spinlock_t l = SPIN_LOCK_UNLOCKED >+ >+#define spin_lock_init_prof(s, l) spin_lock_init(&((s)->l)) >+#define lock_profile_register_struct(type, ptr, idx, print) >+#define lock_profile_deregister_struct(type, ptr) >+ >+#endif >+ > typedef struct { > raw_spinlock_t raw; > u16 recurse_cpu:12; > u16 recurse_cnt:4; > struct lock_debug debug; >+ struct lock_profile profile; > } spinlock_t; > > >-#define SPIN_LOCK_UNLOCKED { _RAW_SPIN_LOCK_UNLOCKED, 0xfffu, 0, >_LOCK_DEBUG } >-#define DEFINE_SPINLOCK(l) spinlock_t l = SPIN_LOCK_UNLOCKED > #define spin_lock_init(l) (*(l) = (spinlock_t)SPIN_LOCK_UNLOCKED) > > typedef struct { > >_______________________________________________ >Xen-changelog mailing list >Xen-changelog@lists.xensource.com >http://lists.xensource.com/xen-changelog_______________________________________________ Xen-devel mailing list Xen-devel@lists.xensource.com http://lists.xensource.com/xen-devel
Juergen Gross
2009-Oct-15 05:03 UTC
Re: [Xen-devel] Re: [Xen-changelog] [xen-unstable] Spinlock profiling (enable in buildwith lock_profile=y)
Masaki Kanno wrote:> Hi, > > I got the following error. > > gcc -O1 -fno-omit-frame-pointer -fno-optimize-sibling-calls -m32 -march > =i686 -g -fno-strict-aliasing -std=gnu99 -Wall -Wstrict-prototypes -Wno- > unused-value -Wdeclaration-after-statement -D__XEN_TOOLS__ -MMD -MF . > xenlockprof.o.d -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 - > D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -mno-tls-direct-seg-refs - > Werror -I ../../tools/python/xen/lowlevel/xc -I ../../tools/libxc -I ../.. > /tools/include -c -o xenlockprof.o xenlockprof.c > cc1: warnings being treated as errors > xenlockprof.c: In function ‘main’: > xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, > but argument 3 has type ‘uint64_t’ > xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, > but argument 5 has type ‘uint64_t’ > make[4]: *** [xenlockprof.o] Error 1 > make[4]: Leaving directory `/xen/xen-unstable.hg/tools/misc'' > make[3]: *** [subdir-install-misc] Error 2 > make[3]: Leaving directory `/xen/xen-unstable.hg/tools'' > make[2]: *** [subdirs-install] Error 2 > make[2]: Leaving directory `/xen/xen-unstable.hg/tools'' > make[1]: *** [install-tools] Error 2 > make[1]: Leaving directory `/xen/xen-unstable.hg'' > make: *** [world] Error 2Sorry, I''ve got no 32 bit machine to test. Attached patch should correct this. Juergen -- Juergen Gross Principal Developer Operating Systems TSP ES&S SWE OS6 Telephone: +49 (0) 89 636 47950 Fujitsu Technolgy Solutions e-mail: juergen.gross@ts.fujitsu.com Otto-Hahn-Ring 6 Internet: ts.fujitsu.com D-81739 Muenchen Company details: ts.fujitsu.com/imprint.html _______________________________________________ Xen-devel mailing list Xen-devel@lists.xensource.com http://lists.xensource.com/xen-devel
Masaki Kanno
2009-Oct-15 07:30 UTC
Re: [Xen-devel] Re: [Xen-changelog] [xen-unstable] Spinlock profiling(enable in buildwith lock_profile=y)
Thu, 15 Oct 2009 07:03:38 +0200, Juergen Gross wrote:>Masaki Kanno wrote: >> Hi, >> >> I got the following error. >> >> gcc -O1 -fno-omit-frame-pointer -fno-optimize-sibling-calls -m32 -march >> =i686 -g -fno-strict-aliasing -std=gnu99 -Wall -Wstrict-prototypes -Wno- >> unused-value -Wdeclaration-after-statement -D__XEN_TOOLS__ -MMD -MF . >> xenlockprof.o.d -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 - >> D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -mno-tls-direct-seg-refs - >> Werror -I ../../tools/python/xen/lowlevel/xc -I ../../tools/libxc -I ../.. >> /tools/include -c -o xenlockprof.o xenlockprof.c >> cc1: warnings being treated as errors >> xenlockprof.c: In function ‘main’: >> xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, >> but argument 3 has type ‘uint64_t’ >> xenlockprof.c:128: warning: format ‘%12ld’ expects type ‘long int’, >> but argument 5 has type ‘uint64_t’ >> make[4]: *** [xenlockprof.o] Error 1 >> make[4]: Leaving directory `/xen/xen-unstable.hg/tools/misc'' >> make[3]: *** [subdir-install-misc] Error 2 >> make[3]: Leaving directory `/xen/xen-unstable.hg/tools'' >> make[2]: *** [subdirs-install] Error 2 >> make[2]: Leaving directory `/xen/xen-unstable.hg/tools'' >> make[1]: *** [install-tools] Error 2 >> make[1]: Leaving directory `/xen/xen-unstable.hg'' >> make: *** [world] Error 2 > >Sorry, I''ve got no 32 bit machine to test. > >Attached patch should correct this. >Hi Juergen, Thank you! The error gets fixed by your patch. Best regards, Kan _______________________________________________ Xen-devel mailing list Xen-devel@lists.xensource.com http://lists.xensource.com/xen-devel