tracing/function-graph-tracer: prevent from hrtimer interrupt eternal loop
PATCH 1/1 tracing/function-graph-tracer: prevent from hrtimer interrupt eternal loop
Impact: fix a system hang on slow systems
While testing the function graph tracer on VirtualBox, I had a system hang immediately after enabling the tracer.
If hrtimer is enabled on kernel, a slow system can spend too much time during tracing the hrtimer_interrupt which will do eternal loops, assuming it always have to retry its process because too much time elapsed during its time update.
Now we provide a feature which lurks at the number of retries on hrtimer_interrupt. After 10 retries, the function graph tracer will finally stop its tracing.
--- arch/x86/kernel/ftrace.c | 2 ++ include/linux/ftrace.h | 31 +++++++++++++++++++++++++++++++ kernel/hrtimer.c | 5 +++++ 3 files changed, 38 insertions(+), 0 deletions(-)
arch/x86/kernel/ftrace.c +2 -0
@@ -389,6 +389,8 @@ void ftrace_nmi_exit(void)#endif /* !CONFIG_DYNAMIC_FTRACE */ +DEFINE_PER_CPU (int, ftrace_graph_hrtimer_loop) =LOCAL_INIT (0 ); +/* Add a function return address to the trace stack on thread info.*/ static int push_return_trace (unsigned long ret,unsigned long long time,unsigned long func,int *depth)
include/linux/ftrace.h +31 -0
@@ -408,6 +408,34 @@ extern void unregister_ftrace_graph(void);extern void ftrace_graph_init_task (struct task_struct *t);extern void ftrace_graph_exit_task (struct task_struct *t); +/* +* Those two functions prevent from eternal loops on hrtimer_interrupt +* because the function graph tracer can cause two much time processing +* on slow systems, and the hrtimer_interrupt can relaunch its processing +* if too much time elapsed during its previous time update. +* +* Note that we don't need an atomic counter for loops here because +* interrupts are disabled in hrtimer_interrupt. +*/ + +extern DEFINE_PER_CPU(int, ftrace_graph_hrtimer_loop); + +static inline void ftrace_graph_hrtimer_enter (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop) =0 ; +} + +static inline void ftrace_graph_hrtimer_retry (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop)++; + +if (__get_cpu_var (ftrace_graph_hrtimer_loop) ==10 ) { +ftrace_graph_stop (); +printk (KERN_WARNING "function-graph-tracer: hrtimer_interrupt " +"exceeded 10 loops. Stopping tracing\n" ); + } +} +static inline int task_curr_ret_stack (struct task_struct *t) {return t->curr_ret_stack;
@@ -437,6 +465,9 @@ static inline int task_curr_ret_stack(struct task_struct *tsk)static inline void pause_graph_tracing (void ) { }static inline void unpause_graph_tracing (void ) { } + +static inline void ftrace_graph_hrtimer_enter (void ) { }; +static inline void ftrace_graph_hrtimer_retry (void ) { };#endif #ifdef CONFIG_TRACING
kernel/hrtimer.c +5 -0
@@ -44,6 +44,7 @@#include <linux/seq_file.h> #include <linux/err.h> #include <linux/debugobjects.h> +#include <linux/ftrace.h> #include <asm/uaccess.h>
@@ -1186,7 +1187,11 @@ void hrtimer_interrupt(struct clock_event_device *dev) cpu_base->nr_events++; dev->next_event.tv64 =KTIME_MAX ; +ftrace_graph_hrtimer_enter (); retry: +/* Prevent from eternal loop on slow systems while tracing */ +ftrace_graph_hrtimer_retry (); + now =ktime_get (); expires_next.tv64 =KTIME_MAX ;
Signature · 1 line
1.6.0.4
Quoted 26 lines · On Thu, 18 Dec 2008 00:52:47 +0100 Frederic Weisbecker <[email protected]>…
Impact: fix a system hang on slow systems
While testing the function graph tracer on VirtualBox, I had a system hang immediately after enabling the tracer.
If hrtimer is enabled on kernel, a slow system can spend too much time during tracing thehrtimer_interruptwhich will do eternal loops, assuming it always have to retry its process because too much time elapsed during its time update.
Now we provide a feature which lurks at the number of retries onhrtimer_interrupt. After 10 retries, the function graph tracer will finally stop its tracing.Signed-off-by Frederic Weisbecker <[email protected]>Cc Thomas Gleixner <[email protected]>Cc Steven Rostedt <[email protected]>--- arch/x86/kernel/ftrace.c | 2 ++ include/linux/ftrace.h | 31 +++++++++++++++++++++++++++++++ kernel/hrtimer.c | 5 +++++ 3 files changed, 38 insertions(+), 0 deletions(-)arch/x86/kernel/ftrace.c +0
-0
arch/x86/kernel/ftrace.c void ftrace_nmi_exit(void) · line 392
Quoted 4 lines
arch/x86/kernel/ftrace.c +1
-0@@ -389,6 +389,8 @@ void ftrace_nmi_exit(void)#endif /* !CONFIG_DYNAMIC_FTRACE */ +DEFINE_PER_CPU (int, ftrace_graph_hrtimer_loop) =LOCAL_INIT (0 );
Strange. This has type `int', but we initialise it with a local_t?
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 412
Quoted 13 lines
arch/x86/kernel/ftrace.c +0
-0/* Add a function return address to the trace stack on thread info.*/ static int push_return_trace (unsigned long ret,unsigned long long time,unsigned long func,int *depth)include/linux/ftrace.h +2
-0@@ -408,6 +408,34 @@ extern void unregister_ftrace_graph(void);extern void ftrace_graph_init_task (struct task_struct *t);extern void ftrace_graph_exit_task (struct task_struct *t); +/* +* Those two functions prevent from eternal loops on hrtimer_interrupt
"These two functions prevent infinite ..."
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 413
Quoted 1 line
include/linux/ftrace.h +1
-0+* because the function graph tracer can cause two much time processing
"can consume too much"
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 421
Quoted 8 lines
include/linux/ftrace.h +8
-0+* on slow systems, and the hrtimer_interrupt can relaunch its processing +* if too much time elapsed during its previous time update. +* +* Note that we don't need an atomic counter for loops here because +* interrupts are disabled in hrtimer_interrupt. +*/ + +extern DEFINE_PER_CPU(int, ftrace_graph_hrtimer_loop);
We have DECLARE_PER_CPU() for this.
Quoted 5 lines
include/linux/ftrace.h +5
-0+static inline void ftrace_graph_hrtimer_enter (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop) =0 ; +} +
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 437
Quoted 10 lines
include/linux/ftrace.h +10
-0+static inline void ftrace_graph_hrtimer_retry (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop)++; + +if (__get_cpu_var (ftrace_graph_hrtimer_loop) ==10 ) { +ftrace_graph_stop (); +printk (KERN_WARNING "function-graph-tracer: hrtimer_interrupt " +"exceeded 10 loops. Stopping tracing\n" ); + } +}
I suspect this code would end up considerably neater (and less likely to break the build) if these functons were not inlined. For a start, ftrace_graph_hrtimer_loop would not need global scope.
include/linux/ftrace.h static inline int task_curr_ret_stack(struct task_struct *tsk) · line 470
Quoted 10 lines
include/linux/ftrace.h +3
-0static inline int task_curr_ret_stack (struct task_struct *t) {return t->curr_ret_stack;@@ -437,6 +465,9 @@ static inline int task_curr_ret_stack(struct task_struct *tsk)static inline void pause_graph_tracing (void ) { }static inline void unpause_graph_tracing (void ) { } + +static inline void ftrace_graph_hrtimer_enter (void ) { }; +static inline void ftrace_graph_hrtimer_retry (void ) { };
Unneeded semicolons.
Please consider doing
static inline void ftrace_graph_hrtimer_enter(void) {
}
Quoted 29 lines
include/linux/ftrace.h +0
-0#endif #ifdef CONFIG_TRACING kernel/hrtimer.c +5
-0@@ -44,6 +44,7 @@#include <linux/seq_file.h> #include <linux/err.h> #include <linux/debugobjects.h> +#include <linux/ftrace.h> #include <asm/uaccess.h> @@ -1186,7 +1187,11 @@ void hrtimer_interrupt(struct clock_event_device *dev) cpu_base->nr_events++; dev->next_event.tv64 =KTIME_MAX ; +ftrace_graph_hrtimer_enter (); retry: +/* Prevent from eternal loop on slow systems while tracing */ +ftrace_graph_hrtimer_retry (); + now =ktime_get (); expires_next.tv64 =KTIME_MAX ;Signature · 1 line
1.6.0.4
2008/12/18 Andrew Morton <[email protected]>:
Quoted 30 lines
Quoted 27 lines · On Thu, 18 Dec 2008 00:52:47 +0100 Frederic Weisbecker <[email protected]>…
Impact: fix a system hang on slow systems
While testing the function graph tracer on VirtualBox, I had a system hang immediately after enabling the tracer.
If hrtimer is enabled on kernel, a slow system can spend too much time during tracing thehrtimer_interruptwhich will do eternal loops, assuming it always have to retry its process because too much time elapsed during its time update.
Now we provide a feature which lurks at the number of retries onhrtimer_interrupt. After 10 retries, the function graph tracer will finally stop its tracing.Signed-off-by Frederic Weisbecker <[email protected]>Cc Thomas Gleixner <[email protected]>Cc Steven Rostedt <[email protected]>--- arch/x86/kernel/ftrace.c | 2 ++ include/linux/ftrace.h | 31 +++++++++++++++++++++++++++++++ kernel/hrtimer.c | 5 +++++ 3 files changed, 38 insertions(+), 0 deletions(-)arch/x86/kernel/ftrace.c +0
-0@@ -389,6 +389,8 @@ void ftrace_nmi_exit(void)
Quoted 5 lines
arch/x86/kernel/ftrace.c void ftrace_nmi_exit(void) · line 392
Quoted 3 lines
arch/x86/kernel/ftrace.c +1
-0#endif /* !CONFIG_DYNAMIC_FTRACE */ +DEFINE_PER_CPU (int, ftrace_graph_hrtimer_loop) =LOCAL_INIT (0 );Strange. This has type `int', but we initialise it with a
local_t?
Oops...
Quoted 11 lines
Quoted 11 lines
arch/x86/kernel/ftrace.c +0
-0/* Add a function return address to the trace stack on thread info.*/ static int push_return_trace (unsigned long ret,unsigned long long time,unsigned long func,int *depth)include/linux/ftrace.h +0
-0@@ -408,6 +408,34 @@ extern void unregister_ftrace_graph(void);extern void ftrace_graph_init_task (struct task_struct *t);extern void ftrace_graph_exit_task (struct task_struct *t);
Quoted 9 lines
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 412
Quoted 2 lines
include/linux/ftrace.h +2
-0+/* +* Those two functions prevent from eternal loops on hrtimer_interrupt "These two functions prevent infinite ..."
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 413
Quoted 1 line
include/linux/ftrace.h +1
-0+* because the function graph tracer can cause two much time processing "can consume too much"
Yeah, I had bad marks at school in english :-)
Quoted 10 lines
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 421
Quoted 8 lines
include/linux/ftrace.h +8
-0+* on slow systems, and the hrtimer_interrupt can relaunch its processing +* if too much time elapsed during its previous time update. +* +* Note that we don't need an atomic counter for loops here because +* interrupts are disabled in hrtimer_interrupt. +*/ + +extern DEFINE_PER_CPU(int, ftrace_graph_hrtimer_loop);We have
DECLARE_PER_CPU()for this.
Ok.
Quoted 11 lines
Quoted 11 lines
include/linux/ftrace.h +11
-0+static inline void ftrace_graph_hrtimer_enter (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop) =0 ; +} + +static inline void ftrace_graph_hrtimer_retry (void ) +{ +__get_cpu_var (ftrace_graph_hrtimer_loop)++; + +if (__get_cpu_var (ftrace_graph_hrtimer_loop) ==10 ) { +ftrace_graph_stop ();
Quoted 8 lines
include/linux/ftrace.h extern void unregister_ftrace_graph(void); · line 437
Quoted 4 lines
include/linux/ftrace.h +4
-0+printk (KERN_WARNING "function-graph-tracer: hrtimer_interrupt " +"exceeded 10 loops. Stopping tracing\n" ); + } +}I suspect this code would end up considerably neater (and less likely to break the build) if these functons were not inlined. For a start,
ftrace_graph_hrtimer_loopwould not need global scope.
I agree. I wanted to make them inlined to minimize the performance issues on hrtimer_interrupt. But that will only have an impact if this tracer is configured.
I will move these functions and the per_cpu counters in kernel/trace/ftrace.c and makeftrace_graph_hrtimer_loop as static.
Quoted 13 lines
include/linux/ftrace.h static inline int task_curr_ret_stack(struct task_struct *tsk) · line 470
Quoted 10 lines
include/linux/ftrace.h +3
-0static inline int task_curr_ret_stack (struct task_struct *t) {return t->curr_ret_stack;@@ -437,6 +465,9 @@ static inline int task_curr_ret_stack(struct task_struct *tsk)static inline void pause_graph_tracing (void ) { }static inline void unpause_graph_tracing (void ) { } + +static inline void ftrace_graph_hrtimer_enter (void ) { }; +static inline void ftrace_graph_hrtimer_retry (void ) { };Unneeded semicolons.
Quoted 5 lines
Please consider doing
static inline void
ftrace_graph_hrtimer_enter(void){
}
Ok.
Quoted 26 lines
Quoted 26 lines
include/linux/ftrace.h +0
-0#endif #ifdef CONFIG_TRACING kernel/hrtimer.c +5
-0@@ -44,6 +44,7 @@#include <linux/seq_file.h> #include <linux/err.h> #include <linux/debugobjects.h> +#include <linux/ftrace.h> #include <asm/uaccess.h> @@ -1186,7 +1187,11 @@ void hrtimer_interrupt(struct clock_event_device *dev) cpu_base->nr_events++; dev->next_event.tv64 =KTIME_MAX ; +ftrace_graph_hrtimer_enter (); retry: +/* Prevent from eternal loop on slow systems while tracing */ +ftrace_graph_hrtimer_retry (); + now =ktime_get ();
Quoted 4 lines
Quoted 3 lines
kernel/hrtimer.c +0
-1expires_next.tv64 =KTIME_MAX ; --1.6.0.4
Thanks Andrew!
I will send a V2 to apply your comments.