Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* Daniel Walker <[EMAIL PROTECTED]> wrote: > On Thu, 2005-08-04 at 15:52 +0200, Ingo Molnar wrote: > > > would be nice to clean up the impact of the latency-histogram code some > > more though: e.g. the #ifdef jungle check_critical_timing() is > > disgusting. Could be cleaned up by always recording the latency_type > > being currently traced into a new tr->latency_type field, and then using > > that in check_critical_timing(). > > the code appears to be adding ifdefs to make preempt_max_latency work > like preempt_threshold , I think all the nasty ifdefs could go away if > we just made it use preempt_threshold .. Plus it logs latency during > boot up cause preempt_max_latency equals zero . yes. Would be nice to have these cleanups too. The #ifdef impact of the LATENCY_HIST code is quite high at the moment, and it needs to be decreased. Ingo - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* Daniel Walker [EMAIL PROTECTED] wrote: On Thu, 2005-08-04 at 15:52 +0200, Ingo Molnar wrote: would be nice to clean up the impact of the latency-histogram code some more though: e.g. the #ifdef jungle check_critical_timing() is disgusting. Could be cleaned up by always recording the latency_type being currently traced into a new tr-latency_type field, and then using that in check_critical_timing(). the code appears to be adding ifdefs to make preempt_max_latency work like preempt_threshold , I think all the nasty ifdefs could go away if we just made it use preempt_threshold .. Plus it logs latency during boot up cause preempt_max_latency equals zero . yes. Would be nice to have these cleanups too. The #ifdef impact of the LATENCY_HIST code is quite high at the moment, and it needs to be decreased. Ingo - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
On Thu, 2005-08-04 at 15:52 +0200, Ingo Molnar wrote: > would be nice to clean up the impact of the latency-histogram code some > more though: e.g. the #ifdef jungle check_critical_timing() is > disgusting. Could be cleaned up by always recording the latency_type > being currently traced into a new tr->latency_type field, and then using > that in check_critical_timing(). the code appears to be adding ifdefs to make preempt_max_latency work like preempt_threshold , I think all the nasty ifdefs could go away if we just made it use preempt_threshold .. Plus it logs latency during boot up cause preempt_max_latency equals zero . Daniel - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
On Thu, 2005-08-04 at 15:52 +0200, Ingo Molnar wrote: would be nice to clean up the impact of the latency-histogram code some more though: e.g. the #ifdef jungle check_critical_timing() is disgusting. Could be cleaned up by always recording the latency_type being currently traced into a new tr-latency_type field, and then using that in check_critical_timing(). the code appears to be adding ifdefs to make preempt_max_latency work like preempt_threshold , I think all the nasty ifdefs could go away if we just made it use preempt_threshold .. Plus it logs latency during boot up cause preempt_max_latency equals zero . Daniel - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* Yang Yi <[EMAIL PROTECTED]> wrote: > > looks pretty good! I'll look at merging your patch after KS/OLS. > > Do you have any trouble while you merge that latency logger patch? i've merged it to the -52-11 patch that, and i've uploaded it a couple of minutes ago. i have done a number of cleanups on it - e.g. instead of latency logging it's now called latency histogram, and i've also fixed a number of coding style issues. Please double-check that it's still OK, seems to work here. would be nice to clean up the impact of the latency-histogram code some more though: e.g. the #ifdef jungle check_critical_timing() is disgusting. Could be cleaned up by always recording the latency_type being currently traced into a new tr->latency_type field, and then using that in check_critical_timing(). Ingo - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* Yang Yi [EMAIL PROTECTED] wrote: looks pretty good! I'll look at merging your patch after KS/OLS. Do you have any trouble while you merge that latency logger patch? i've merged it to the -52-11 patch that, and i've uploaded it a couple of minutes ago. i have done a number of cleanups on it - e.g. instead of latency logging it's now called latency histogram, and i've also fixed a number of coding style issues. Please double-check that it's still OK, seems to work here. would be nice to clean up the impact of the latency-histogram code some more though: e.g. the #ifdef jungle check_critical_timing() is disgusting. Could be cleaned up by always recording the latency_type being currently traced into a new tr-latency_type field, and then using that in check_critical_timing(). Ingo - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
>> Hi, Ingo >> >> This patch can record interrupt-off latency, preemption-off latency >> and wakeup latency in a big history array, in the meanwhile, it >> dummies up printks produced by these latency timing. >looks pretty good! I'll look at merging your patch after KS/OLS. > > Ingo Hi, ingo Do you have any trouble while you merge that latency logger patch? - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
Hi, Ingo This patch can record interrupt-off latency, preemption-off latency and wakeup latency in a big history array, in the meanwhile, it dummies up printks produced by these latency timing. looks pretty good! I'll look at merging your patch after KS/OLS. Ingo Hi, ingo Do you have any trouble while you merge that latency logger patch? - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* yangyi <[EMAIL PROTECTED]> wrote: > Hi, Ingo > > This patch can record interrupt-off latency, preemption-off latency > and wakeup latency in a big history array, in the meanwhile, it > dummies up printks produced by these latency timing. looks pretty good! I'll look at merging your patch after KS/OLS. Ingo - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
* yangyi [EMAIL PROTECTED] wrote: Hi, Ingo This patch can record interrupt-off latency, preemption-off latency and wakeup latency in a big history array, in the meanwhile, it dummies up printks produced by these latency timing. looks pretty good! I'll look at merging your patch after KS/OLS. Ingo - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
[PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
Hi, Ingo
This patch can record interrupt-off latency, preemption-off latency and
wakeup latency in a big history array, in the meanwhile, it dummies up
printks produced
by these latency timing.
This patch adds three options: "Log interrupts-off critical section
latency", "Log non-preemptible critical section latency" and "Log wakeup
latency", they may be selected together, but just enabling one of them
will be better.
All the latency history can be viewed via /proc interface:
(Note, * presents CPU ID)
###interrupt-off latency history
cat /proc/latency_log/interrupt_off_latency/CPU*
###preemption-off latency history
cat /proc/latency_log/preemption_off_latency/CPU*
###wakeup latency history
cat /proc/latency_log/wakeup_latency/CPU*
Latency tracing will trace the maximum sample of three options, so
/proc/latency_trace can provide the detailed tracing for maximum sample.
diffstat:
kernel/Makefile |1
kernel/latency.c | 96
kernel/latency_log.c | 292
+++
lib/Kconfig.debug | 59 ++
4 files changed, 445 insertions(+), 3 deletions(-)
--- /dev/null 2003-01-30 18:24:37.0 +0800
+++ linux-2.6.12/kernel/latency_log.c 2005-07-15 17:45:53.0
+0800
@@ -0,0 +1,292 @@
+/*
+ * kernel/latency_log.c
+ *
+ * Add support for history logs of preemption-off latency and
+ * interrupt-off latency and wakeup latency, it depends on
+ * Real-Time Preemption Support.
+ *
+ * Copyright (C) 2005, 2007 MontaVista Software, Inc.
+ * Yi Yang <[EMAIL PROTECTED]>
+ *
+ */
+#include
+#include
+#include
+#include
+#include
+#include
+
+#define MAX_ENTRY_NUM 10240
+#define LATENCY_TYPE_NUM 3
+
+typedef struct log_data_struct {
+ atomic_t log_mode; /* 0 log, 1 don't log */
+ unsigned long min_lat;
+ unsigned long avg_lat;
+ unsigned long max_lat;
+ unsigned long long beyond_log_bound_samples;
+ unsigned long long accumulate_lat;
+ unsigned long long total_samples;
+ unsigned long long log_array[MAX_ENTRY_NUM];
+} log_data_t;
+
+enum {
+ INTERRUPT_LATENCY = 0,
+ PREEMPT_LATENCY,
+ WAKEUP_LATENCY
+};
+
+static struct proc_dir_entry * latency_log_root = NULL;
+static char * latency_log_proc_dir_root = "latency_log";
+
+static char * percpu_proc_name = "CPU";
+
+#ifdef CONFIG_INTERRUPT_OFF_LOG
+static DEFINE_PER_CPU(log_data_t, interrupt_off_log);
+static char * interrupt_off_log_proc_dir = "interrupt_off_latency";
+#endif
+
+#ifdef CONFIG_PREEMPT_OFF_LOG
+static DEFINE_PER_CPU(log_data_t, preempt_off_log);
+static char * preempt_off_log_proc_dir = "preempt_off_latency";
+#endif
+
+#ifdef CONFIG_WAKEUP_LATENCY_LOG
+static DEFINE_PER_CPU(log_data_t, wakeup_latency_log);
+static char * wakeup_latency_log_proc_dir = "wakeup_latency";
+#endif
+
+static struct proc_dir_entry *entry[LATENCY_TYPE_NUM][NR_CPUS];
+
+static inline u64 u64_div(u64 x, u64 y)
+{
+do_div(x, y);
+return x;
+}
+
+void latency_log(int latency_type, int cpu, unsigned long latency)
+{
+ log_data_t * my_log;
+
+
+ if ((cpu < 0) || (cpu >= NR_CPUS) || (latency_type <
INTERRUPT_LATENCY)
+ || (latency_type > WAKEUP_LATENCY) || (latency < 0)) {
+ return;
+ }
+
+ switch(latency_type) {
+#ifdef CONFIG_INTERRUPT_OFF_LOG
+ case INTERRUPT_LATENCY:
+ my_log = (log_data_t *)_cpu(interrupt_off_log, cpu);
+ if (atomic_read(_log->log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+
+#ifdef CONFIG_PREEMPT_OFF_LOG
+ case PREEMPT_LATENCY:
+ my_log = (log_data_t *)_cpu(preempt_off_log, cpu);
+ if (atomic_read(_log->log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+
+#ifdef CONFIG_WAKEUP_LATENCY_LOG
+ case WAKEUP_LATENCY:
+ my_log = (log_data_t *)_cpu(wakeup_latency_log, cpu);
+ if (atomic_read(_log->log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+ default:
+ return;
+ }
+
+ if (latency >= MAX_ENTRY_NUM) {
+ my_log->beyond_log_bound_samples++;
+ }
+ else {
+ my_log->log_array[latency]++;
+ }
+
+ if (latency < my_log->min_lat) {
+ my_log->min_lat = latency;
+ }
+ else if (latency > my_log->max_lat) {
+ my_log->max_lat = latency;
+ }
+
+ my_log->total_samples++;
+ my_log->accumulate_lat += latency;
+ my_log->avg_lat = (unsigned long)u64_div(my_log->accumulate_lat,
my_log->total_samples);
+ return;
+}
+
+static void *l_start(struct seq_file *m, loff_t * pos)
+{
+ loff_t *index_ptr = kmalloc(sizeof(loff_t), GFP_KERNEL);
+ loff_t index = *pos;
+ log_data_t *my_log = (log_data_t *) m->private;
+
+
[PATCH] latency logger for realtime-preempt-2.6.12-final-V0.7.51-30
Hi, Ingo
This patch can record interrupt-off latency, preemption-off latency and
wakeup latency in a big history array, in the meanwhile, it dummies up
printks produced
by these latency timing.
This patch adds three options: Log interrupts-off critical section
latency, Log non-preemptible critical section latency and Log wakeup
latency, they may be selected together, but just enabling one of them
will be better.
All the latency history can be viewed via /proc interface:
(Note, * presents CPU ID)
###interrupt-off latency history
cat /proc/latency_log/interrupt_off_latency/CPU*
###preemption-off latency history
cat /proc/latency_log/preemption_off_latency/CPU*
###wakeup latency history
cat /proc/latency_log/wakeup_latency/CPU*
Latency tracing will trace the maximum sample of three options, so
/proc/latency_trace can provide the detailed tracing for maximum sample.
diffstat:
kernel/Makefile |1
kernel/latency.c | 96
kernel/latency_log.c | 292
+++
lib/Kconfig.debug | 59 ++
4 files changed, 445 insertions(+), 3 deletions(-)
--- /dev/null 2003-01-30 18:24:37.0 +0800
+++ linux-2.6.12/kernel/latency_log.c 2005-07-15 17:45:53.0
+0800
@@ -0,0 +1,292 @@
+/*
+ * kernel/latency_log.c
+ *
+ * Add support for history logs of preemption-off latency and
+ * interrupt-off latency and wakeup latency, it depends on
+ * Real-Time Preemption Support.
+ *
+ * Copyright (C) 2005, 2007 MontaVista Software, Inc.
+ * Yi Yang [EMAIL PROTECTED]
+ *
+ */
+#include linux/config.h
+#include linux/module.h
+#include linux/proc_fs.h
+#include linux/seq_file.h
+#include linux/percpu.h
+#include asm/atomic.h
+
+#define MAX_ENTRY_NUM 10240
+#define LATENCY_TYPE_NUM 3
+
+typedef struct log_data_struct {
+ atomic_t log_mode; /* 0 log, 1 don't log */
+ unsigned long min_lat;
+ unsigned long avg_lat;
+ unsigned long max_lat;
+ unsigned long long beyond_log_bound_samples;
+ unsigned long long accumulate_lat;
+ unsigned long long total_samples;
+ unsigned long long log_array[MAX_ENTRY_NUM];
+} log_data_t;
+
+enum {
+ INTERRUPT_LATENCY = 0,
+ PREEMPT_LATENCY,
+ WAKEUP_LATENCY
+};
+
+static struct proc_dir_entry * latency_log_root = NULL;
+static char * latency_log_proc_dir_root = latency_log;
+
+static char * percpu_proc_name = CPU;
+
+#ifdef CONFIG_INTERRUPT_OFF_LOG
+static DEFINE_PER_CPU(log_data_t, interrupt_off_log);
+static char * interrupt_off_log_proc_dir = interrupt_off_latency;
+#endif
+
+#ifdef CONFIG_PREEMPT_OFF_LOG
+static DEFINE_PER_CPU(log_data_t, preempt_off_log);
+static char * preempt_off_log_proc_dir = preempt_off_latency;
+#endif
+
+#ifdef CONFIG_WAKEUP_LATENCY_LOG
+static DEFINE_PER_CPU(log_data_t, wakeup_latency_log);
+static char * wakeup_latency_log_proc_dir = wakeup_latency;
+#endif
+
+static struct proc_dir_entry *entry[LATENCY_TYPE_NUM][NR_CPUS];
+
+static inline u64 u64_div(u64 x, u64 y)
+{
+do_div(x, y);
+return x;
+}
+
+void latency_log(int latency_type, int cpu, unsigned long latency)
+{
+ log_data_t * my_log;
+
+
+ if ((cpu 0) || (cpu = NR_CPUS) || (latency_type
INTERRUPT_LATENCY)
+ || (latency_type WAKEUP_LATENCY) || (latency 0)) {
+ return;
+ }
+
+ switch(latency_type) {
+#ifdef CONFIG_INTERRUPT_OFF_LOG
+ case INTERRUPT_LATENCY:
+ my_log = (log_data_t *)per_cpu(interrupt_off_log, cpu);
+ if (atomic_read(my_log-log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+
+#ifdef CONFIG_PREEMPT_OFF_LOG
+ case PREEMPT_LATENCY:
+ my_log = (log_data_t *)per_cpu(preempt_off_log, cpu);
+ if (atomic_read(my_log-log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+
+#ifdef CONFIG_WAKEUP_LATENCY_LOG
+ case WAKEUP_LATENCY:
+ my_log = (log_data_t *)per_cpu(wakeup_latency_log, cpu);
+ if (atomic_read(my_log-log_mode) == 0) {
+ return;
+ }
+ break;
+#endif
+ default:
+ return;
+ }
+
+ if (latency = MAX_ENTRY_NUM) {
+ my_log-beyond_log_bound_samples++;
+ }
+ else {
+ my_log-log_array[latency]++;
+ }
+
+ if (latency my_log-min_lat) {
+ my_log-min_lat = latency;
+ }
+ else if (latency my_log-max_lat) {
+ my_log-max_lat = latency;
+ }
+
+ my_log-total_samples++;
+ my_log-accumulate_lat += latency;
+ my_log-avg_lat = (unsigned long)u64_div(my_log-accumulate_lat,
my_log-total_samples);
+ return;
+}
+
+static void *l_start(struct seq_file *m, loff_t * pos)
+{
+ loff_t *index_ptr = kmalloc(sizeof(loff_t), GFP_KERNEL);
+ loff_t index = *pos;
+
