WARNING - OLD ARCHIVES

This is an archived copy of the Xen.org mailing list, which we have preserved to ensure that existing links to archives are not broken. The live archive, which contains the latest emails, can be found at http://lists.xen.org/
   
 
 
Xen 
 
Home Products Support Community News
 
   
 

xen-devel

Re: [Xen-devel] [Patch] support of lock profiling in Xen

To: Keir Fraser <keir.fraser@xxxxxxxxxxxxx>
Subject: Re: [Xen-devel] [Patch] support of lock profiling in Xen
From: Juergen Gross <juergen.gross@xxxxxxxxxxxxxx>
Date: Fri, 09 Oct 2009 10:27:08 +0200
Cc: "xen-devel@xxxxxxxxxxxxxxxxxxx" <xen-devel@xxxxxxxxxxxxxxxxxxx>
Delivery-date: Fri, 09 Oct 2009 01:27:50 -0700
Dkim-signature: v=1; a=rsa-sha256; c=simple/simple; d=ts.fujitsu.com; i=juergen.gross@xxxxxxxxxxxxxx; q=dns/txt; s=s1536b; t=1255076930; x=1286612930; h=from:sender:reply-to:subject:date:message-id:to:cc: mime-version:content-transfer-encoding:content-id: content-description:resent-date:resent-from:resent-sender: resent-to:resent-cc:resent-message-id:in-reply-to: references:list-id:list-help:list-unsubscribe: list-subscribe:list-post:list-owner:list-archive; z=From:=20Juergen=20Gross=20<juergen.gross@xxxxxxxxxxxxxx> |Subject:=20Re:=20[Xen-devel]=20[Patch]=20support=20of=20 lock=20profiling=20in=20Xen|Date:=20Fri,=2009=20Oct=20200 9=2010:27:08=20+0200|Message-ID:=20<4ACEF3DC.3040708@xxxx ujitsu.com>|To:=20Keir=20Fraser=20<keir.fraser@xxxxxxxxxx com>|CC:=20"xen-devel@xxxxxxxxxxxxxxxxxxx"=20<xen-devel@l ists.xensource.com>|MIME-Version:=201.0|In-Reply-To:=20<C 6F373BD.16DD6%keir.fraser@xxxxxxxxxxxxx>|References:=20<C 6F373BD.16DD6%keir.fraser@xxxxxxxxxxxxx>; bh=gyWi0eTTScVQIt4NM1z0ZzyHj5cRwJO5bb+vbYxMCVg=; b=OOQvt9j3L+qr9XekLjMeIpQKfDl8BSns+69ydBoStv+GoJtrHB6ji6c3 mXDEoO0iOReZsl/oja/3VEeh0EmvyBQu6UceuceKs0PZZmruaWTOrNQPA Yd3WPIG5K81BMn9dDShqv5AbcQYV+hhvcuzrKi4vikU4Yv98RKH/ff4dj figWi5+DlcEu4mZm0OL2JFRiJQPcFcyVWHD2RSDzJJGY8X8ck/nmz2owE CI7yz26+MZGVty9uoHaGLXK+wHksp;
Domainkey-signature: s=s1536a; d=ts.fujitsu.com; c=nofws; q=dns; h=X-SBRSScore:X-IronPort-AV:Received:X-IronPort-AV: Received:Received:Message-ID:Date:From:Organization: User-Agent:MIME-Version:To:CC:Subject:References: In-Reply-To:X-Enigmail-Version:Content-Type; b=FMOasGNwUNYafy+6xcHoTXexWrykaP1QQLhxFq/txz2dvoX9Nf32SJcn JZA70xwnI+r1Re9qHxS1QlCvLbRud77H3w4AuReEKvEJs+rsUhTY7nSnu VyvZBrelF/2cirbkPxpzjeyanyHUufSE1NxysxvlAzJjsMevtRGXmg5T+ IdjRcjD4LJGrvZcMUBgTuZ6wyXbDAu7cvwwfHvNg1U17UTeftC6vcb2mh 19YdBtgQfH2mlEvYaobkn+aQr98kx;
Envelope-to: www-data@xxxxxxxxxxxxxxxxxxx
In-reply-to: <C6F373BD.16DD6%keir.fraser@xxxxxxxxxxxxx>
List-help: <mailto:xen-devel-request@lists.xensource.com?subject=help>
List-id: Xen developer discussion <xen-devel.lists.xensource.com>
List-post: <mailto:xen-devel@lists.xensource.com>
List-subscribe: <http://lists.xensource.com/mailman/listinfo/xen-devel>, <mailto:xen-devel-request@lists.xensource.com?subject=subscribe>
List-unsubscribe: <http://lists.xensource.com/mailman/listinfo/xen-devel>, <mailto:xen-devel-request@lists.xensource.com?subject=unsubscribe>
Organization: Fujitsu Technology Solutions
References: <C6F373BD.16DD6%keir.fraser@xxxxxxxxxxxxx>
Sender: xen-devel-bounces@xxxxxxxxxxxxxxxxxxx
User-agent: Mozilla-Thunderbird 2.0.0.22 (X11/20090707)
Keir Fraser wrote:
> On 08/10/2009 10:35, "Juergen Gross" <juergen.gross@xxxxxxxxxxxxxx> wrote:
> 
>>> After all, now I think about it, an 'arbitrary' index specified to
>>> spinlock_init() is just making our lives more complicated if it will
>>> basically *always* be a domid. And knowing at a higher level which locks are
>>> actually per-domain could help your pretty printing?
>> I thought in this direction, too.
>> I would, however, try not to limit it to per domain locks, even if the first
>> implementation would support only global locks and per domain locks.
>>
>> The perfc style declarations should only be necessary for the dynamically
>> initialized locks, and those could live near the domain structure definition
>> (or any other structure where they are needed).
>>
>> I think the statically defined locks can be handled via an own data section
>> requiring no centrally defined index.
> 
> Okay, well this all sounds an acceptable kind of direction. Worth spinning
> another patch.

Here it is.
I managed to avoid the perfc-like stuff completely.

Included are 2 global locks defined for profiling and 2 locks in the domain
structure.

I've added some comments in spinlock.h how to use the profiling in structures.

Tested by compilation and boot of Dom0 with and without profiling enabled.


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@xxxxxxxxxxxxxx
Otto-Hahn-Ring 6                        Internet: ts.fujitsu.com
D-81739 Muenchen                 Company details: ts.fujitsu.com/imprint.html
Support of lock profiling

Signed-off-by: juergen.gross@xxxxxxxxxxxxxx

diff -r 729567f615c1 tools/libxc/xc_misc.c
--- a/tools/libxc/xc_misc.c     Wed Oct 07 16:29:03 2009 +0100
+++ b/tools/libxc/xc_misc.c     Fri Oct 09 09:35:45 2009 +0200
@@ -121,6 +121,30 @@
     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;
+}
+
 int xc_getcpuinfo(int xc_handle, int max_cpus,
                   xc_cpuinfo_t *info, int *nr_cpus)
 {
diff -r 729567f615c1 tools/libxc/xenctrl.h
--- a/tools/libxc/xenctrl.h     Wed Oct 07 16:29:03 2009 +0100
+++ b/tools/libxc/xenctrl.h     Fri Oct 09 09:35:45 2009 +0200
@@ -700,6 +700,14 @@
                      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 729567f615c1 tools/misc/Makefile
--- a/tools/misc/Makefile       Wed Oct 07 16:29:03 2009 +0100
+++ b/tools/misc/Makefile       Fri Oct 09 09:35:45 2009 +0200
@@ -10,7 +10,7 @@
 
 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 := $(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 @@
 %.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 729567f615c1 tools/misc/xenlockprof.c
--- /dev/null   Thu Jan 01 00:00:00 1970 +0000
+++ b/tools/misc/xenlockprof.c  Fri Oct 09 09:35:45 2009 +0200
@@ -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@xxxxxxxxxxxxxx)
+ *        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 729567f615c1 xen/Rules.mk
--- a/xen/Rules.mk      Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/Rules.mk      Fri Oct 09 09:35:45 2009 +0200
@@ -6,6 +6,7 @@
 verbose       ?= n
 perfc         ?= n
 perfc_arrays  ?= n
+lock_profile  ?= n
 crash_debug   ?= n
 frame_pointer ?= n
 
@@ -49,6 +50,7 @@
 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
 
 ifneq ($(max_phys_cpus),)
diff -r 729567f615c1 xen/arch/x86/pci.c
--- a/xen/arch/x86/pci.c        Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/arch/x86/pci.c        Fri Oct 09 09:35:45 2009 +0200
@@ -8,7 +8,7 @@
 #include <xen/pci.h>
 #include <asm/io.h>
 
-static DEFINE_SPINLOCK(pci_config_lock);
+DEFINE_SPINLOCK_STATIC_PROF(pci_config_lock);
 
 uint32_t pci_conf_read(uint32_t cf8, uint8_t offset, uint8_t bytes)
 {
diff -r 729567f615c1 xen/arch/x86/smp.c
--- a/xen/arch/x86/smp.c        Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/arch/x86/smp.c        Fri Oct 09 09:35:45 2009 +0200
@@ -201,7 +201,7 @@
     local_irq_restore(flags);
 }
 
-static DEFINE_SPINLOCK(flush_lock);
+DEFINE_SPINLOCK_STATIC_PROF(flush_lock);
 static cpumask_t flush_cpumask;
 static const void *flush_va;
 static unsigned int flush_flags;
diff -r 729567f615c1 xen/arch/x86/xen.lds.S
--- a/xen/arch/x86/xen.lds.S    Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/arch/x86/xen.lds.S    Fri Oct 09 09:35:45 2009 +0200
@@ -62,6 +62,13 @@
        *(.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 = .;
   .init.text : {
diff -r 729567f615c1 xen/common/domain.c
--- a/xen/common/domain.c       Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/common/domain.c       Fri Oct 09 09:35:45 2009 +0200
@@ -226,8 +226,8 @@
     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);
@@ -884,6 +884,29 @@
     return -ENOSYS;
 }
 
+#ifdef LOCK_PROFILE
+void domain_lock_prof_func(lock_profile_subfunc *sub, void *par)
+{
+    struct domain *d;
+
+    rcu_read_lock(&domlist_read_lock);
+    for_each_domain(d)
+    {
+        sub((struct lock_profile_data_array *)(&d->lock_profile_array),
+           LOCKPROF_TYPE_PERDOM, "domain", d->domain_id, par);
+    }
+    rcu_read_unlock(&domlist_read_lock);
+    return;
+}
+
+static int __init domain_lock_prof_init(void)
+{
+    lock_profile_funcs[LOCKPROF_TYPE_PERDOM] = domain_lock_prof_func;
+    return 0;
+}
+__initcall(domain_lock_prof_init);
+#endif
+
 /*
  * Local variables:
  * mode: C
diff -r 729567f615c1 xen/common/keyhandler.c
--- a/xen/common/keyhandler.c   Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/common/keyhandler.c   Fri Oct 09 09:35:45 2009 +0200
@@ -347,6 +347,20 @@
 };
 #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 @@
     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 729567f615c1 xen/common/spinlock.c
--- a/xen/common/spinlock.c     Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/common/spinlock.c     Fri Oct 09 09:35:45 2009 +0200
@@ -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,104 @@
 
 #endif
 
+#ifdef LOCK_PROFILE
+
+#define LOCK_PROFILE_REL                                                    \
+    if (lock->profile.data)                                                 \
+    {                                                                       \
+        lock->profile.data->time_hold += NOW() - lock->profile.time_locked; \
+        lock->profile.data->lock_cnt++;                                     \
+    }
+#define LOCK_PROFILE_VAR    s_time_t block = 0
+#define LOCK_PROFILE_BLOCK  if (lock->profile.data) block = block ? : NOW();
+#define LOCK_PROFILE_GOT                                              \
+    if (lock->profile.data)                                           \
+    {                                                                 \
+        lock->profile.time_locked = NOW();                            \
+        if (block)                                                    \
+        {                                                             \
+            lock->profile.data->time_block +=                         \
+                lock->profile.time_locked - block;                    \
+            lock->profile.data->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 +156,35 @@
 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;
+    if (lock->profile.data)
+    {
+        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.data)
+    {
+        lock->profile.data->time_block += NOW() - block;
+        lock->profile.data->block_cnt++;
+    }
+#else
     check_lock(&lock->debug);
     do { mb(); } while ( _raw_spin_is_locked(&lock->raw) );
+#endif
     mb();
 }
 
@@ -248,3 +322,189 @@
     check_lock(&lock->debug);
     return _raw_rw_is_write_locked(&lock->raw);
 }
+
+#ifdef LOCK_PROFILE
+extern struct lock_profile_data __lock_profile_start;
+extern struct lock_profile_data __lock_profile_end;
+
+static s_time_t lock_profile_start = 0;
+
+lock_profile_func *lock_profile_funcs[LOCKPROF_TYPE_N];
+
+void spinlock_profile_iterate(lock_profile_subfunc *sub, void *par)
+{
+    int  i;
+
+    for (i = 0; i < LOCKPROF_TYPE_N; i++)
+    {
+        if (lock_profile_funcs[i])
+           lock_profile_funcs[i](sub, par);
+    }
+    return;
+}
+
+void spinlock_profile_print_array(struct lock_profile_data_array *array,
+    uint32_t type, char *txt, uint32_t idx, void *par)
+{
+    int  i;
+    struct lock_profile_data *q;
+
+    for (i = 0; i < array->cnt; i++)
+    {
+        q = array->array + i;
+        if (q->name == NULL)
+            continue;
+        printk("%s %d %s:\n", txt, idx, q->name);
+        printk("  lock:%12ld(%08X:%08X), block:%12ld(%08X:%08X)\n",
+            q->lock_cnt, (u32)(q->time_hold >> 32), (u32)q->time_hold,
+            q->block_cnt, (u32)(q->time_block >> 32), (u32)q->time_block);
+    }
+    return;
+}
+
+void spinlock_profile_printall(unsigned char key)
+{
+    s_time_t now = NOW();
+    s_time_t diff;
+    struct lock_profile_data *q;
+
+    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);
+    for (q = &__lock_profile_start; q < &__lock_profile_end; q++)
+    {
+        printk("%s:\n", q->name);
+        printk("  lock:%12ld(%08X:%08X), block:%12ld(%08X:%08X)\n",
+            q->lock_cnt, (u32)(q->time_hold >> 32), (u32)q->time_hold,
+            q->block_cnt, (u32)(q->time_block >> 32), (u32)q->time_block);
+    }
+    spinlock_profile_iterate(spinlock_profile_print_array, NULL);
+    return;
+}
+
+void spinlock_profile_reset_array(struct lock_profile_data_array *array,
+    uint32_t type, char *txt, uint32_t idx, void *par)
+{
+    int  i;
+
+    for (i = 0; i < array->cnt; i++)
+    {
+        array->array[i].lock_cnt = 0;
+        array->array[i].block_cnt = 0;
+        array->array[i].time_hold = 0;
+        array->array[i].time_block = 0;
+    }
+    return;
+}
+
+void spinlock_profile_reset(unsigned char key)
+{
+    s_time_t now = NOW();
+    struct lock_profile_data *q;
+
+    if ( key != '\0' )
+        printk("Xen lock profile info RESET (now = %08X:%08X)\n",
+            (u32)(now>>32), (u32)now);
+    lock_profile_start = now;
+    for (q = &__lock_profile_start; q < &__lock_profile_end; q++)
+    {
+        q->lock_cnt = 0;
+        q->block_cnt = 0;
+        q->time_hold = 0;
+        q->time_block = 0;
+    }
+    spinlock_profile_iterate(spinlock_profile_reset_array, NULL);
+    return;
+}
+
+typedef struct {
+    xen_sysctl_lockprof_op_t *pc;
+    int                      rc;
+} spinlock_profile_ucopy_t;
+
+void spinlock_profile_ucopy_array(struct lock_profile_data_array *array,
+    uint32_t type, char *txt, uint32_t idx, void *par)
+{
+    int  i;
+    struct lock_profile_data *q;
+    spinlock_profile_ucopy_t *p;
+    xen_sysctl_lockprof_data_t elem;
+
+    p = (spinlock_profile_ucopy_t *)par;
+    if (p->rc)
+        return;
+
+    for (i = 0; i < array->cnt; i++)
+    {
+        q = array->array + i;
+        if (q->name == NULL)
+            continue;
+        if (p->pc->nr_elem < p->pc->max_elem)
+        {
+            safe_strcpy(elem.name, q->name);
+            elem.type = type;
+            elem.idx = idx;
+            elem.lock_cnt = q->lock_cnt;
+            elem.block_cnt = q->block_cnt;
+            elem.lock_time = q->time_hold;
+            elem.block_time = q->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;
+    struct lock_profile_data *q;
+    xen_sysctl_lockprof_data_t elem;
+
+    rc = 0;
+    switch (pc->cmd)
+    {
+    case XEN_SYSCTL_LOCKPROF_reset:
+        spinlock_profile_reset('\0');
+        break;
+    case XEN_SYSCTL_LOCKPROF_query:
+        q = &__lock_profile_start;
+       pc->nr_elem = 0;
+       par.rc = 0;
+       par.pc = pc;
+        for (q = &__lock_profile_start; q < &__lock_profile_end; q++)
+        {
+            if (pc->nr_elem < pc->max_elem)
+            {
+                safe_strcpy(elem.name, q->name);
+                elem.type = LOCKPROF_TYPE_GLOBAL;
+                elem.idx = 0;
+                elem.lock_cnt = q->lock_cnt;
+                elem.block_cnt = q->block_cnt;
+                elem.lock_time = q->time_hold;
+                elem.block_time = q->time_block;
+                if (copy_to_guest_offset(pc->data, pc->nr_elem, &elem, 1))
+                {
+                    return -EFAULT;
+                }
+            }
+            pc->nr_elem++;
+        }
+        spinlock_profile_iterate(spinlock_profile_ucopy_array, &par);
+        pc->time = NOW() - lock_profile_start;
+       rc = par.rc;
+        break;
+    default:
+        rc = -EINVAL;
+        break;
+    }
+    return rc;
+}
+#endif
diff -r 729567f615c1 xen/common/sysctl.c
--- a/xen/common/sysctl.c       Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/common/sysctl.c       Fri Oct 09 09:35:45 2009 +0200
@@ -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 @@
     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 729567f615c1 xen/include/public/sysctl.h
--- a/xen/include/public/sysctl.h       Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/include/public/sysctl.h       Fri Oct 09 09:35:45 2009 +0200
@@ -454,6 +454,38 @@
 
 #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_t lock_cnt;     /* # of locking succeeded */
+    uint64_t block_cnt;    /* # of wait for lock */
+    uint64_t lock_time;    /* nsecs lock held */
+    uint64_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_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;
     uint32_t interface_version; /* XEN_SYSCTL_INTERFACE_VERSION */
@@ -471,6 +503,7 @@
         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 729567f615c1 xen/include/xen/sched.h
--- a/xen/include/xen/sched.h   Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/include/xen/sched.h   Fri Oct 09 09:35:45 2009 +0200
@@ -276,6 +276,8 @@
 
     /* transcendent memory, auto-allocated on first tmem op by each domain */
     void *tmem;
+
+    SPIN_LOCK_PROF_ARRAY(5);
 };
 
 struct domain_setup_info
diff -r 729567f615c1 xen/include/xen/spinlock.h
--- a/xen/include/xen/spinlock.h        Wed Oct 07 16:29:03 2009 +0100
+++ b/xen/include/xen/spinlock.h        Fri Oct 09 09:35:45 2009 +0200
@@ -19,17 +19,119 @@
 #define spin_debug_disable() ((void)0)
 #endif
 
+#ifdef LOCK_PROFILE
+/*
+    lock profiling on:
+
+    Global locks which sould be subject to profiling must be declared via
+    DEFINE_SPINLOCK_PROF or DEFINE_SPINLOCK_STATIC_PROF.
+
+    For locks in structures further measures are necessary:
+    The structure must include a profiling data section declared via
+    SPIN_LOCK_PROF_ARRAY(n)
+    with n being the maximum number of profiled locks in the structure.
+    Each lock in the structure subject to profiling has to be initialized via
+    spin_lock_init_prof(s, l)
+    with s being the structure pointer and l the lock field.
+    To print the profile data an iterator function must be registered (only if
+    LOCK_PROFILE is defined):
+
+    void func (lock_profile_subfunc *sub, void *par)
+    {
+        struct xyz *x;
+
+        for_each_xyz(x)
+        {
+            sub((struct lock_profile_data_array *)(&x->lock_profile_array),
+                LOCKPROF_TYPE_XYZ, "xyz", x->index, par);
+        }
+        return;
+    }
+
+    static int __init xyz_init(void)
+    {
+        lock_profile_funcs[LOCKPROF_TYPE_XYZ] = func;
+        return 0;
+    }
+    __initcall(xyz_init);
+*/
+
+struct lock_profile_data {
+    char *name;                  /* lock name, may contain %d for idx */
+    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 */
+};
+
+struct lock_profile {
+    struct lock_profile_data *data;        /* profiling data */
+    s64                      time_locked;  /* system time of last locking */
+};
+
+struct lock_profile_data_array {
+    int                      cnt;          /* # of populated entries */
+    struct lock_profile_data array[100];   /* profile data */
+};
+
+typedef void lock_profile_subfunc(struct lock_profile_data_array *,
+                                  uint32_t, char *, uint32_t, void *);
+typedef void lock_profile_func(lock_profile_subfunc *, void *);
+
+extern lock_profile_func *lock_profile_funcs[];
+
+#define _LOCK_PROFILE(name) { &name, 0 }
+#define _LOCK_NO_PROFILE { NULL, 0 }
+#define _LOCK_PROFILE_DATA(name)                                            \
+    struct lock_profile_data __lock_profile_##name                          \
+    __attribute__ ((__section__(".lockprofile.data"))) = { #name, 0, 0, 0, 0 };
+#define SPIN_LOCK_PROF_ARRAY(n)                                             \
+    struct {                                                                \
+        int                      cnt;                                       \
+        struct lock_profile_data data[n];                                   \
+    } lock_profile_array
+#define _spin_lock_init_prof(s, l)  ;                                       \
+    BUG_ON((s)->lock_profile_array.cnt >=                                   \
+        (sizeof((s)->lock_profile_array.data) /                             \
+        sizeof(struct lock_profile_data)));                                 \
+    (s)->l.profile.data =                                                   \
+        (s)->lock_profile_array.data + (s)->lock_profile_array.cnt;         \
+    (s)->lock_profile_array.cnt++;                                          \
+    (s)->l.profile.data->name = #l
+
+#else
+struct lock_profile { };
+#define _LOCK_PROFILE(name) { }
+#define _LOCK_NO_PROFILE { }
+#define _LOCK_PROFILE_DATA(name)
+#define SPIN_LOCK_PROF_ARRAY(n) struct { } lock_profile_array
+#define _spin_lock_init_prof(s, l)
+#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 _SPIN_LOCK_UNLOCKED(x) { _RAW_SPIN_LOCK_UNLOCKED, 0xfffu, 0,          \
+                                 _LOCK_DEBUG, x }
+#define SPIN_LOCK_UNLOCKED _SPIN_LOCK_UNLOCKED(_LOCK_NO_PROFILE)
+#define SPIN_LOCK_UNLOCKED_PROF(n)                                            \
+        _SPIN_LOCK_UNLOCKED(_LOCK_PROFILE(__lock_profile_##n))
 #define DEFINE_SPINLOCK(l) spinlock_t l = SPIN_LOCK_UNLOCKED
+#define DEFINE_SPINLOCK_PROF(l) _LOCK_PROFILE_DATA(l)                         \
+                           spinlock_t l = SPIN_LOCK_UNLOCKED_PROF(l)
+#define DEFINE_SPINLOCK_STATIC(l) static spinlock_t l = SPIN_LOCK_UNLOCKED
+#define DEFINE_SPINLOCK_STATIC_PROF(l) _LOCK_PROFILE_DATA(l)                  \
+                           static spinlock_t l = SPIN_LOCK_UNLOCKED_PROF(l)
 #define spin_lock_init(l) (*(l) = (spinlock_t)SPIN_LOCK_UNLOCKED)
+#define spin_lock_init_prof(s, l)                                             \
+    spin_lock_init(&(s)->l)                                                   \
+    _spin_lock_init_prof(s, l)
 
 typedef struct {
     raw_rwlock_t raw;
_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel