lkml.org 
[lkml]   [2007]   [Apr]   [23]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
Patch in this message
/
Subject[PATCH -rt] add caller for x86_64 trace from entry.S
From
Date
Currently the x86_64 trace code from entry.S calls a
trace_hardirqs_on_thunk, that then calls trace_hardirqs_on.

The problem is that the trace records the call coming from
trace_hardirqs_on_thunk and not the location in entry.S, which makes it
difficult to find exactly where a latency lies.

This patch adds a call called trace_hardirqs_on_caller that passes in
the calling address to use for the trace. It also changes the code in
trace_hardirqs_on_thunk to pass in the caller.

So instead of getting a trace that looks like this:

preemption latency trace v1.1.5 on 2.6.20-rt8
--------------------------------------------------------------------
latency: 25 us, #4/4, CPU#3 | (M:rt VP:0, KP:0, SP:1 HP:1 #P:4)
-----------------
| task: softirq-timer/3-44 (uid:0 nice:0 policy:1 rt_prio:50)
-----------------

_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
cat-3186 3D... 0us+: trace_hardirqs_off_thunk ((0))
<...>-44 3D... 24us : schedule ((0))
<...>-44 3D... 24us : trace_hardirqs_on (schedule)



We now get a trace that looks like this:

preemption latency trace v1.1.5 on 2.6.20-rt8
--------------------------------------------------------------------
latency: 51 us, #4/4, CPU#0 | (M:rt VP:0, KP:0, SP:1 HP:1 #P:4)
-----------------
| task: automount-2692 (uid:0 nice:0 policy:0 rt_prio:0)
-----------------

_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
automoun-2692 0D... 2us+: apic_timer_interrupt ((0))
automoun-2692 0DN.. 21us+: retint_careful ((0))
automoun-2692 0DN.. 23us : trace_hardirqs_on_caller (retint_careful)


Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

Index: linux-2.6.21-rc6-rt0/arch/x86_64/lib/thunk.S
===================================================================
--- linux-2.6.21-rc6-rt0.orig/arch/x86_64/lib/thunk.S
+++ linux-2.6.21-rc6-rt0/arch/x86_64/lib/thunk.S
@@ -49,8 +49,22 @@
#endif

#ifdef CONFIG_TRACE_IRQFLAGS
- thunk trace_hardirqs_on_thunk,trace_hardirqs_on
- thunk trace_hardirqs_off_thunk,trace_hardirqs_off
+ /* put return address in rdi (arg1) */
+ .macro thunk_ra name,func
+ .globl \name
+\name:
+ CFI_STARTPROC
+ SAVE_ARGS
+ /* SAVE_ARGS pushs 9 elements */
+ /* the next element would be the rip */
+ movq 9*8(%rsp), %rdi
+ call \func
+ jmp restore
+ CFI_ENDPROC
+ .endm
+
+ thunk_ra trace_hardirqs_on_thunk,trace_hardirqs_on_caller
+ thunk_ra trace_hardirqs_off_thunk,trace_hardirqs_off_caller
#endif

/* SAVE_ARGS below is used only for the .cfi directives it contains. */
Index: linux-2.6.21-rc6-rt0/kernel/latency_trace.c
===================================================================
--- linux-2.6.21-rc6-rt0.orig/kernel/latency_trace.c
+++ linux-2.6.21-rc6-rt0/kernel/latency_trace.c
@@ -1986,6 +1986,28 @@ void notrace trace_hardirqs_off(void)

EXPORT_SYMBOL(trace_hardirqs_off);

+/* used by x86_64 thunk.S */
+void notrace trace_hardirqs_on_caller(unsigned long caller_addr)
+{
+ unsigned long flags;
+
+ local_save_flags(flags);
+
+ if (!irqs_off_preempt_count() && irqs_disabled_flags(flags))
+ __stop_critical_timing(caller_addr, 0 /* CALLER_ADDR1 */);
+}
+
+void notrace trace_hardirqs_off_caller(unsigned long caller_addr)
+{
+ unsigned long flags;
+
+ local_save_flags(flags);
+
+ if (!irqs_off_preempt_count() && irqs_disabled_flags(flags))
+ __start_critical_timing(caller_addr, 0 /* CALLER_ADDR1 */,
+ INTERRUPT_LATENCY);
+}
+
#endif /* !CONFIG_LOCKDEP */

#endif /* CONFIG_CRITICAL_IRQSOFF_TIMING */
Index: linux-2.6.21-rc6-rt0/kernel/lockdep.c
===================================================================
--- linux-2.6.21-rc6-rt0.orig/kernel/lockdep.c
+++ linux-2.6.21-rc6-rt0/kernel/lockdep.c
@@ -1858,7 +1858,7 @@ void early_boot_irqs_on(void)
/*
* Hardirqs will be enabled:
*/
-void notrace trace_hardirqs_on(void)
+void notrace trace_hardirqs_on_caller(unsigned long a0)
{
struct task_struct *curr = current;
unsigned long ip;
@@ -1900,16 +1900,20 @@ void notrace trace_hardirqs_on(void)
curr->hardirq_enable_event = ++curr->irq_events;
debug_atomic_inc(&hardirqs_on_events);
#ifdef CONFIG_CRITICAL_IRQSOFF_TIMING
- time_hardirqs_on(CALLER_ADDR0, 0 /* CALLER_ADDR1 */);
+ time_hardirqs_on(a0, 0 /* CALLER_ADDR1 */);
#endif
}

+void notrace trace_hardirqs_on(void) {
+ trace_hardirqs_on_caller(CALLER_ADDR0);
+}
+
EXPORT_SYMBOL(trace_hardirqs_on);

/*
* Hardirqs were disabled:
*/
-void notrace trace_hardirqs_off(void)
+void notrace trace_hardirqs_off_caller(unsigned long a0)
{
struct task_struct *curr = current;

@@ -1928,12 +1932,16 @@ void notrace trace_hardirqs_off(void)
curr->hardirq_disable_event = ++curr->irq_events;
debug_atomic_inc(&hardirqs_off_events);
#ifdef CONFIG_CRITICAL_IRQSOFF_TIMING
- time_hardirqs_off(CALLER_ADDR0, 0 /* CALLER_ADDR1 */);
+ time_hardirqs_off(a0, 0 /* CALLER_ADDR1 */);
#endif
} else
debug_atomic_inc(&redundant_hardirqs_off);
}

+void notrace trace_hardirqs_off(void) {
+ trace_hardirqs_off_caller(CALLER_ADDR0);
+}
+
EXPORT_SYMBOL(trace_hardirqs_off);

/*


-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

\
 
 \ /
  Last update: 2007-04-23 17:37    [W:0.031 / U:0.036 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site