From: Jan Kiszka <jan.kiszka@domain.hid>
To: xenomai-core <xenomai@xenomai.org>
Subject: [Xenomai-core] [patch] spinlock latency debugging
Date: Tue, 29 Nov 2005 20:15:23 +0100 [thread overview]
Message-ID: <438CA8CB.4090609@domain.hid> (raw)
[-- Attachment #1.1: Type: text/plain, Size: 781 bytes --]
Hi,
this is a first attempt to add some more instrumentation to the Xenomai
core and related modules. It enables the existing spinlock profiling
also for non-SMP setups and adds the exit location to the log. Note that
this is likely not yet ready for inclusion, it's only tested with
debugging on and may break with other configs.
Comments are welcome.
Some first observations: this kind of instrumentation is unfortunately
insufficient to trace the full latency a task may suffer from. In case
some IRQ hits inside a critical section, the tracing will not start
before some functions finally called by the IRQ handler acquires a
xnlock. Task latencies and longest locking periods differ by factor 2
*at least*. What we finally need is IRQ-off tracing.
Jan
[-- Attachment #1.2: spinlock_debug.patch --]
[-- Type: text/plain, Size: 13527 bytes --]
Index: include/asm-ia64/system.h
===================================================================
--- include/asm-ia64/system.h (revision 202)
+++ include/asm-ia64/system.h (working copy)
@@ -525,7 +525,7 @@
static rthal_trap_handler_t xnarch_old_trap_handler;
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
static xnlock_t xnarch_stacks_lock = XNARCH_LOCK_UNLOCKED;
#endif
static atomic_counter_t xnarch_allocated_stacks;
Index: include/asm-generic/system.h
===================================================================
--- include/asm-generic/system.h (revision 202)
+++ include/asm-generic/system.h (working copy)
@@ -54,16 +54,20 @@
#define splget(x) rthal_local_irq_flags(x)
#define splsync(x) rthal_local_irq_sync(x)
-#if defined(CONFIG_SMP) && \
- (defined(CONFIG_XENO_OPT_STATS) || defined(CONFIG_XENO_OPT_DEBUG))
+/*#if defined(CONFIG_SMP) && \
+ (defined(CONFIG_XENO_OPT_STATS) || defined(CONFIG_XENO_OPT_DEBUG))*/
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
typedef struct {
unsigned long long spin_time;
unsigned long long lock_time;
- const char *file;
- const char *function;
- unsigned line;
+ const char *get_file;
+ const char *get_function;
+ unsigned get_line;
+ const char *put_file;
+ const char *put_function;
+ unsigned put_line;
} xnlockinfo_t;
@@ -89,9 +93,9 @@
0LL, \
}
-#define CONFIG_XENO_SPINLOCK_DEBUG 1
+//#define CONFIG_XENO_SPINLOCK_DEBUG 1
-#else /* !(CONFIG_XENO_OPT_STATS && CONFIG_SMP) */
+#else /* !CONFIG_XENO_OPT_SPINLOCK_DEBUG */
typedef struct { volatile unsigned long lock; } xnlock_t;
@@ -197,14 +201,17 @@
return !!s;
}
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
#define xnlock_get_irqsave(lock,x) \
((x) = __xnlock_get_irqsave(lock, __FILE__, __LINE__,__FUNCTION__))
-#else /* !CONFIG_XENO_SPINLOCK_DEBUG */
+#define xnlock_put_irqrestore(lock,x) \
+ __xnlock_put_irqrestore(lock, x, __FILE__, __LINE__,__FUNCTION__)
+#else /* !CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#define xnlock_get_irqsave(lock,x) ((x) = __xnlock_get_irqsave(lock))
-#endif /* CONFIG_XENO_SPINLOCK_DEBUG */
+#define xnlock_put_irqrestore(lock,x) __xnlock_put_irqrestore(lock,x)
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#define xnlock_clear_irqoff(lock) xnlock_put_irqrestore(lock,1)
#define xnlock_clear_irqon(lock) xnlock_put_irqrestore(lock,0)
@@ -213,7 +220,7 @@
*lock = XNARCH_LOCK_UNLOCKED;
}
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
#define XNARCH_DEBUG_SPIN_LIMIT 3000000
@@ -223,10 +230,10 @@
const char *function)
{
unsigned spin_count = 0;
-#else /* !CONFIG_XENO_SPINLOCK_DEBUG */
+#else /* !CONFIG_XENO_OPT_SPINLOCK_DEBUG */
static inline spl_t __xnlock_get_irqsave (xnlock_t *lock)
{
-#endif /* CONFIG_XENO_SPINLOCK_DEBUG */
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
rthal_declare_cpuid;
unsigned long flags;
@@ -236,9 +243,9 @@
if (!test_and_set_bit(cpuid,&lock->lock))
{
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
unsigned long long lock_date = rthal_rdtsc();
-#endif /* CONFIG_XENO_SPINLOCK_DEBUG */
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
while (test_and_set_bit(BITS_PER_LONG - 1,&lock->lock))
/* Use an non-locking test in the inner loop, as Linux'es
bit_spin_lock. */
@@ -246,7 +253,7 @@
{
cpu_relax();
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
if (++spin_count == XNARCH_DEBUG_SPIN_LIMIT)
{
rthal_emergency_console();
@@ -260,17 +267,17 @@
for (;;)
cpu_relax();
}
-#endif /* CONFIG_XENO_SPINLOCK_DEBUG */
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
}
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
lock->spin_time = rthal_rdtsc() - lock_date;
lock->lock_date = lock_date;
lock->file = file;
lock->function = function;
lock->line = line;
lock->cpu = cpuid;
-#endif /* CONFIG_XENO_SPINLOCK_DEBUG */
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
}
else
flags |= 2;
@@ -278,8 +285,15 @@
return flags;
}
-static inline void xnlock_put_irqrestore (xnlock_t *lock, spl_t flags)
-
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
+static inline void __xnlock_put_irqrestore (xnlock_t *lock,
+ spl_t flags,
+ const char *file,
+ unsigned line,
+ const char *function)
+#else /* !CONFIG_XENO_OPT_SPINLOCK_DEBUG */
+static inline void __xnlock_put_irqrestore (xnlock_t *lock, spl_t flags)
+#endif /* CONFIG_XENO_OPT_SPINLOCK_DEBUG */
{
if (!(flags & 2))
{
@@ -299,15 +313,18 @@
{
xnlock_stats[cpuid].lock_time = lock_time;
xnlock_stats[cpuid].spin_time = lock->spin_time;
- xnlock_stats[cpuid].file = lock->file;
- xnlock_stats[cpuid].function = lock->function;
- xnlock_stats[cpuid].line = lock->line;
+ xnlock_stats[cpuid].get_file = lock->file;
+ xnlock_stats[cpuid].get_function = lock->function;
+ xnlock_stats[cpuid].get_line = lock->line;
+ xnlock_stats[cpuid].put_file = file;
+ xnlock_stats[cpuid].put_function = function;
+ xnlock_stats[cpuid].put_line = line;
}
#endif /* CONFIG_XENO_OPT_STATS */
clear_bit(BITS_PER_LONG - 1,&lock->lock);
}
-#ifdef CONFIG_XENO_SPINLOCK_DEBUG
+#ifdef CONFIG_XENO_OPT_SPINLOCK_DEBUG
else
{
rthal_emergency_console();
@@ -325,7 +342,7 @@
rthal_local_irq_restore(flags & 1);
}
-#else /* !CONFIG_SMP */
+#else /* !(CONFIG_SMP || CONFIG_XENO_OPT_SPINLOCK_DEBUG) */
#define xnlock_init(lock) do { } while(0)
#define xnlock_get_irqsave(lock,x) rthal_local_irq_save(x)
@@ -333,7 +350,7 @@
#define xnlock_clear_irqoff(lock) rthal_local_irq_disable()
#define xnlock_clear_irqon(lock) rthal_local_irq_enable()
-#endif /* CONFIG_SMP */
+#endif /* CONFIG_SMP || CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#ifdef XENO_POD_MODULE
Index: include/rtdm/core.h
===================================================================
--- include/rtdm/core.h (revision 202)
+++ include/rtdm/core.h (working copy)
@@ -33,10 +33,7 @@
};
-#ifdef CONFIG_SMP
extern xnlock_t rt_fildes_lock;
-#endif /* CONFIG_SMP */
-
extern unsigned int fd_count;
extern struct rtdm_fildes *fildes_table;
extern int open_fildes;
Index: include/nucleus/heap.h
===================================================================
--- include/nucleus/heap.h (revision 202)
+++ include/nucleus/heap.h (working copy)
@@ -87,7 +87,7 @@
xnqueue_t extents;
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
xnlock_t lock;
#endif /* CONFIG_SMP */
Index: include/nucleus/pod.h
===================================================================
--- include/nucleus/pod.h (revision 202)
+++ include/nucleus/pod.h (working copy)
@@ -233,7 +233,7 @@
extern xnpod_t *nkpod;
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
extern xnlock_t nklock;
#endif /* CONFIG_SMP */
Index: include/nucleus/queue.h
===================================================================
--- include/nucleus/queue.h (revision 202)
+++ include/nucleus/queue.h (working copy)
@@ -57,7 +57,8 @@
xnholder_t head;
int elems;
-#if defined(__KERNEL__) && defined(CONFIG_XENO_OPT_DEBUG) && defined(CONFIG_SMP)
+#if defined(__KERNEL__) && defined(CONFIG_XENO_OPT_DEBUG) && \
+ (defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCKDEBUG))
xnlock_t lock;
#endif /* __KERNEL__ && CONFIG_XENO_OPT_DEBUG && CONFIG_SMP */
Index: ksrc/skins/posix/signal.c
===================================================================
--- ksrc/skins/posix/signal.c (revision 202)
+++ ksrc/skins/posix/signal.c (working copy)
@@ -32,7 +32,7 @@
static struct sigaction actions[SIGRTMAX];
static pse51_siginfo_t pse51_infos_pool[PSE51_SIGQUEUE_MAX];
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
static xnlock_t pse51_infos_lock;
#endif
static xnpqueue_t pse51_infos_free_list;
Index: ksrc/skins/rtdm/device.c
===================================================================
--- ksrc/skins/rtdm/device.c (revision 202)
+++ ksrc/skins/rtdm/device.c (working copy)
@@ -62,7 +62,7 @@
DECLARE_MUTEX(nrt_dev_lock);
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
xnlock_t rt_dev_lock = XNARCH_LOCK_UNLOCKED;
#endif /* CONFIG_SMP */
Index: ksrc/skins/rtdm/core.c
===================================================================
--- ksrc/skins/rtdm/core.c (revision 202)
+++ ksrc/skins/rtdm/core.c (working copy)
@@ -44,7 +44,7 @@
static struct rtdm_fildes *free_fildes; /* chain of free descriptors */
int open_fildes; /* number of used descriptors */
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
xnlock_t rt_fildes_lock = XNARCH_LOCK_UNLOCKED;
#endif /* !CONFIG_SMP */
Index: ksrc/nucleus/Kconfig
===================================================================
--- ksrc/nucleus/Kconfig (revision 202)
+++ ksrc/nucleus/Kconfig (working copy)
@@ -87,6 +87,14 @@
Do not switch this option on unless you really know what you
are doing.
+config XENO_OPT_SPINLOCK_DEBUG
+ bool "Spinlock debugging"
+ default n
+# depends on XENO_OPT_DEBUG
+ help
+
+ no help
+
config XENO_OPT_WATCHDOG
bool "Watchdog support"
default n
Index: ksrc/nucleus/pod.c
===================================================================
--- ksrc/nucleus/pod.c (revision 202)
+++ ksrc/nucleus/pod.c (working copy)
@@ -48,7 +48,7 @@
xnpod_t *nkpod = NULL;
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
xnlock_t nklock = XNARCH_LOCK_UNLOCKED;
#endif /* CONFIG_SMP */
@@ -3431,6 +3431,6 @@
EXPORT_SYMBOL(nkclock);
EXPORT_SYMBOL(nkpod);
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
EXPORT_SYMBOL(nklock);
#endif /* CONFIG_SMP */
Index: ksrc/nucleus/module.c
===================================================================
--- ksrc/nucleus/module.c (revision 202)
+++ ksrc/nucleus/module.c (working copy)
@@ -375,7 +375,7 @@
.release = seq_release_private,
};
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
xnlockinfo_t xnlock_stats[RTHAL_NR_CPUS];
@@ -405,12 +405,16 @@
p += sprintf(p,
" longest locked section: %llu ns\n"
" spinning time: %llu ns\n"
- " section entry: %s:%d (%s)\n",
+ " section entry: %s:%d (%s)\n"
+ " section exit: %s:%d (%s)\n",
xnarch_tsc_to_ns(lockinfo.lock_time),
xnarch_tsc_to_ns(lockinfo.spin_time),
- lockinfo.file,
- lockinfo.line,
- lockinfo.function);
+ lockinfo.get_file,
+ lockinfo.get_line,
+ lockinfo.get_function,
+ lockinfo.put_file,
+ lockinfo.put_line,
+ lockinfo.put_function);
}
len = p - page - off;
@@ -425,7 +429,7 @@
EXPORT_SYMBOL(xnlock_stats);
-#endif /* CONFIG_SMP */
+#endif /* CONFIG_SMP || CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#endif /* CONFIG_XENO_OPT_STATS */
@@ -612,13 +616,13 @@
&stat_seq_operations,
0,
rthal_proc_root);
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
add_proc_leaf("lock",
&lock_read_proc,
NULL,
NULL,
rthal_proc_root);
-#endif /* CONFIG_SMP */
+#endif /* CONFIG_SMP || CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#endif /* CONFIG_XENO_OPT_STATS */
@@ -675,9 +679,9 @@
remove_proc_entry("sched",rthal_proc_root);
#ifdef CONFIG_XENO_OPT_STATS
remove_proc_entry("stat",rthal_proc_root);
-#ifdef CONFIG_SMP
+#if defined(CONFIG_SMP) || defined(CONFIG_XENO_OPT_SPINLOCK_DEBUG)
remove_proc_entry("lock",rthal_proc_root);
-#endif /* CONFIG_SMP */
+#endif /* CONFIG_SMP || CONFIG_XENO_OPT_SPINLOCK_DEBUG */
#endif /* CONFIG_XENO_OPT_STATS */
}
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 250 bytes --]
reply other threads:[~2005-11-29 19:15 UTC|newest]
Thread overview: [no followups] expand[flat|nested] mbox.gz Atom feed
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=438CA8CB.4090609@domain.hid \
--to=jan.kiszka@domain.hid \
--cc=xenomai@xenomai.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.