xen-devel.lists.xenproject.org archive mirror
 help / color / mirror / Atom feed
* [Xen-devel] [PATCH v4 0/5] enhance lock debugging
@ 2019-09-09 14:31 Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock Juergen Gross
                   ` (4 more replies)
  0 siblings, 5 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich, Volodymyr Babchuk,
	Roger Pau Monné

While hunting a locking problem in my core scheduling series I have
added some debugging aids to spinlock handling making it easier to
find the root cause for the problem.

Making use of the already existing lock profiling and enhancing it a
little bit produces some really valuable diagnostic data e.g. when a
NMI watchdog is triggering a crash.

Changes in V4:
- some comments by Jan Beulich addressed
- replaced patch 5 with another approach to make lock names unique

Changes in V3:
- rebase to current staging (after realizing that patch 4 still
  applied, but resulting in patching a wrong function)

Changes in V2:
- multiple comments addressed
- added patch 5

Juergen Gross (5):
  xen/spinlocks: in debug builds store cpu holding the lock
  xen: add new CONFIG_DEBUG_LOCKS option
  xen: print lock profile info in panic()
  xen: modify lock profiling interface
  xen: add function name to lock profiling data

 tools/libxc/xc_misc.c       |   1 +
 tools/misc/xenlockprof.c    |  17 +---
 xen/Kconfig.debug           |  10 ++-
 xen/arch/arm/xen.lds.S      |  13 ++--
 xen/arch/x86/domain.c       |   2 +-
 xen/arch/x86/xen.lds.S      |  13 ++--
 xen/common/domain.c         |   4 +-
 xen/common/keyhandler.c     |   2 +-
 xen/common/spinlock.c       | 185 ++++++++++++++++++++++++++++++++------------
 xen/common/sysctl.c         |   2 +-
 xen/drivers/char/console.c  |   4 +-
 xen/include/public/sysctl.h |  11 +--
 xen/include/xen/spinlock.h  |  75 +++++++++++-------
 13 files changed, 221 insertions(+), 118 deletions(-)

-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply	[flat|nested] 8+ messages in thread

* [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock
  2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
@ 2019-09-09 14:31 ` Juergen Gross
  2019-09-09 14:50   ` Jan Beulich
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 2/5] xen: add new CONFIG_DEBUG_LOCKS option Juergen Gross
                   ` (3 subsequent siblings)
  4 siblings, 1 reply; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich

Add the cpu currently holding the lock to struct lock_debug. This makes
analysis of locking errors easier and it can be tested whether the
correct cpu is releasing a lock again.

Signed-off-by: Juergen Gross <jgross@suse.com>
---
V2:
- adjust types (Jan Beulich)
V4:
- add define for bitfield size to store cpu number (Jan Beulich)
- make padding field unnamed (Jan Beulich)
---
 xen/common/spinlock.c      | 33 ++++++++++++++++++++++++++-------
 xen/include/xen/spinlock.h | 28 +++++++++++++++++++---------
 2 files changed, 45 insertions(+), 16 deletions(-)

diff --git a/xen/common/spinlock.c b/xen/common/spinlock.c
index 6bc52d70c0..1be1b5ebe6 100644
--- a/xen/common/spinlock.c
+++ b/xen/common/spinlock.c
@@ -13,9 +13,9 @@
 
 static atomic_t spin_debug __read_mostly = ATOMIC_INIT(0);
 
-static void check_lock(struct lock_debug *debug)
+static void check_lock(union lock_debug *debug)
 {
-    int irq_safe = !local_irq_is_enabled();
+    bool irq_safe = !local_irq_is_enabled();
 
     if ( unlikely(atomic_read(&spin_debug) <= 0) )
         return;
@@ -43,18 +43,21 @@ static void check_lock(struct lock_debug *debug)
      */
     if ( unlikely(debug->irq_safe != irq_safe) )
     {
-        int seen = cmpxchg(&debug->irq_safe, -1, irq_safe);
+        union lock_debug seen, new = { 0 };
 
-        if ( seen == !irq_safe )
+        new.irq_safe = irq_safe;
+        seen.val = cmpxchg(&debug->val, LOCK_DEBUG_INITVAL, new.val);
+
+        if ( !seen.unseen && seen.irq_safe == !irq_safe )
         {
             printk("CHECKLOCK FAILURE: prev irqsafe: %d, curr irqsafe %d\n",
-                   seen, irq_safe);
+                   seen.irq_safe, irq_safe);
             BUG();
         }
     }
 }
 
-static void check_barrier(struct lock_debug *debug)
+static void check_barrier(union lock_debug *debug)
 {
     if ( unlikely(atomic_read(&spin_debug) <= 0) )
         return;
@@ -70,7 +73,18 @@ static void check_barrier(struct lock_debug *debug)
      * However, if we spin on an IRQ-unsafe lock with IRQs disabled then that
      * is clearly wrong, for the same reason outlined in check_lock() above.
      */
-    BUG_ON(!local_irq_is_enabled() && (debug->irq_safe == 0));
+    BUG_ON(!local_irq_is_enabled() && !debug->irq_safe);
+}
+
+static void got_lock(union lock_debug *debug)
+{
+    debug->cpu = smp_processor_id();
+}
+
+static void rel_lock(union lock_debug *debug)
+{
+    ASSERT(debug->cpu == smp_processor_id());
+    debug->cpu = SPINLOCK_NO_CPU;
 }
 
 void spin_debug_enable(void)
@@ -87,6 +101,8 @@ void spin_debug_disable(void)
 
 #define check_lock(l) ((void)0)
 #define check_barrier(l) ((void)0)
+#define got_lock(l) ((void)0)
+#define rel_lock(l) ((void)0)
 
 #endif
 
@@ -150,6 +166,7 @@ void inline _spin_lock_cb(spinlock_t *lock, void (*cb)(void *), void *data)
             cb(data);
         arch_lock_relax();
     }
+    got_lock(&lock->debug);
     LOCK_PROFILE_GOT;
     preempt_disable();
     arch_lock_acquire_barrier();
@@ -181,6 +198,7 @@ void _spin_unlock(spinlock_t *lock)
     arch_lock_release_barrier();
     preempt_enable();
     LOCK_PROFILE_REL;
+    rel_lock(&lock->debug);
     add_sized(&lock->tickets.head, 1);
     arch_lock_signal();
 }
@@ -224,6 +242,7 @@ int _spin_trylock(spinlock_t *lock)
     if ( cmpxchg(&lock->tickets.head_tail,
                  old.head_tail, new.head_tail) != old.head_tail )
         return 0;
+    got_lock(&lock->debug);
 #ifdef CONFIG_LOCK_PROFILE
     if (lock->profile)
         lock->profile->time_locked = NOW();
diff --git a/xen/include/xen/spinlock.h b/xen/include/xen/spinlock.h
index 2c7415e23a..24405386a7 100644
--- a/xen/include/xen/spinlock.h
+++ b/xen/include/xen/spinlock.h
@@ -5,15 +5,24 @@
 #include <asm/spinlock.h>
 #include <asm/types.h>
 
+#define SPINLOCK_CPU_BITS  12
+
 #ifndef NDEBUG
-struct lock_debug {
-    s16 irq_safe; /* +1: IRQ-safe; 0: not IRQ-safe; -1: don't know yet */
+union lock_debug {
+    uint16_t val;
+#define LOCK_DEBUG_INITVAL 0xffff
+    struct {
+        uint16_t cpu:SPINLOCK_CPU_BITS;
+        uint16_t :(14 - SPINLOCK_CPU_BITS);
+        bool irq_safe:1;
+        bool unseen:1;
+    };
 };
-#define _LOCK_DEBUG { -1 }
+#define _LOCK_DEBUG { LOCK_DEBUG_INITVAL }
 void spin_debug_enable(void);
 void spin_debug_disable(void);
 #else
-struct lock_debug { };
+union lock_debug { };
 #define _LOCK_DEBUG { }
 #define spin_debug_enable() ((void)0)
 #define spin_debug_disable() ((void)0)
@@ -138,11 +147,12 @@ typedef union {
 
 typedef struct spinlock {
     spinlock_tickets_t tickets;
-    u16 recurse_cpu:12;
-#define SPINLOCK_NO_CPU 0xfffu
-    u16 recurse_cnt:4;
-#define SPINLOCK_MAX_RECURSE 0xfu
-    struct lock_debug debug;
+    u16 recurse_cpu:SPINLOCK_CPU_BITS;
+#define SPINLOCK_NO_CPU        ((1u << SPINLOCK_CPU_BITS) - 1)
+#define SPINLOCK_RECURSE_BITS  (16 - SPINLOCK_CPU_BITS)
+    u16 recurse_cnt:SPINLOCK_RECURSE_BITS;
+#define SPINLOCK_MAX_RECURSE   ((1u << SPINLOCK_RECURSE_BITS) - 1)
+    union lock_debug debug;
 #ifdef CONFIG_LOCK_PROFILE
     struct lock_profile *profile;
 #endif
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* [Xen-devel] [PATCH v4 2/5] xen: add new CONFIG_DEBUG_LOCKS option
  2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock Juergen Gross
@ 2019-09-09 14:31 ` Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 3/5] xen: print lock profile info in panic() Juergen Gross
                   ` (2 subsequent siblings)
  4 siblings, 0 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich

Instead of enabling debugging for debug builds only add a dedicated
Kconfig option for that purpose which defaults to DEBUG.

Signed-off-by: Juergen Gross <jgross@suse.com>
Reviewed-by: Jan Beulich <jbeulich@suse.com>
---
V2:
- rename to CONFIG_DEBUG_LOCKS (Jan Beulich)
---
 xen/Kconfig.debug          | 7 +++++++
 xen/common/spinlock.c      | 4 ++--
 xen/include/xen/spinlock.h | 2 +-
 3 files changed, 10 insertions(+), 3 deletions(-)

diff --git a/xen/Kconfig.debug b/xen/Kconfig.debug
index e10e314e25..1faaa3ba6a 100644
--- a/xen/Kconfig.debug
+++ b/xen/Kconfig.debug
@@ -51,6 +51,13 @@ config LOCK_PROFILE
 	  You can use serial console to print (and reset) using 'l' and 'L'
 	  respectively, or the 'xenlockprof' tool.
 
+config DEBUG_LOCKS
+	bool "Lock debugging"
+	default DEBUG
+	---help---
+	  Enable debugging features of lock handling.  Some additional
+	  checks will be performed when acquiring and releasing locks.
+
 config PERF_COUNTERS
 	bool "Performance Counters"
 	---help---
diff --git a/xen/common/spinlock.c b/xen/common/spinlock.c
index 1be1b5ebe6..79e70a9947 100644
--- a/xen/common/spinlock.c
+++ b/xen/common/spinlock.c
@@ -9,7 +9,7 @@
 #include <asm/processor.h>
 #include <asm/atomic.h>
 
-#ifndef NDEBUG
+#ifdef CONFIG_DEBUG_LOCKS
 
 static atomic_t spin_debug __read_mostly = ATOMIC_INIT(0);
 
@@ -97,7 +97,7 @@ void spin_debug_disable(void)
     atomic_dec(&spin_debug);
 }
 
-#else /* defined(NDEBUG) */
+#else /* CONFIG_DEBUG_LOCKS */
 
 #define check_lock(l) ((void)0)
 #define check_barrier(l) ((void)0)
diff --git a/xen/include/xen/spinlock.h b/xen/include/xen/spinlock.h
index 24405386a7..6da55e74a2 100644
--- a/xen/include/xen/spinlock.h
+++ b/xen/include/xen/spinlock.h
@@ -7,7 +7,7 @@
 
 #define SPINLOCK_CPU_BITS  12
 
-#ifndef NDEBUG
+#ifdef CONFIG_DEBUG_LOCKS
 union lock_debug {
     uint16_t val;
 #define LOCK_DEBUG_INITVAL 0xffff
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* [Xen-devel] [PATCH v4 3/5] xen: print lock profile info in panic()
  2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 2/5] xen: add new CONFIG_DEBUG_LOCKS option Juergen Gross
@ 2019-09-09 14:31 ` Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 4/5] xen: modify lock profiling interface Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 5/5] xen: add function name to lock profiling data Juergen Gross
  4 siblings, 0 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich, Volodymyr Babchuk,
	Roger Pau Monné

Print the lock profile data when the system crashes and add some more
information for each lock data (lock address, cpu holding the lock).
While at it use the PRI_stime format specifier for printing time data.

This is especially beneficial for watchdog triggered crashes in case
of deadlocks.

In order to have the cpu holding the lock available let the
lock profile config option select DEBUG_LOCKS.

As printing the lock profile data will make use of locking, too, we
need to disable spinlock debugging before calling
spinlock_profile_printall() from panic().

While at it remove a superfluous #ifdef CONFIG_LOCK_PROFILE and rename
CONFIG_LOCK_PROFILE to CONFIG_DEBUG_LOCK_PROFILE.

Also move the .lockprofile.data section to init area in linker scripts
as the data is no longer needed after boot.

Signed-off-by: Juergen Gross <jgross@suse.com>
Acked-by: Jan Beulich <jbeulich@suse.com>
---
V2:
- rename CONFIG_LOCK_PROFILE to CONFIG_DEBUG_LOCK_PROFILE (Jan Beulich)
- move .lockprofile.data section to init area in linker scripts
- use PRI_stime (Andrew Cooper)
- don't print "cpu=4095", but "not locked" (Andrew Cooper)
---
 xen/Kconfig.debug          |  3 ++-
 xen/arch/arm/xen.lds.S     | 13 +++++++------
 xen/arch/x86/domain.c      |  2 +-
 xen/arch/x86/xen.lds.S     | 13 +++++++------
 xen/common/keyhandler.c    |  2 +-
 xen/common/spinlock.c      | 33 ++++++++++++++++++---------------
 xen/common/sysctl.c        |  2 +-
 xen/drivers/char/console.c |  4 +++-
 xen/include/xen/spinlock.h | 12 +++++++-----
 9 files changed, 47 insertions(+), 37 deletions(-)

diff --git a/xen/Kconfig.debug b/xen/Kconfig.debug
index 1faaa3ba6a..22573e74db 100644
--- a/xen/Kconfig.debug
+++ b/xen/Kconfig.debug
@@ -44,8 +44,9 @@ config COVERAGE
 
 	  If unsure, say N here.
 
-config LOCK_PROFILE
+config DEBUG_LOCK_PROFILE
 	bool "Lock Profiling"
+	select DEBUG_LOCKS
 	---help---
 	  Lock profiling allows you to see how often locks are taken and blocked.
 	  You can use serial console to print (and reset) using 'l' and 'L'
diff --git a/xen/arch/arm/xen.lds.S b/xen/arch/arm/xen.lds.S
index 16ce1dd01e..a497f6a48d 100644
--- a/xen/arch/arm/xen.lds.S
+++ b/xen/arch/arm/xen.lds.S
@@ -54,12 +54,6 @@ SECTIONS
        *(.data.rel.ro)
        *(.data.rel.ro.*)
 
-#ifdef CONFIG_LOCK_PROFILE
-       . = ALIGN(POINTER_ALIGN);
-       __lock_profile_start = .;
-       *(.lockprofile.data)
-       __lock_profile_end = .;
-#endif
        . = ALIGN(POINTER_ALIGN);
        __param_start = .;
        *(.data.param)
@@ -173,6 +167,13 @@ SECTIONS
        . = ALIGN(4);
        *(.altinstr_replacement)
 
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
+       . = ALIGN(POINTER_ALIGN);
+       __lock_profile_start = .;
+       *(.lockprofile.data)
+       __lock_profile_end = .;
+#endif
+
        *(.init.data)
        *(.init.data.rel)
        *(.init.data.rel.*)
diff --git a/xen/arch/x86/domain.c b/xen/arch/x86/domain.c
index d538de8eae..facaeeed1f 100644
--- a/xen/arch/x86/domain.c
+++ b/xen/arch/x86/domain.c
@@ -305,7 +305,7 @@ struct domain *alloc_domain_struct(void)
 #endif
 
 
-#ifndef CONFIG_LOCK_PROFILE
+#ifndef CONFIG_DEBUG_LOCK_PROFILE
     BUILD_BUG_ON(sizeof(*d) > PAGE_SIZE);
 #endif
     d = alloc_xenheap_pages(order, MEMF_bits(bits));
diff --git a/xen/arch/x86/xen.lds.S b/xen/arch/x86/xen.lds.S
index 87fa02b9b5..111edb5360 100644
--- a/xen/arch/x86/xen.lds.S
+++ b/xen/arch/x86/xen.lds.S
@@ -128,12 +128,6 @@ SECTIONS
        *(.ex_table.pre)
        __stop___pre_ex_table = .;
 
-#ifdef CONFIG_LOCK_PROFILE
-       . = ALIGN(POINTER_ALIGN);
-       __lock_profile_start = .;
-       *(.lockprofile.data)
-       __lock_profile_end = .;
-#endif
        . = ALIGN(POINTER_ALIGN);
        __param_start = .;
        *(.data.param)
@@ -251,6 +245,13 @@ SECTIONS
         *(.altinstructions)
         __alt_instructions_end = .;
 
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
+       . = ALIGN(POINTER_ALIGN);
+       __lock_profile_start = .;
+       *(.lockprofile.data)
+       __lock_profile_end = .;
+#endif
+
        . = ALIGN(8);
        __ctors_start = .;
        *(.ctors)
diff --git a/xen/common/keyhandler.c b/xen/common/keyhandler.c
index 57b360ee4b..c36baa4dff 100644
--- a/xen/common/keyhandler.c
+++ b/xen/common/keyhandler.c
@@ -62,7 +62,7 @@ static struct keyhandler {
     KEYHANDLER('P', perfc_reset, "reset performance counters", 0),
 #endif
 
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
     KEYHANDLER('l', spinlock_profile_printall, "print lock profile info", 1),
     KEYHANDLER('L', spinlock_profile_reset, "reset lock profile info", 0),
 #endif
diff --git a/xen/common/spinlock.c b/xen/common/spinlock.c
index 79e70a9947..c4f706c627 100644
--- a/xen/common/spinlock.c
+++ b/xen/common/spinlock.c
@@ -106,7 +106,7 @@ void spin_debug_disable(void)
 
 #endif
 
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
 
 #define LOCK_PROFILE_REL                                                     \
     if (lock->profile)                                                       \
@@ -243,7 +243,7 @@ int _spin_trylock(spinlock_t *lock)
                  old.head_tail, new.head_tail) != old.head_tail )
         return 0;
     got_lock(&lock->debug);
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
     if (lock->profile)
         lock->profile->time_locked = NOW();
 #endif
@@ -258,7 +258,7 @@ int _spin_trylock(spinlock_t *lock)
 void _spin_barrier(spinlock_t *lock)
 {
     spinlock_tickets_t sample;
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
     s_time_t block = NOW();
 #endif
 
@@ -269,7 +269,7 @@ void _spin_barrier(spinlock_t *lock)
     {
         while ( observe_head(&lock->tickets) == sample.head )
             arch_lock_relax();
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
         if ( lock->profile )
         {
             lock->profile->time_block += NOW() - block;
@@ -327,7 +327,7 @@ void _spin_unlock_recursive(spinlock_t *lock)
     }
 }
 
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
 
 struct lock_profile_anc {
     struct lock_profile_qhead *head_q;   /* first head of this type */
@@ -362,14 +362,19 @@ static void spinlock_profile_iterate(lock_profile_subfunc *sub, void *par)
 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[type].name, data->name);
+    struct spinlock *lock = data->lock;
+
+    printk("%s ", lock_profile_ancs[type].name);
+    if ( type != LOCKPROF_TYPE_GLOBAL )
+        printk("%d ", idx);
+    printk("%s: addr=%p, lockval=%08x, ", data->name, lock,
+           lock->tickets.head_tail);
+    if ( lock->debug.cpu == SPINLOCK_NO_CPU )
+        printk("not locked\n");
     else
-        printk("%s %d %s:\n", lock_profile_ancs[type].name, idx, data->name);
-    printk("  lock:%12"PRId64"(%08X:%08X), block:%12"PRId64"(%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);
+        printk("cpu=%d\n", lock->debug.cpu);
+    printk("  lock:%" PRId64 "(%" PRI_stime "), block:%" PRId64 "(%" PRI_stime ")\n",
+           data->lock_cnt, data->time_hold, data->block_cnt, data->time_block);
 }
 
 void spinlock_profile_printall(unsigned char key)
@@ -488,7 +493,6 @@ void _lock_profile_deregister_struct(
     spin_unlock(&lock_profile_lock);
 }
 
-#ifdef CONFIG_LOCK_PROFILE
 static int __init lock_prof_init(void)
 {
     struct lock_profile **q;
@@ -507,6 +511,5 @@ static int __init lock_prof_init(void)
     return 0;
 }
 __initcall(lock_prof_init);
-#endif
 
-#endif /* LOCK_PROFILE */
+#endif /* CONFIG_DEBUG_LOCK_PROFILE */
diff --git a/xen/common/sysctl.c b/xen/common/sysctl.c
index 92b4ea0d21..c8f86424d5 100644
--- a/xen/common/sysctl.c
+++ b/xen/common/sysctl.c
@@ -119,7 +119,7 @@ long do_sysctl(XEN_GUEST_HANDLE_PARAM(xen_sysctl_t) u_sysctl)
         break;
 #endif
 
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
     case XEN_SYSCTL_lockprof_op:
         ret = spinlock_profile_control(&op->u.lockprof_op);
         break;
diff --git a/xen/drivers/char/console.c b/xen/drivers/char/console.c
index 7f29190eaf..e133534be7 100644
--- a/xen/drivers/char/console.c
+++ b/xen/drivers/char/console.c
@@ -1170,7 +1170,9 @@ void panic(const char *fmt, ...)
     unsigned long flags;
     static DEFINE_SPINLOCK(lock);
     static char buf[128];
-    
+
+    spin_debug_disable();
+    spinlock_profile_printall('\0');
     debugtrace_dump();
 
     /* Protects buf[] and ensure multi-line message prints atomically. */
diff --git a/xen/include/xen/spinlock.h b/xen/include/xen/spinlock.h
index 6da55e74a2..0f81c5f900 100644
--- a/xen/include/xen/spinlock.h
+++ b/xen/include/xen/spinlock.h
@@ -1,6 +1,7 @@
 #ifndef __SPINLOCK_H__
 #define __SPINLOCK_H__
 
+#include <xen/time.h>
 #include <asm/system.h>
 #include <asm/spinlock.h>
 #include <asm/types.h>
@@ -28,7 +29,7 @@ union lock_debug { };
 #define spin_debug_disable() ((void)0)
 #endif
 
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
 
 #include <public/sysctl.h>
 
@@ -74,9 +75,9 @@ struct lock_profile {
     struct spinlock     *lock;       /* the lock itself */
     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 */
+    s_time_t            time_hold;   /* cumulated lock time */
+    s_time_t            time_block;  /* cumulated wait time */
+    s_time_t            time_locked; /* system time of last locking */
 };
 
 struct lock_profile_qhead {
@@ -132,6 +133,7 @@ struct lock_profile_qhead { };
 #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)
+#define spinlock_profile_printall(key)
 
 #endif
 
@@ -153,7 +155,7 @@ typedef struct spinlock {
     u16 recurse_cnt:SPINLOCK_RECURSE_BITS;
 #define SPINLOCK_MAX_RECURSE   ((1u << SPINLOCK_RECURSE_BITS) - 1)
     union lock_debug debug;
-#ifdef CONFIG_LOCK_PROFILE
+#ifdef CONFIG_DEBUG_LOCK_PROFILE
     struct lock_profile *profile;
 #endif
 } spinlock_t;
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* [Xen-devel] [PATCH v4 4/5] xen: modify lock profiling interface
  2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
                   ` (2 preceding siblings ...)
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 3/5] xen: print lock profile info in panic() Juergen Gross
@ 2019-09-09 14:31 ` Juergen Gross
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 5/5] xen: add function name to lock profiling data Juergen Gross
  4 siblings, 0 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich

Today adding locks located in a struct to lock profiling requires a
unique type index for each structure. This makes it hard to add any
new structure as the related sysctl interface needs to be changed, too.

Instead of using an index the already existing struct name specified
in lock_profile_register_struct() can be used as an identifier instead.

Modify the sysctl interface to use the struct name instead of the type
index and adapt the related coding accordingly. Instead of an array of
struct anchors for lock profiling we now use a linked list for that
purpose. Use the special idx value -1 for cases where the idx isn't
relevant (global locks) and shouldn't be printed.

Increment the sysctl.h interface version as an interface is being
modified.

Add the missing setting of profiling time to xc_lockprof_query().

Add freeing element data when deregistering a structure.

Signed-off-by: Juergen Gross <jgross@suse.com>
---
V2:
- add comment about memory allocation needs (Jan Beulich)
- check success of memory allocation (Jan Beulich)
V4:
- style correction (Jan Beulich)
- avoid memory allocation while holding lock (Jan Beulich)
---
 tools/libxc/xc_misc.c       |   1 +
 tools/misc/xenlockprof.c    |  17 ++-----
 xen/common/domain.c         |   4 +-
 xen/common/spinlock.c       | 107 ++++++++++++++++++++++++++++++++------------
 xen/include/public/sysctl.h |  11 ++---
 xen/include/xen/spinlock.h  |  29 +++++++-----
 6 files changed, 107 insertions(+), 62 deletions(-)

diff --git a/tools/libxc/xc_misc.c b/tools/libxc/xc_misc.c
index 8e60b6e9f0..22708f1b1f 100644
--- a/tools/libxc/xc_misc.c
+++ b/tools/libxc/xc_misc.c
@@ -533,6 +533,7 @@ int xc_lockprof_query(xc_interface *xch,
     rc = do_sysctl(xch, &sysctl);
 
     *n_elems = sysctl.u.lockprof_op.nr_elem;
+    *time = sysctl.u.lockprof_op.time;
 
     return rc;
 }
diff --git a/tools/misc/xenlockprof.c b/tools/misc/xenlockprof.c
index 11f43a35e3..c6aa3fe841 100644
--- a/tools/misc/xenlockprof.c
+++ b/tools/misc/xenlockprof.c
@@ -88,19 +88,10 @@ int main(int argc, char *argv[])
     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;
-        }
+        if ( data[j].idx == LOCKPROF_IDX_NONE )
+            sprintf(name, "%s %s", data[j].type, data[j].name);
+        else
+            sprintf(name, "%s %d %s", data[j].type, data[j].idx, data[j].name);
         l = (double)(data[j].lock_time) / 1E+09;
         b = (double)(data[j].block_time) / 1E+09;
         sl += l;
diff --git a/xen/common/domain.c b/xen/common/domain.c
index e9d2c613e0..52960298db 100644
--- a/xen/common/domain.c
+++ b/xen/common/domain.c
@@ -290,7 +290,7 @@ static void _domain_destroy(struct domain *d)
 
     xsm_free_security_domain(d);
 
-    lock_profile_deregister_struct(LOCKPROF_TYPE_PERDOM, d);
+    lock_profile_deregister_struct(d, "Domain");
 
     free_domain_struct(d);
 }
@@ -376,7 +376,7 @@ struct domain *domain_create(domid_t domid,
         d->max_vcpus = config->max_vcpus;
     }
 
-    lock_profile_register_struct(LOCKPROF_TYPE_PERDOM, d, domid, "Domain");
+    lock_profile_register_struct(d, domid, "Domain");
 
     if ( (err = xsm_alloc_security_domain(d)) != 0 )
         goto fail;
diff --git a/xen/common/spinlock.c b/xen/common/spinlock.c
index c4f706c627..f40a6b5cb2 100644
--- a/xen/common/spinlock.c
+++ b/xen/common/spinlock.c
@@ -330,42 +330,43 @@ void _spin_unlock_recursive(spinlock_t *lock)
 #ifdef CONFIG_DEBUG_LOCK_PROFILE
 
 struct lock_profile_anc {
+    struct lock_profile_anc   *next;     /* next type */
     struct lock_profile_qhead *head_q;   /* first head of this type */
-    char                      *name;     /* descriptive string for print */
+    const char                *name;     /* descriptive string for print */
 };
 
 typedef void lock_profile_subfunc(
-    struct lock_profile *, int32_t, int32_t, void *);
+    struct lock_profile *, const char *, int32_t, void *);
 
 extern struct lock_profile *__lock_profile_start;
 extern struct lock_profile *__lock_profile_end;
 
 static s_time_t lock_profile_start;
-static struct lock_profile_anc lock_profile_ancs[LOCKPROF_TYPE_N];
+static struct lock_profile_anc *lock_profile_ancs;
 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_anc *anc;
     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 ( anc = lock_profile_ancs; anc; anc = anc->next )
+        for ( hq = anc->head_q; hq; hq = hq->head_q )
             for ( eq = hq->elem_q; eq; eq = eq->next )
-                sub(eq, i, hq->idx, par);
+                sub(eq, anc->name, hq->idx, par);
     spin_unlock(&lock_profile_lock);
 }
 
 static void spinlock_profile_print_elem(struct lock_profile *data,
-    int32_t type, int32_t idx, void *par)
+    const char *type, int32_t idx, void *par)
 {
     struct spinlock *lock = data->lock;
 
-    printk("%s ", lock_profile_ancs[type].name);
-    if ( type != LOCKPROF_TYPE_GLOBAL )
+    printk("%s ", type);
+    if ( idx != LOCKPROF_IDX_NONE )
         printk("%d ", idx);
     printk("%s: addr=%p, lockval=%08x, ", data->name, lock,
            lock->tickets.head_tail);
@@ -389,7 +390,7 @@ void spinlock_profile_printall(unsigned char key)
 }
 
 static void spinlock_profile_reset_elem(struct lock_profile *data,
-    int32_t type, int32_t idx, void *par)
+    const char *type, int32_t idx, void *par)
 {
     data->lock_cnt = 0;
     data->block_cnt = 0;
@@ -413,7 +414,7 @@ typedef struct {
 } spinlock_profile_ucopy_t;
 
 static void spinlock_profile_ucopy_elem(struct lock_profile *data,
-    int32_t type, int32_t idx, void *par)
+    const char *type, int32_t idx, void *par)
 {
     spinlock_profile_ucopy_t *p = par;
     struct xen_sysctl_lockprof_data elem;
@@ -424,7 +425,7 @@ static void spinlock_profile_ucopy_elem(struct lock_profile *data,
     if ( p->pc->nr_elem < p->pc->max_elem )
     {
         safe_strcpy(elem.name, data->name);
-        elem.type = type;
+        safe_strcpy(elem.type, type);
         elem.idx = idx;
         elem.lock_cnt = data->lock_cnt;
         elem.block_cnt = data->block_cnt;
@@ -465,31 +466,82 @@ int spinlock_profile_control(struct xen_sysctl_lockprof_op *pc)
     return rc;
 }
 
-void _lock_profile_register_struct(
-    int32_t type, struct lock_profile_qhead *qhead, int32_t idx, char *name)
+static struct lock_profile_anc *find_prof_anc(const char *name)
 {
-    qhead->idx = idx;
+    struct lock_profile_anc *anc;
+
+    for ( anc = lock_profile_ancs; anc; anc = anc->next )
+        if ( !strcmp(anc->name, name) )
+            return anc;
+
+    return NULL;
+}
+
+void _lock_profile_register_struct(struct lock_profile_qhead *qhead,
+                                   int32_t idx, const char *name)
+{
+    struct lock_profile_anc *anc, *anc_new;
+
     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;
+
+    anc = find_prof_anc(name);
+    if ( !anc )
+    {
+        spin_unlock(&lock_profile_lock);
+
+        anc_new = xzalloc(struct lock_profile_anc);
+        if ( !anc_new )
+            return;
+
+        spin_lock(&lock_profile_lock);
+
+        anc = find_prof_anc(name);
+        if ( anc )
+            xfree(anc_new);
+        else
+        {
+            anc = anc_new;
+            anc->name = name;
+            anc->next = lock_profile_ancs;
+            lock_profile_ancs = anc;
+        }
+    }
+
+    qhead->idx = idx;
+    qhead->head_q = anc->head_q;
+    anc->head_q = qhead;
+
     spin_unlock(&lock_profile_lock);
 }
 
-void _lock_profile_deregister_struct(
-    int32_t type, struct lock_profile_qhead *qhead)
+void _lock_profile_deregister_struct(struct lock_profile_qhead *qhead,
+                                     const char *name)
 {
+    struct lock_profile_anc *anc;
     struct lock_profile_qhead **q;
+    struct lock_profile *elem;
 
     spin_lock(&lock_profile_lock);
-    for ( q = &lock_profile_ancs[type].head_q; *q; q = &(*q)->head_q )
+
+    anc = find_prof_anc(name);
+    if ( anc )
     {
-        if ( *q == qhead )
+        for ( q = &anc->head_q; *q; q = &(*q)->head_q )
         {
-            *q = qhead->head_q;
-            break;
+            if ( *q == qhead )
+            {
+                *q = qhead->head_q;
+                while ( qhead->elem_q )
+                {
+                    elem = qhead->elem_q;
+                    qhead->elem_q = elem->next;
+                    xfree(elem);
+                }
+                break;
+            }
         }
     }
+
     spin_unlock(&lock_profile_lock);
 }
 
@@ -504,9 +556,8 @@ static int __init lock_prof_init(void)
         (*q)->lock->profile = *q;
     }
 
-    _lock_profile_register_struct(
-        LOCKPROF_TYPE_GLOBAL, &lock_profile_glb_q,
-        0, "Global lock");
+    _lock_profile_register_struct(&lock_profile_glb_q, LOCKPROF_IDX_NONE,
+                                  "Global");
 
     return 0;
 }
diff --git a/xen/include/public/sysctl.h b/xen/include/public/sysctl.h
index 36b3f8c429..9453f5eb7d 100644
--- a/xen/include/public/sysctl.h
+++ b/xen/include/public/sysctl.h
@@ -35,7 +35,7 @@
 #include "domctl.h"
 #include "physdev.h"
 
-#define XEN_SYSCTL_INTERFACE_VERSION 0x00000012
+#define XEN_SYSCTL_INTERFACE_VERSION 0x00000013
 
 /*
  * Read console content from Xen buffer ring.
@@ -433,14 +433,11 @@ struct xen_sysctl_page_offline_op {
 /* 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_??? */
+    char     name[40];     /* lock name */
+    char     type[20];     /* e.g. "domain" */
     int32_t  idx;          /* index (e.g. domain id) */
+#define LOCKPROF_IDX_NONE  -1
     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 */
diff --git a/xen/include/xen/spinlock.h b/xen/include/xen/spinlock.h
index 0f81c5f900..eafa522d79 100644
--- a/xen/include/xen/spinlock.h
+++ b/xen/include/xen/spinlock.h
@@ -52,19 +52,24 @@ union lock_debug { };
 
       with ptr being the main structure pointer and lock the spinlock field
 
+      It should be noted that this will need to allocate memory, so interrupts
+      must be enabled.
+
     - each structure has to be added to profiling with
 
-      lock_profile_register_struct(type, ptr, idx, print);
+      lock_profile_register_struct(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"
 
+      It should be noted that this will might need to allocate memory, so
+      interrupts must be enabled.
+
     - removing of a structure is done via
 
-      lock_profile_deregister_struct(type, ptr);
+      lock_profile_deregister_struct(ptr, print);
 */
 
 struct spinlock;
@@ -110,14 +115,14 @@ struct lock_profile_qhead {
         (s)->profile_head.elem_q = prof;                                      \
     } 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 *);
+void _lock_profile_register_struct(struct lock_profile_qhead *, int32_t,
+                                   const char *);
+void _lock_profile_deregister_struct(struct lock_profile_qhead *, const char *);
 
-#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))
+#define lock_profile_register_struct(ptr, idx, print)                         \
+    _lock_profile_register_struct(&((ptr)->profile_head), idx, print)
+#define lock_profile_deregister_struct(ptr, print)                            \
+    _lock_profile_deregister_struct(&((ptr)->profile_head), print)
 
 extern int spinlock_profile_control(struct xen_sysctl_lockprof_op *pc);
 extern void spinlock_profile_printall(unsigned char key);
@@ -131,8 +136,8 @@ struct lock_profile_qhead { };
 #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)
+#define lock_profile_register_struct(ptr, idx, print)
+#define lock_profile_deregister_struct(ptr, print)
 #define spinlock_profile_printall(key)
 
 #endif
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* [Xen-devel] [PATCH v4 5/5] xen: add function name to lock profiling data
  2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
                   ` (3 preceding siblings ...)
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 4/5] xen: modify lock profiling interface Juergen Gross
@ 2019-09-09 14:31 ` Juergen Gross
  4 siblings, 0 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:31 UTC (permalink / raw)
  To: xen-devel
  Cc: Juergen Gross, Stefano Stabellini, Wei Liu,
	Konrad Rzeszutek Wilk, George Dunlap, Andrew Cooper, Ian Jackson,
	Tim Deegan, Julien Grall, Jan Beulich

A spinlock defined via DEFINE_SPINLOCK() as a static variable local to
a function shows up in lock profiling just with its local variable
name. This results in multiple locks just named "lock".

In order to be able to distinguish those locks in the lock profiling
output add the function name to struct lock_profile and initialize it
with __PRETTY_FUNCTION__ (__func__ or __FUNCTION__ are not usable
outside of functions with some compilers).

Signed-off-by: Juergen Gross <jgross@suse.com>
---
 xen/common/spinlock.c      | 16 +++++++++++++---
 xen/include/xen/spinlock.h |  4 +++-
 2 files changed, 16 insertions(+), 4 deletions(-)

diff --git a/xen/common/spinlock.c b/xen/common/spinlock.c
index f40a6b5cb2..cb1c65c5e2 100644
--- a/xen/common/spinlock.c
+++ b/xen/common/spinlock.c
@@ -345,6 +345,7 @@ static s_time_t lock_profile_start;
 static struct lock_profile_anc *lock_profile_ancs;
 static struct lock_profile_qhead lock_profile_glb_q;
 static spinlock_t lock_profile_lock = SPIN_LOCK_UNLOCKED;
+static const char *lock_profile_nofunc = __PRETTY_FUNCTION__;
 
 static void spinlock_profile_iterate(lock_profile_subfunc *sub, void *par)
 {
@@ -368,8 +369,10 @@ static void spinlock_profile_print_elem(struct lock_profile *data,
     printk("%s ", type);
     if ( idx != LOCKPROF_IDX_NONE )
         printk("%d ", idx);
-    printk("%s: addr=%p, lockval=%08x, ", data->name, lock,
-           lock->tickets.head_tail);
+    printk("%s", data->name);
+    if ( data->func && strcmp(data->func, lock_profile_nofunc) )
+        printk("@%s", data->func);
+    printk(": addr=%p, lockval=%08x, ", lock, lock->tickets.head_tail);
     if ( lock->debug.cpu == SPINLOCK_NO_CPU )
         printk("not locked\n");
     else
@@ -424,7 +427,14 @@ static void spinlock_profile_ucopy_elem(struct lock_profile *data,
 
     if ( p->pc->nr_elem < p->pc->max_elem )
     {
-        safe_strcpy(elem.name, data->name);
+        if ( data->func && strcmp(data->func, lock_profile_nofunc) )
+        {
+            snprintf(elem.name, sizeof(elem.name), "%s@%s", data->name,
+                     data->func);
+            elem.name[sizeof(elem.name) - 1] = 0;
+        }
+        else
+            safe_strcpy(elem.name, data->name);
         safe_strcpy(elem.type, type);
         elem.idx = idx;
         elem.lock_cnt = data->lock_cnt;
diff --git a/xen/include/xen/spinlock.h b/xen/include/xen/spinlock.h
index eafa522d79..9cbd222b0d 100644
--- a/xen/include/xen/spinlock.h
+++ b/xen/include/xen/spinlock.h
@@ -77,6 +77,7 @@ struct spinlock;
 struct lock_profile {
     struct lock_profile *next;       /* forward link */
     char                *name;       /* lock name */
+    const char          *func;       /* function name */
     struct spinlock     *lock;       /* the lock itself */
     u64                 lock_cnt;    /* # of complete locking ops */
     u64                 block_cnt;   /* # of complete wait for lock */
@@ -91,7 +92,8 @@ struct lock_profile_qhead {
     int32_t                   idx;     /* index for printout */
 };
 
-#define _LOCK_PROFILE(name) { 0, #name, &name, 0, 0, 0, 0, 0 }
+#define _LOCK_PROFILE(name) { 0, #name, __PRETTY_FUNCTION__, &name,           \
+                              0, 0, 0, 0, 0 }
 #define _LOCK_PROFILE_PTR(name)                                               \
     static struct lock_profile * const __lock_profile_##name                  \
     __used_section(".lockprofile.data") =                                     \
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* Re: [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock
  2019-09-09 14:31 ` [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock Juergen Gross
@ 2019-09-09 14:50   ` Jan Beulich
  2019-09-09 14:56     ` Juergen Gross
  0 siblings, 1 reply; 8+ messages in thread
From: Jan Beulich @ 2019-09-09 14:50 UTC (permalink / raw)
  To: Juergen Gross
  Cc: Stefano Stabellini, Wei Liu, Konrad Rzeszutek Wilk,
	George Dunlap, Andrew Cooper, Ian Jackson, Tim Deegan,
	Julien Grall, xen-devel

On 09.09.2019 16:31, Juergen Gross wrote:
> --- a/xen/include/xen/spinlock.h
> +++ b/xen/include/xen/spinlock.h
> @@ -5,15 +5,24 @@
>  #include <asm/spinlock.h>
>  #include <asm/types.h>
>  
> +#define SPINLOCK_CPU_BITS  12
> +
>  #ifndef NDEBUG
> -struct lock_debug {
> -    s16 irq_safe; /* +1: IRQ-safe; 0: not IRQ-safe; -1: don't know yet */
> +union lock_debug {
> +    uint16_t val;
> +#define LOCK_DEBUG_INITVAL 0xffff
> +    struct {
> +        uint16_t cpu:SPINLOCK_CPU_BITS;
> +        uint16_t :(14 - SPINLOCK_CPU_BITS);

I'm sorry that I realize this only now that I see this and ...

> +        bool irq_safe:1;
> +        bool unseen:1;
> +    };
>  };
> -#define _LOCK_DEBUG { -1 }
> +#define _LOCK_DEBUG { LOCK_DEBUG_INITVAL }
>  void spin_debug_enable(void);
>  void spin_debug_disable(void);
>  #else
> -struct lock_debug { };
> +union lock_debug { };
>  #define _LOCK_DEBUG { }
>  #define spin_debug_enable() ((void)0)
>  #define spin_debug_disable() ((void)0)
> @@ -138,11 +147,12 @@ typedef union {
>  
>  typedef struct spinlock {
>      spinlock_tickets_t tickets;
> -    u16 recurse_cpu:12;
> -#define SPINLOCK_NO_CPU 0xfffu
> -    u16 recurse_cnt:4;
> -#define SPINLOCK_MAX_RECURSE 0xfu
> -    struct lock_debug debug;
> +    u16 recurse_cpu:SPINLOCK_CPU_BITS;
> +#define SPINLOCK_NO_CPU        ((1u << SPINLOCK_CPU_BITS) - 1)
> +#define SPINLOCK_RECURSE_BITS  (16 - SPINLOCK_CPU_BITS)
> +    u16 recurse_cnt:SPINLOCK_RECURSE_BITS;
> +#define SPINLOCK_MAX_RECURSE   ((1u << SPINLOCK_RECURSE_BITS) - 1)

... this: These subtractions are prone to yield de-generate
bitfields when the difference ends up zero (leading to
presumably very strange breakage, albeit one would hope that
it also would be very obvious that _something_ is broken). I
think we need BUILD_BUG_ON()s checking that neither
difference actually is zero.

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock
  2019-09-09 14:50   ` Jan Beulich
@ 2019-09-09 14:56     ` Juergen Gross
  0 siblings, 0 replies; 8+ messages in thread
From: Juergen Gross @ 2019-09-09 14:56 UTC (permalink / raw)
  To: Jan Beulich
  Cc: Stefano Stabellini, Wei Liu, Konrad Rzeszutek Wilk,
	George Dunlap, Andrew Cooper, Ian Jackson, Tim Deegan,
	Julien Grall, xen-devel

On 09.09.19 16:50, Jan Beulich wrote:
> On 09.09.2019 16:31, Juergen Gross wrote:
>> --- a/xen/include/xen/spinlock.h
>> +++ b/xen/include/xen/spinlock.h
>> @@ -5,15 +5,24 @@
>>   #include <asm/spinlock.h>
>>   #include <asm/types.h>
>>   
>> +#define SPINLOCK_CPU_BITS  12
>> +
>>   #ifndef NDEBUG
>> -struct lock_debug {
>> -    s16 irq_safe; /* +1: IRQ-safe; 0: not IRQ-safe; -1: don't know yet */
>> +union lock_debug {
>> +    uint16_t val;
>> +#define LOCK_DEBUG_INITVAL 0xffff
>> +    struct {
>> +        uint16_t cpu:SPINLOCK_CPU_BITS;
>> +        uint16_t :(14 - SPINLOCK_CPU_BITS);
> 
> I'm sorry that I realize this only now that I see this and ...
> 
>> +        bool irq_safe:1;
>> +        bool unseen:1;
>> +    };
>>   };
>> -#define _LOCK_DEBUG { -1 }
>> +#define _LOCK_DEBUG { LOCK_DEBUG_INITVAL }
>>   void spin_debug_enable(void);
>>   void spin_debug_disable(void);
>>   #else
>> -struct lock_debug { };
>> +union lock_debug { };
>>   #define _LOCK_DEBUG { }
>>   #define spin_debug_enable() ((void)0)
>>   #define spin_debug_disable() ((void)0)
>> @@ -138,11 +147,12 @@ typedef union {
>>   
>>   typedef struct spinlock {
>>       spinlock_tickets_t tickets;
>> -    u16 recurse_cpu:12;
>> -#define SPINLOCK_NO_CPU 0xfffu
>> -    u16 recurse_cnt:4;
>> -#define SPINLOCK_MAX_RECURSE 0xfu
>> -    struct lock_debug debug;
>> +    u16 recurse_cpu:SPINLOCK_CPU_BITS;
>> +#define SPINLOCK_NO_CPU        ((1u << SPINLOCK_CPU_BITS) - 1)
>> +#define SPINLOCK_RECURSE_BITS  (16 - SPINLOCK_CPU_BITS)
>> +    u16 recurse_cnt:SPINLOCK_RECURSE_BITS;
>> +#define SPINLOCK_MAX_RECURSE   ((1u << SPINLOCK_RECURSE_BITS) - 1)
> 
> ... this: These subtractions are prone to yield de-generate
> bitfields when the difference ends up zero (leading to
> presumably very strange breakage, albeit one would hope that
> it also would be very obvious that _something_ is broken). I
> think we need BUILD_BUG_ON()s checking that neither
> difference actually is zero.

Okay, will add them.


Juergen


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2019-09-09 14:56 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-09-09 14:31 [Xen-devel] [PATCH v4 0/5] enhance lock debugging Juergen Gross
2019-09-09 14:31 ` [Xen-devel] [PATCH v4 1/5] xen/spinlocks: in debug builds store cpu holding the lock Juergen Gross
2019-09-09 14:50   ` Jan Beulich
2019-09-09 14:56     ` Juergen Gross
2019-09-09 14:31 ` [Xen-devel] [PATCH v4 2/5] xen: add new CONFIG_DEBUG_LOCKS option Juergen Gross
2019-09-09 14:31 ` [Xen-devel] [PATCH v4 3/5] xen: print lock profile info in panic() Juergen Gross
2019-09-09 14:31 ` [Xen-devel] [PATCH v4 4/5] xen: modify lock profiling interface Juergen Gross
2019-09-09 14:31 ` [Xen-devel] [PATCH v4 5/5] xen: add function name to lock profiling data Juergen Gross

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).