[PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

STALE7264d

11 messages, 3 authors, 2006-12-04 · open the first message on its own page

[PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-11-13 19:51:25

In addition to the clock jump-back check being falsely triggered by clock wrap
with 32-bit cycles_t, as noticed by Kevin Hilman, there's another issue: using
%Lx format to print 32-bit values warrants erroneous values on 32-bit machines
like ARM and PPC32...

Signed-off-by: Sergei Shtylyov <redacted>

---
There's a lot more of this cr*p with CONFIG_LATENCY_TRACE enabled, hence is
take 3 on this patch...

 kernel/latency_trace.c |   42 +++++++++++++++++++++---------------------
 1 files changed, 21 insertions(+), 21 deletions(-)

Index: linux-2.6/kernel/latency_trace.c
===================================================================
--- linux-2.6.orig/kernel/latency_trace.c
+++ linux-2.6/kernel/latency_trace.c
@@ -989,30 +989,30 @@ static void update_out_trace(void)
 			tmp_max = max_tr.traces + cpu;
 			entries = min(tmp_max->trace_idx, MAX_TRACE-1);
 			printk("CPU%d: %016Lx (%016Lx) ... #%d (%016Lx) %016Lx\n", cpu,
-				tmp_max->trace[0].timestamp,
-				tmp_max->trace[1].timestamp,
+				(u64)tmp_max->trace[0].timestamp,
+				(u64)tmp_max->trace[1].timestamp,
 				entries,
-				tmp_max->trace[entries-2].timestamp,
-				tmp_max->trace[entries-1].timestamp);
+				(u64)tmp_max->trace[entries-2].timestamp,
+				(u64)tmp_max->trace[entries-1].timestamp);
 		}
 		tmp_max = max_tr.traces + max_tr.cpu;
 		entries = min(tmp_max->trace_idx, MAX_TRACE-1);
 
 		printk("CPU%d entries: %d\n", max_tr.cpu, entries);
-		printk("first stamp: %016Lx\n", first_stamp);
-		printk(" last stamp: %016Lx\n", first_stamp);
+		printk("first stamp: %016Lx\n", (u64)first_stamp);
+		printk(" last stamp: %016Lx\n", (u64)first_stamp);
 	}
 
 #if 0
-	printk("first_stamp: %Ld [%016Lx]\n", first_stamp, first_stamp);
-	printk(" last_stamp: %Ld [%016Lx]\n", last_stamp, last_stamp);
+	printk("first_stamp: %Ld [%016Lx]\n", (u64)first_stamp, (u64)first_stamp);
+	printk(" last_stamp: %Ld [%016Lx]\n", (u64)last_stamp, (u64)last_stamp);
 	printk("   +1 stamp: %Ld [%016Lx]\n",
-		tmp_max->trace[entries].timestamp,
-		tmp_max->trace[entries].timestamp);
+		(u64)tmp_max->trace[entries].timestamp,
+		(u64)tmp_max->trace[entries].timestamp);
 	printk("   +2 stamp: %Ld [%016Lx]\n",
-		tmp_max->trace[entries+1].timestamp,
-		tmp_max->trace[entries+1].timestamp);
-	printk("      delta: %Ld\n", last_stamp-first_stamp);
+		(u64)tmp_max->trace[entries+1].timestamp,
+		(u64)tmp_max->trace[entries+1].timestamp);
+	printk("      delta: %Ld\n", (u64)(last_stamp-first_stamp));
 	printk("    entries: %d\n", entries);
 #endif
 
@@ -1240,7 +1240,7 @@ static int notrace l_show_fn(struct seq_
 			pid_to_cmdline(entry->pid),
 			entry->pid, entry->cpu, entry->flags,
 			entry->preempt_count, trace_idx,
-			entry->timestamp, abs_usecs/1000,
+			(u64)entry->timestamp, abs_usecs/1000,
 			abs_usecs % 1000, rel_usecs/1000, rel_usecs % 1000);
 		print_name_offset(m, entry->u.fn.eip);
 		seq_puts(m, " (");
@@ -1623,8 +1623,8 @@ check_critical_timing(int cpu, struct cp
 #ifndef CONFIG_CRITICAL_LATENCY_HIST
 	if (!preempt_thresh && preempt_max_latency > delta) {
 		printk("bug: updating %016Lx > %016Lx?\n",
-			preempt_max_latency, delta);
-		printk("  [%016Lx %016Lx %016Lx]\n", T0, T1, T2);
+			(u64)preempt_max_latency, (u64)delta);
+		printk("  [%016Lx %016Lx %016Lx]\n", (u64)T0, (u64)T1, (u64)T2);
 	}
 #endif
 
@@ -2006,7 +2006,7 @@ check_wakeup_timing(struct cpu_trace *tr
 	____trace(smp_processor_id(), TRACE_FN, tr, CALLER_ADDR0, parent_eip, 0, 0, 0, *flags);
 	T2 = get_cycles();
 	if (T2 < T1)
-		printk("bug2: %016Lx < %016Lx!\n", T2, T1);
+		printk("bug2: %016Lx < %016Lx!\n", (u64)T2, (u64)T1);
 	delta = T2-T0;
 
 	latency = cycles_to_usecs(delta);
@@ -2023,8 +2023,8 @@ check_wakeup_timing(struct cpu_trace *tr
 #ifndef CONFIG_WAKEUP_LATENCY_HIST
 	if (!preempt_thresh && preempt_max_latency > delta) {
 		printk("bug2: updating %016Lx > %016Lx?\n",
-			preempt_max_latency, delta);
-		printk("  [%016Lx %016Lx %016Lx]\n", T0, T1, T2);
+			(u64)preempt_max_latency, (u64)delta);
+		printk("  [%016Lx %016Lx %016Lx]\n", (u64)T0, (u64)T1, (u64)T2);
 	}
 #endif
 
@@ -2273,8 +2273,8 @@ long user_trace_stop(void)
 		if (!preempt_thresh && preempt_max_latency > delta) {
 			local_irq_restore(flags);
 			printk("bug3: updating %016Lx > %016Lx [%016Lx]?\n",
-				preempt_max_latency, delta, tmp0);
-			printk("  [%016Lx %016Lx]\n", T0, T1);
+				(u64)preempt_max_latency, (u64)delta, tmp0);
+			printk("  [%016Lx %016Lx]\n", (u64)T0, (u64)T1);
 			local_irq_save(flags);
 		}
 

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-12-03 19:32:25

Hello, I wrote:
In addition to the clock jump-back check being falsely triggered by clock wrap
with 32-bit cycles_t, as noticed by Kevin Hilman, there's another issue: using
%Lx format to print 32-bit values warrants erroneous values on 32-bit machines
like ARM and PPC32...
Signed-off-by: Sergei Shtylyov <redacted>
   What was the destiny of that patch? I haven't seen it accepted, haven't seen any comments... while this is not a mere warning fix. What am I expected to do to get it accepted -- recast it against 2.6.19-rt1?
 kernel/latency_trace.c |   42 +++++++++++++++++++++---------------------
 1 files changed, 21 insertions(+), 21 deletions(-)
WBR, Sergei

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Ingo Molnar <hidden>
Date: 2006-12-04 09:52:10

* Sergei Shtylyov [off-list ref] wrote:
   What was the destiny of that patch? I haven't seen it accepted, 
haven't seen any comments... while this is not a mere warning fix. 
What am I expected to do to get it accepted -- recast it against 
2.6.19-rt1?
i'd suggest to redo it - but please keep it simple and clean. Those 
dozens of casts to u64 are quite ugly. Why is cycles_t 32-bits on some 
of the arches to begin with?

	Ingo

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-12-04 12:27:43

Hello.

Ingo Molnar wrote:
quoted
  What was the destiny of that patch? I haven't seen it accepted, haven't seen any comments... while this is not a mere warning fix. What am I expected to do to get it accepted -- recast it against 2.6.19-rt1?
i'd suggest to redo it - but please keep it simple and clean. Those dozens of casts to u64 are quite ugly.
   Alas, there's *nothing* I can do about it with 32-bit cycles_t. And if you look at the kernel, this is not the only case of such "ugliness", look at this commit for example:

http://www.kernel.org/git/?p=linux/kernel/git/paulus/powerpc.git;a=commit;h=685143ac1f7a579a3fac9c7f2ac8f82e95af6864
Why is cycles_t 32-bits on some of the arches to begin with?
   I guess this was done for speed reasons. That's not a qustion for me although...
	Ingo
WBR, Sergei

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Ingo Molnar <hidden>
Date: 2006-12-04 15:40:43

* Sergei Shtylyov [off-list ref] wrote:
quoted
i'd suggest to redo it - but please keep it simple and clean. Those 
dozens of casts to u64 are quite ugly.
   Alas, there's *nothing* I can do about it with 32-bit cycles_t. 
[...]
there's *always* a way to do such things more cleanly - such as the 
patch below. Could you try to fix it up for 32-bit cycles_t platforms? I 
bet the hackery will be limited to now() and maybe the conversion 
routines, instead of spreading all around latency_trace.c.

	Ingo

Index: linux/kernel/latency_trace.c
===================================================================
--- linux.orig/kernel/latency_trace.c
+++ linux/kernel/latency_trace.c
@@ -18,6 +18,7 @@
 #include <linux/kallsyms.h>
 #include <linux/seq_file.h>
 #include <linux/interrupt.h>
+#include <linux/clocksource.h>
 #include <linux/proc_fs.h>
 #include <linux/latency_hist.h>
 #include <linux/utsrelease.h>
@@ -43,7 +44,7 @@ int trace_use_raw_cycles = 1;
  * points, but the trace entries inbetween are timestamped with
  * get_cycles().
  */
-static unsigned long notrace cycles_to_us(cycles_t delta)
+static unsigned long notrace cycles_to_us(cycle_t delta)
 {
 	if (!trace_use_raw_cycles)
 		return cycles_to_usecs(delta);
@@ -60,7 +61,7 @@ static unsigned long notrace cycles_to_u
 	return (unsigned long) delta;
 }
 
-static notrace inline cycles_t now(void)
+static notrace inline cycle_t now(void)
 {
 	if (trace_use_raw_cycles)
 		return get_cycles();
@@ -150,17 +151,17 @@ enum trace_flag_type
  * we clear it after bootup.
  */
 #ifdef CONFIG_LATENCY_HIST
-static cycles_t preempt_max_latency = (cycles_t)0UL;
+static cycle_t preempt_max_latency = (cycle_t)0UL;
 #else
-static cycles_t preempt_max_latency = (cycles_t)ULONG_MAX;
+static cycle_t preempt_max_latency = (cycle_t)ULONG_MAX;
 #endif
 
-static cycles_t preempt_thresh;
+static cycle_t preempt_thresh;
 
 /*
  * Should this new latency be reported/recorded?
  */
-static int report_latency(cycles_t delta)
+static int report_latency(cycle_t delta)
 {
 	if (latency_hist_flag && !trace_user_triggered)
 		return 1;
@@ -193,7 +194,7 @@ struct trace_entry {
 	char flags;
 	char preempt_count; // assumes PREEMPT_MASK is 8 bits or less
 	int pid;
-	cycles_t timestamp;
+	cycle_t timestamp;
 	union {
 		struct {
 			unsigned long eip;
@@ -224,7 +225,7 @@ struct trace_entry {
 struct cpu_trace {
 	atomic_t disabled;
 	unsigned long trace_idx;
-	cycles_t preempt_timestamp;
+	cycle_t preempt_timestamp;
 	unsigned long critical_start, critical_end;
 	unsigned long critical_sequence;
 	atomic_t overrun;
@@ -274,7 +275,7 @@ int trace_user_trigger_irq = -1;
 
 struct saved_trace_struct {
 	int cpu;
-	cycles_t first_timestamp, last_timestamp;
+	cycle_t first_timestamp, last_timestamp;
 	struct cpu_trace traces[NR_CPUS];
 } ____cacheline_aligned_in_smp;
 
@@ -586,7 +587,7 @@ ____trace(int cpu, enum trace_type type,
 {
 	struct trace_entry *entry;
 	unsigned long idx, idx_next;
-	cycles_t timestamp;
+	cycle_t timestamp;
 	u32 pc;
 
 #ifdef CONFIG_DEBUG_PREEMPT
@@ -972,7 +973,7 @@ struct block_idx {
  */
 static int min_idx(struct block_idx *bidx)
 {
-	cycles_t min_stamp = (cycles_t) -1;
+	cycle_t min_stamp = (cycle_t) -1;
 	struct trace_entry *entry;
 	int cpu, min_cpu = -1, idx;
 
@@ -1006,7 +1007,7 @@ static int min_idx(struct block_idx *bid
 static void update_out_trace(void)
 {
 	struct trace_entry *out_entry, *entry, *tmp;
-	cycles_t stamp, first_stamp, last_stamp;
+	cycle_t stamp, first_stamp, last_stamp;
 	struct block_idx bidx = { { 0, }, };
 	struct cpu_trace *tmp_max, *tmp_out;
 	int cpu, sum, entries, overrun_sum;
@@ -1694,7 +1695,7 @@ static void notrace
 check_critical_timing(int cpu, struct cpu_trace *tr, unsigned long parent_eip)
 {
 	unsigned long latency, t0, t1;
-	cycles_t T0, T1, T2, delta;
+	cycle_t T0, T1, T2, delta;
 	unsigned long flags;
 
 	if (trace_user_triggered)
@@ -1721,7 +1722,7 @@ check_critical_timing(int cpu, struct cp
 	T2 = get_monotonic_cycles();
 
 	/* check for buggy clocks, handling wrap for 32-bit clocks */
-	if (TYPE_EQUAL(cycles_t, unsigned long)) {
+	if (TYPE_EQUAL(cycle_t, unsigned long)) {
 		if (time_after((unsigned long)T1, (unsigned long)T2))
 			printk("bug: %08lx < %08lx!\n",
 				(unsigned long)T2, (unsigned long)T1);
@@ -2100,7 +2101,7 @@ check_wakeup_timing(struct cpu_trace *tr
 {
 	int cpu = raw_smp_processor_id();
 	unsigned long latency, t0, t1;
-	cycles_t T0, T1, delta;
+	cycle_t T0, T1, delta;
 
 	if (trace_user_triggered)
 		return;
@@ -2293,7 +2294,7 @@ long user_trace_start(void)
 	 * bootup then we assume that this was the intention
 	 * (we wont get any tracing done otherwise):
 	 */
-	if (preempt_max_latency == (cycles_t)ULONG_MAX)
+	if (preempt_max_latency == (cycle_t)ULONG_MAX)
 		preempt_max_latency = 0;
 
 	/*
@@ -2343,7 +2344,7 @@ long user_trace_stop(void)
 {
 	unsigned long latency, flags;
 	struct cpu_trace *tr;
-	cycles_t delta;
+	cycle_t delta;
 
 	if (!trace_user_triggered || trace_print_at_crash || print_functions)
 		return -EINVAL;
@@ -2371,7 +2372,7 @@ long user_trace_stop(void)
 
 	atomic_inc(&tr->disabled);
 	if (tr->preempt_timestamp) {
-		cycles_t T0, T1;
+		cycle_t T0, T1;
 		unsigned long long tmp0;
 
 		T0 = tr->preempt_timestamp;
@@ -2633,7 +2634,7 @@ void print_traces(struct task_struct *ta
 static int preempt_read_proc(char *page, char **start, off_t off,
 			     int count, int *eof, void *data)
 {
-	cycles_t *max = data;
+	cycle_t *max = data;
 
 	return sprintf(page, "%ld\n", cycles_to_usecs(*max));
 }
@@ -2642,7 +2643,7 @@ static int preempt_write_proc(struct fil
 			      unsigned long count, void *data)
 {
 	unsigned int c, done = 0, val, sum = 0;
-	cycles_t *max = data;
+	cycle_t *max = data;
 
 	while (count) {
 		if (get_user(c, buffer))
Index: linux/kernel/timer.c
===================================================================
--- linux.orig/kernel/timer.c
+++ linux/kernel/timer.c
@@ -889,7 +889,7 @@ static inline s64 __get_nsec_offset(void
 	return ns_offset;
 }
 
-cycles_t notrace get_monotonic_cycles(void)
+cycle_t notrace get_monotonic_cycles(void)
 {
 	cycle_t cycle_now, cycle_delta;
 
@@ -902,7 +902,7 @@ cycles_t notrace get_monotonic_cycles(vo
 	return clock->cycle_last + cycle_delta;
 }
 
-unsigned long notrace cycles_to_usecs(cycles_t cycles)
+unsigned long notrace cycles_to_usecs(cycle_t cycles)
 {
 	u64 ret = cyc2ns(clock, cycles);
 
@@ -911,7 +911,7 @@ unsigned long notrace cycles_to_usecs(cy
 	return ret;
 }
 
-cycles_t notrace usecs_to_cycles(unsigned long usecs)
+cycle_t notrace usecs_to_cycles(unsigned long usecs)
 {
 	return ns2cyc(clock, (u64)usecs * 1000);
 }

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-12-04 16:19:39

Hello.

Ingo Molnar wrote:
quoted
quoted
i'd suggest to redo it - but please keep it simple and clean. Those dozens of casts to u64 are quite ugly.
quoted
  Alas, there's *nothing* I can do about it with 32-bit cycles_t. [...]
there's *always* a way to do such things more cleanly - such as the patch below. Could you try to fix it up for 32-bit cycles_t platforms? I bet the hackery will be limited to now() and maybe the conversion routines, instead of spreading all around latency_trace.c.
   I'm not sure what you want me to do... You've switched to clocksource specific cycle_t (which is u64), do you want me to use the clocksource interface to get the cycles from now on?
quoted hunk
Index: linux/kernel/latency_trace.c
===================================================================
--- linux.orig/kernel/latency_trace.c
+++ linux/kernel/latency_trace.c
[...]
quoted hunk
@@ -1721,7 +1722,7 @@ check_critical_timing(int cpu, struct cp
 	T2 = get_monotonic_cycles();
 
 	/* check for buggy clocks, handling wrap for 32-bit clocks */
-	if (TYPE_EQUAL(cycles_t, unsigned long)) {
+	if (TYPE_EQUAL(cycle_t, unsigned long)) {
 		if (time_after((unsigned long)T1, (unsigned long)T2))
 			printk("bug: %08lx < %08lx!\n",
 				(unsigned long)T2, (unsigned long)T1);
   This earlier fix by Kevin woulnd't have sense anymore with cycle_t...

WBR, Sergei

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Ingo Molnar <hidden>
Date: 2006-12-04 16:24:14


* Sergei Shtylyov [off-list ref] wrote:
quoted
	/* check for buggy clocks, handling wrap for 32-bit clocks */
-	if (TYPE_EQUAL(cycles_t, unsigned long)) {
+	if (TYPE_EQUAL(cycle_t, unsigned long)) {
		if (time_after((unsigned long)T1, (unsigned long)T2))
			printk("bug: %08lx < %08lx!\n",
				(unsigned long)T2, (unsigned long)T1);
   This earlier fix by Kevin woulnd't have sense anymore with cycle_t...
yeah, indeed - i've zapped this one too.

basically, what i'd like is the 32-bit clocks/cycles be handled 
intelligently, and not adding to the cruft that already is in 
kernel/latency_tracing.c.

	Ingo

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-12-04 17:08:24

Hello.

Ingo Molnar wrote:
quoted
quoted
/* check for buggy clocks, handling wrap for 32-bit clocks */
-	if (TYPE_EQUAL(cycles_t, unsigned long)) {
+	if (TYPE_EQUAL(cycle_t, unsigned long)) {
	if (time_after((unsigned long)T1, (unsigned long)T2))
		printk("bug: %08lx < %08lx!\n",
			(unsigned long)T2, (unsigned long)T1);
quoted
  This earlier fix by Kevin woulnd't have sense anymore with cycle_t...
yeah, indeed - i've zapped this one too.
   Moreover, it was somewhat incorrect from the very start since 'unsigned long' is 64-bit on 64-bit machines, and cycles_t is 'unsigned long' on both PPC32 and PPC64, so else branch would've *never* be executed...
basically, what i'd like is the 32-bit clocks/cycles be handled intelligently, and not adding to the cruft that already is in kernel/latency_tracing.c.
   Yeah, I've looked at 2.6.19-rt2 and saw the new approach. But what's left to fix there, only the case of using PPC32 raw cycles? I guess you only need to cast a result of get_cycles() to cycle_t... wait, it'll be explicitly cast in the return stmt, won't it?
	Ingo
WBR, Sergei

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Sergei Shtylyov <hidden>
Date: 2006-12-04 18:03:10

Hello.

Sergei Shtylyov wrote:
quoted
Why is cycles_t 32-bits on some of the arches to begin with?
    I guess this was done for speed reasons.
   The whole 64-bit timebase can't be rad atomically on PPC32. ARM probably has stricter limitations...
quoted
Ingo
WBR, Sergei

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Roman Zippel <hidden>
Date: 2006-12-04 21:57:18

Hi,

On Monday 04 December 2006 16:39, Ingo Molnar wrote:
there's *always* a way to do such things more cleanly - such as the
patch below. Could you try to fix it up for 32-bit cycles_t platforms? I
bet the hackery will be limited to now() and maybe the conversion
routines, instead of spreading all around latency_trace.c.
While I'm not against this patch, but on m68k I prefer a 32bit cycle type 
(however it's called), so it doesn't solve the original problem.

bye, Roman

Re: [PATCH] 2.6.18-rt7: fix more issues with 32-bit cycles_t in latency_trace.c (take 3)

From: Ingo Molnar <hidden>
Date: 2006-12-04 21:59:56

* Roman Zippel [off-list ref] wrote:
While I'm not against this patch, but on m68k I prefer a 32bit cycle 
type (however it's called), so it doesn't solve the original problem.
i havent changed the cycles_t type - it's still 32-bit. I agree with you 
that we dont want to bloat 32-bit arch-level code by artificially 
forcing everyone to a 64-bit cycles_t.

	Ingo
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help