Re: [Xenomai-core] Re: [PATCH] latency tracer update
Jan Kiszka wrote:
Jan Kiszka wrote:
Jan Kiszka wrote:
...
Meanwhile I found a solution for the described unterminated trace (put
an explicite trace_end at the end of __ipipe_unstall_iret_root),
included the irq number in the begin/end report, and stumbled over some
other remaining unterminated trace on a different machine. So, no need
to hurry with the merge (not the review! ;) ), I will publish a second
revision first.
And here comes this revision finally. Should apply (almost) cleanly
against latest ipipe versions. Additionally to the changes of the first
revision this one addresses the following topics:
o fix trace overrun handling
o report IRQ number to tracer on IRQ entry/exit
o fix virtually leaking IRQs-off in __ipipe_unstall_iret_root()
o fix another potential NMI race
o really trace the maximum IRQs-off time, not the maximum time of
consecutive IRQs-off times (that scenario will soon be addressed
instead in the latency benchmark tool = resetfreeze the maximum
latency from the user's point of view)
...and it turned out that the existing functions were no sufficient for
this. So here comes an add-on patch to update3:
o allow ipipe_trace_{frozen|max}_reset from every context
(well, at least give it a try and just fail on locked traces)
o mark border between valid and invalid trace points
o show invalid points border
Apply order:
ipipe_tracer.update3
ipipe_tracer.update3-1
Merged in 1.1-03, with the appropriate tracer patch. Thanks.
The front-end to the first change, a modified latency+timerbench will
get committed to Xenomai soon. It already works nicely, automatically
creating a freeze of the maximum latency turn the benchmark perceives.
Jan
--- linux-2.6.14.3/kernel/ipipe/tracer.c.orig 2006-01-06 11:13:41.0
+0100
+++ linux-2.6.14.3/kernel/ipipe/tracer.c2006-01-06 20:11:10.0
+0100
@@ -134,10 +134,14 @@ __ipipe_migrate_pre_trace(struct ipipe_t
int i;
new_tp-trace_pos = pre_trace+1;
+
for (i = new_tp-trace_pos; i 0; i--)
memcpy(new_tp-point[WRAP_POINT_NO(new_tp-trace_pos-i)],
old_tp-point[WRAP_POINT_NO(old_pos-i)],
sizeof(struct ipipe_trace_point));
+
+ /* mark the end (i.e. the point before point[0]) invalid */
+ new_tp-point[IPIPE_TRACE_POINTS-1].eip = 0;
}
static notrace struct ipipe_trace_path *
@@ -436,21 +440,23 @@ void notrace ipipe_trace_special(unsigne
}
EXPORT_SYMBOL(ipipe_trace_special);
-void ipipe_trace_max_reset(void)
+int ipipe_trace_max_reset(void)
{
int cpu_id;
unsigned long flags;
struct ipipe_trace_path *path;
+ int ret = 0;
- /* only allowed from root domain (we sync with /proc routines) */
- if (ipipe_current_domain != ipipe_root_domain)
- return;
-
- down(out_mutex);
flags = __ipipe_global_path_lock();
for_each_cpu(cpu_id) {
path = trace_paths[cpu_id][max_path[cpu_id]];
+
+ if (path-dump_lock) {
+ ret = -EBUSY;
+ break;
+ }
+
path-begin = -1;
path-end = -1;
path-trace_pos = 0;
@@ -458,25 +464,28 @@ void ipipe_trace_max_reset(void)
}
__ipipe_global_path_unlock(flags);
- up(out_mutex);
+
+ return ret;
}
EXPORT_SYMBOL(ipipe_trace_max_reset);
-void ipipe_trace_frozen_reset(void)
+int ipipe_trace_frozen_reset(void)
{
int cpu_id;
unsigned long flags;
struct ipipe_trace_path *path;
+ int ret = 0;
- /* only allowed from root domain (we sync with /proc routines) */
- if (ipipe_current_domain != ipipe_root_domain)
- return;
-
- down(out_mutex);
flags = __ipipe_global_path_lock();
for_each_cpu(cpu_id) {
path = trace_paths[cpu_id][frozen_path[cpu_id]];
+
+ if (path-dump_lock) {
+ ret = -EBUSY;
+ break;
+ }
+
path-begin = -1;
path-end = -1;
path-trace_pos = 0;
@@ -484,7 +493,8 @@ void ipipe_trace_frozen_reset(void)
}
__ipipe_global_path_unlock(flags);
- up(out_mutex);
+
+ return ret;
}
EXPORT_SYMBOL(ipipe_trace_frozen_reset);
@@ -684,8 +694,10 @@ static int __ipipe_prtrace_show(struct s
unsigned long long abs_delta;
struct ipipe_trace_point *point = p;
- if (!point-eip)
+ if (!point-eip) {
+ seq_puts(m, -invalid-\n);
return 0;
+ }
/* ipipe_tsc2us works on unsigned = handle sign separately */
delta = point-timestamp -
@@ -749,7 +761,10 @@ static ssize_t
__ipipe_max_reset(struct file *file, const char __user *pbuffer,
size_t count, loff_t *data)
{
+ down(out_mutex);
Re: [Xenomai-core] Re: [PATCH] latency tracer update
Jan Kiszka wrote:
Jan Kiszka wrote:
Jan Kiszka wrote:
...
Meanwhile I found a solution for the described unterminated trace (put
an explicite trace_end at the end of __ipipe_unstall_iret_root),
included the irq number in the begin/end report, and stumbled over some
other remaining unterminated trace on a different machine. So, no need
to hurry with the merge (not the review! ;) ), I will publish a second
revision first.
And here comes this revision finally. Should apply (almost) cleanly
against latest ipipe versions. Additionally to the changes of the first
revision this one addresses the following topics:
o fix trace overrun handling
o report IRQ number to tracer on IRQ entry/exit
o fix virtually leaking IRQs-off in __ipipe_unstall_iret_root()
o fix another potential NMI race
o really trace the maximum IRQs-off time, not the maximum time of
consecutive IRQs-off times (that scenario will soon be addressed
instead in the latency benchmark tool = resetfreeze the maximum
latency from the user's point of view)
...and it turned out that the existing functions were no sufficient for
this. So here comes an add-on patch to update3:
o allow ipipe_trace_{frozen|max}_reset from every context
(well, at least give it a try and just fail on locked traces)
o mark border between valid and invalid trace points
o show invalid points border
Apply order:
ipipe_tracer.update3
ipipe_tracer.update3-1
Merged in 1.1-03, with the appropriate tracer patch. Thanks.
The front-end to the first change, a modified latency+timerbench will
get committed to Xenomai soon. It already works nicely, automatically
creating a freeze of the maximum latency turn the benchmark perceives.
Jan
--- linux-2.6.14.3/kernel/ipipe/tracer.c.orig 2006-01-06 11:13:41.0
+0100
+++ linux-2.6.14.3/kernel/ipipe/tracer.c2006-01-06 20:11:10.0
+0100
@@ -134,10 +134,14 @@ __ipipe_migrate_pre_trace(struct ipipe_t
int i;
new_tp-trace_pos = pre_trace+1;
+
for (i = new_tp-trace_pos; i 0; i--)
memcpy(new_tp-point[WRAP_POINT_NO(new_tp-trace_pos-i)],
old_tp-point[WRAP_POINT_NO(old_pos-i)],
sizeof(struct ipipe_trace_point));
+
+ /* mark the end (i.e. the point before point[0]) invalid */
+ new_tp-point[IPIPE_TRACE_POINTS-1].eip = 0;
}
static notrace struct ipipe_trace_path *
@@ -436,21 +440,23 @@ void notrace ipipe_trace_special(unsigne
}
EXPORT_SYMBOL(ipipe_trace_special);
-void ipipe_trace_max_reset(void)
+int ipipe_trace_max_reset(void)
{
int cpu_id;
unsigned long flags;
struct ipipe_trace_path *path;
+ int ret = 0;
- /* only allowed from root domain (we sync with /proc routines) */
- if (ipipe_current_domain != ipipe_root_domain)
- return;
-
- down(out_mutex);
flags = __ipipe_global_path_lock();
for_each_cpu(cpu_id) {
path = trace_paths[cpu_id][max_path[cpu_id]];
+
+ if (path-dump_lock) {
+ ret = -EBUSY;
+ break;
+ }
+
path-begin = -1;
path-end = -1;
path-trace_pos = 0;
@@ -458,25 +464,28 @@ void ipipe_trace_max_reset(void)
}
__ipipe_global_path_unlock(flags);
- up(out_mutex);
+
+ return ret;
}
EXPORT_SYMBOL(ipipe_trace_max_reset);
-void ipipe_trace_frozen_reset(void)
+int ipipe_trace_frozen_reset(void)
{
int cpu_id;
unsigned long flags;
struct ipipe_trace_path *path;
+ int ret = 0;
- /* only allowed from root domain (we sync with /proc routines) */
- if (ipipe_current_domain != ipipe_root_domain)
- return;
-
- down(out_mutex);
flags = __ipipe_global_path_lock();
for_each_cpu(cpu_id) {
path = trace_paths[cpu_id][frozen_path[cpu_id]];
+
+ if (path-dump_lock) {
+ ret = -EBUSY;
+ break;
+ }
+
path-begin = -1;
path-end = -1;
path-trace_pos = 0;
@@ -484,7 +493,8 @@ void ipipe_trace_frozen_reset(void)
}
__ipipe_global_path_unlock(flags);
- up(out_mutex);
+
+ return ret;
}
EXPORT_SYMBOL(ipipe_trace_frozen_reset);
@@ -684,8 +694,10 @@ static int __ipipe_prtrace_show(struct s
unsigned long long abs_delta;
struct ipipe_trace_point *point = p;
- if (!point-eip)
+ if (!point-eip) {
+ seq_puts(m, -invalid-\n);
return 0;
+ }
/* ipipe_tsc2us works on unsigned = handle sign separately */
delta = point-timestamp -
@@ -749,7 +761,10 @@ static ssize_t
__ipipe_max_reset(struct file *file, const char __user *pbuffer,
size_t count, loff_t *data)
{
+ down(out_mutex);
Re: [Xenomai-core] Re: [PATCH] latency tracer update
Jan Kiszka wrote:
...
Meanwhile I found a solution for the described unterminated trace (put
an explicite trace_end at the end of __ipipe_unstall_iret_root),
included the irq number in the begin/end report, and stumbled over some
other remaining unterminated trace on a different machine. So, no need
to hurry with the merge (not the review! ;) ), I will publish a second
revision first.
And here comes this revision finally. Should apply (almost) cleanly
against latest ipipe versions. Additionally to the changes of the first
revision this one addresses the following topics:
o fix trace overrun handling
o report IRQ number to tracer on IRQ entry/exit
o fix virtually leaking IRQs-off in __ipipe_unstall_iret_root()
o fix another potential NMI race
o really trace the maximum IRQs-off time, not the maximum time of
consecutive IRQs-off times (that scenario will soon be addressed
instead in the latency benchmark tool = resetfreeze the maximum
latency from the user's point of view)
o remove the ipipe_trace_special reporting in local_irq_xxx trace
points (cleans up the traces inside IRQ-off paths)
The tracer has undergone a significant number of tests now and it really
looks like it is stable. I will now have to fix/improve some minor
issues on the Xenomai side regarding tracing.
Jan
--- linux-2.6.14.3/arch/i386/kernel/entry.S.orig2006-01-03
19:30:15.0 +0100
+++ linux-2.6.14.3/arch/i386/kernel/entry.S 2006-01-05 03:37:24.0
+0100
@@ -106,6 +106,33 @@ VM_MASK= 0x0002
call __ipipe_divert_exception ; \
testl %eax,%eax ; \
jnz restore_raw
+
+#ifdef CONFIG_IPIPE_TRACE_IRQSOFF
+# ifdef CONFIG_REGPARM
+# define LOAD_ARG
+# define REMOVE_ARG
+# else /* !CONFIG_REGPARM */
+# define LOAD_ARG pushl %eax
+# define REMOVE_ARGaddl $4, %esp
+# endif /* CONFIG_REGPARM */
+# define IPIPE_TRACE_IRQ_ENTER \
+ lea EIP-4(%esp), %ebp; \
+ movl ORIG_EAX(%esp), %eax; \
+ LOAD_ARG; \
+ call ipipe_trace_begin; \
+ REMOVE_ARG
+# define IPIPE_TRACE_IRQ_EXIT \
+ pushl %eax; \
+ movl ORIG_EAX+4(%esp), %eax; \
+ LOAD_ARG; \
+ call ipipe_trace_end; \
+ REMOVE_ARG; \
+ popl %eax
+#else /* !CONFIG_IPIPE_TRACE_IRQSOFF */
+# define IPIPE_TRACE_IRQ_ENTER
+# define IPIPE_TRACE_IRQ_EXIT
+#endif /* CONFIG_IPIPE_TRACE_IRQSOFF */
+
#else /* !CONFIG_IPIPE */
#define CLI cli
#define STI sti
@@ -474,7 +501,9 @@ vector=vector+1
ALIGN
common_interrupt:
SAVE_ALL
+ IPIPE_TRACE_IRQ_ENTER; \
call __ipipe_handle_irq
+ IPIPE_TRACE_IRQ_EXIT; \
testl %eax,%eax
jnz ret_from_intr
RESTORE_REGS
@@ -485,7 +514,9 @@ common_interrupt:
ENTRY(name)\
pushl $nr-288; /* nr - (256 + FIRST_EXTERNAL_VECTOR) */ \
SAVE_ALL; \
+ IPIPE_TRACE_IRQ_ENTER; \
call __ipipe_handle_irq;\
+ IPIPE_TRACE_IRQ_EXIT; \
testl %eax,%eax;\
jnz ret_from_intr; \
RESTORE_REGS; \
--- linux-2.6.14.3/arch/i386/kernel/ipipe-root.c.orig 2006-01-02
20:42:58.0 +0100
+++ linux-2.6.14.3/arch/i386/kernel/ipipe-root.c2006-01-06
02:47:31.0 +0100
@@ -283,7 +283,7 @@ asmlinkage int __ipipe_kpreempt_root(str
}
__ipipe_stall_root();
- local_irq_enable_hw();
+ local_irq_enable_hw_notrace();
return 1; /* Ok, may reschedule now. */
}
@@ -320,6 +320,9 @@ asmlinkage void __ipipe_unstall_iret_roo
irq_pending_hi IPIPE_IRQMASK_VIRT) != 0)
__ipipe_sync_stage(IPIPE_IRQMASK_VIRT);
}
+#ifdef CONFIG_IPIPE_TRACE_IRQSOFF
+ ipipe_trace_end(0x800D);
+#endif /* CONFIG_IPIPE_TRACE_IRQSOFF */
}
asmlinkage int __ipipe_syscall_root(struct pt_regs regs)
--- linux-2.6.14.3/kernel/ipipe/tracer.c.orig 2006-01-02 20:44:21.0
+0100
+++ linux-2.6.14.3/kernel/ipipe/tracer.c2006-01-06 02:35:08.0
+0100
@@ -47,8 +47,10 @@
#define IPIPE_TFLG_NMI_LOCK 0x0001
#define IPIPE_TFLG_NMI_HIT 0x0002
-#define IPIPE_TFLG_HWIRQ_OFF0x0004
-#define IPIPE_TFLG_FREEZING 0x0008
+#define IPIPE_TFLG_NMI_FREEZE_REQ 0x0004
+
+#define IPIPE_TFLG_HWIRQ_OFF0x0100
+#define IPIPE_TFLG_FREEZING 0x0200
struct ipipe_trace_point{
@@ -63,10 +65,13 @@ struct ipipe_trace_point{
struct ipipe_trace_path{
volatile int flags;
int dump_lock; /* separated from flags due to cross-cpu access */
- int trace_pos;
- int begin, end;
- int post_trace;
- unsigned long long length;
+ int trace_pos; /* next point to fill */
+ int begin, end; /* finalised path begin and end */
+ int post_trace; /*
