tracing/ftrace: use preempt_enable_no_resched_notrace in ring_buffer_time_stamp()
Subsystems (2)
PATCH 1/1 tracing/ftrace: use preempt_enable_no_resched_notrace in ring_buffer_time_stamp()
Impact: prevent a trace recursion
After some tests with function graph tracer under x86-32, I saw some recursions caused by ring_buffer_time_stamp() that calls preempt_enable_no_notrace() which calls preempt_schedule() which is traced itself.
This patch re-enables preemption without rescheduling.
--- kernel/trace/ring_buffer.c | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)
kernel/trace/ring_buffer.c +1 -1
@@ -109,7 +109,7 @@ u64 ring_buffer_time_stamp(int cpu)preempt_disable_notrace ();/* shift to debug/test normalization and TIME_EXTENTS */ time =sched_clock () <<DEBUG_SHIFT ; -preempt_enable_notrace (); +preempt_enable_no_resched_notrace ();return time; }
Signature · 1 line
1.6.0.4
Ingo Molnar
AppliedQuoted 6 lines · Frederic Weisbecker
Impact: prevent a trace recursion
After some tests with function graph tracer under x86-32, I saw some recursions caused by
ring_buffer_time_stamp()that callspreempt_enable_no_notrace()which callspreempt_schedule()which is traced itself.
Quoted 7 lines
This patch re-enables preemption without rescheduling.
Cc Steven Rostedt <[email protected]>Signed-off-by Frederic Weisbecker <[email protected]>--- kernel/trace/ring_buffer.c | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)
applied to tip/tracing/ftrace, thanks Frederic!
Does this explain+fix the weird crashes/reboots you were seeing?
Ingo
2008/12/16 Ingo Molnar <[email protected]>:
Quoted 17 lines · Frederic Weisbecker
Quoted 7 lines
Impact: prevent a trace recursion
After some tests with function graph tracer under x86-32, I saw some recursions caused by
ring_buffer_time_stamp()that callspreempt_enable_no_notrace()which callspreempt_schedule()which is traced itself.Quoted 7 lines
This patch re-enables preemption without rescheduling.
Cc Steven Rostedt <[email protected]>Signed-off-by Frederic Weisbecker <[email protected]>--- kernel/trace/ring_buffer.c | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)
Quoted 6 lines
applied to tip/tracing/ftrace, thanks Frederic!
Does this explain+fix the weird crashes/reboots you were seeing?
Ingo
No, actually the functions tracers are protected against recursion, but rescheduling attempts
during all trace insertions (and moreover a call to prepare_ftrace_return with cancelled insertion)
is a useless payload.
The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through /sys/device/system/cpu No tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).
One other thing: I've seen these pointless calls to preempt_schedule while testing the function graph tracer on
VirtualBox. Since it provides virtual serial lines, it was more easy to debug than usual (I haven't any serial line
on my box).
The function graph tracer hangs on VirtualBox with a x86-32 -tip. It seems that the tracing is too slow and so hrtimer_interrupt() does an eternal loop, assuming that a new time update has to be done (because too much time elapsed during th tracing) after each iteration.
I'm not sure what to do...disabling tracing for hrtimers or....
Steven Rostedt
maintainerQuoted 5 lines · Fr?d?ric Weisbecker
The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).
Do you have STACK_TRACER enabled?
-- Steve
2008/12/16 Steven Rostedt <[email protected]>:
Quoted 13 lines · Fr?d?ric Weisbecker
Quoted 5 lines
The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).Do you have
STACK_TRACERenabled?-- Steve
Yes. Do you think the origin comes from the fact that ftrace is running with stack tracer?
Quoted 36 lines · Frédéric Weisbecker
2008/12/16 Ingo Molnar <[email protected]>:
Quoted 17 lines · Frederic Weisbecker
Quoted 7 lines
Impact: prevent a trace recursion
After some tests with function graph tracer under x86-32, I saw some recursions caused by
ring_buffer_time_stamp()that callspreempt_enable_no_notrace()which callspreempt_schedule()which is traced itself.Quoted 7 lines
This patch re-enables preemption without rescheduling.
Cc Steven Rostedt <[email protected]>Signed-off-by Frederic Weisbecker <[email protected]>--- kernel/trace/ring_buffer.c | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)Quoted 6 lines
applied to tip/tracing/ftrace, thanks Frederic!
Does this explain+fix the weird crashes/reboots you were seeing?
Ingo
No, actually the functions tracers are protected against recursion, but rescheduling attempts
during all trace insertions (and moreover a call toprepare_ftrace_returnwith cancelled insertion)
is a useless payload.The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).
Quoted 9 lines
One other thing: I've seen these pointless calls to
preempt_schedulewhile testing the function graph tracer on VirtualBox. Since it provides virtual serial lines, it was more easy to debug than usual (I haven't any serial line on my box). The function graph tracer hangs on VirtualBox with a x86-32 -tip. It seems that the tracing is too slow and sohrtimer_interrupt()does an eternal loop, assuming that a new time update has to be done (because too much time elapsed during th tracing) after each iteration. I'm not sure what to do...disabling tracing for hrtimers or....
reduce HZ?
Ingo
2008/12/16 Steven Rostedt <[email protected]>:
Quoted 13 lines · Fr?d?ric Weisbecker
Quoted 5 lines
The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).Do you have
STACK_TRACERenabled?-- Steve
You were right. I've just built a kernel without STACK_TRACER and the problem disappears...
Quoted 10 lines · Frédéric Weisbecker
2008/12/16 Steven Rostedt <[email protected]>:
Quoted 9 lines · Fr?d?ric Weisbecker
Quoted 5 lines
The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).
Quoted 7 lines
Quoted 4 lines
Do you have
STACK_TRACERenabled?-- Steve
You were right. I've just built a kernel without
STACK_TRACERand the problem disappears...
i noticed high stack-tracer overhead too. Which is understandable i guess:
the stack tracer keeps the mcount callbacks running all the time and can save the stack backtrace of the highest-stack-usage point in time that the kernel ever has hit in the past. That is a pretty powerful debug capability, with appropriate costs.
Ingo
2008/12/16 Ingo Molnar <[email protected]>:
Quoted 49 lines · Frédéric Weisbecker
Quoted 37 lines
2008/12/16 Ingo Molnar <[email protected]>:
Quoted 17 lines · Frederic Weisbecker
Quoted 7 lines
Impact: prevent a trace recursion
After some tests with function graph tracer under x86-32, I saw some recursions caused by
ring_buffer_time_stamp()that callspreempt_enable_no_notrace()which callspreempt_schedule()which is traced itself.Quoted 7 lines
This patch re-enables preemption without rescheduling.
Cc Steven Rostedt <[email protected]>Signed-off-by Frederic Weisbecker <[email protected]>--- kernel/trace/ring_buffer.c | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)Quoted 6 lines
applied to tip/tracing/ftrace, thanks Frederic!
Does this explain+fix the weird crashes/reboots you were seeing?
Ingo
No, actually the functions tracers are protected against recursion, but rescheduling attempts
during all trace insertions (and moreover a call toprepare_ftrace_returnwith cancelled insertion)
is a useless payload.The hard reboots I've seen are related to x86-64 while disabling/reenabling a CPU through
/sys/device/system/cpuNo tracer was enabled at these times (the problem still remains with latest updates on -tip for half an hour).Quoted 9 lines
One other thing: I've seen these pointless calls to
preempt_schedulewhile testing the function graph tracer on VirtualBox. Since it provides virtual serial lines, it was more easy to debug than usual (I haven't any serial line on my box). The function graph tracer hangs on VirtualBox with a x86-32 -tip. It seems that the tracing is too slow and sohrtimer_interrupt()does an eternal loop, assuming that a new time update has to be done (because too much time elapsed during th tracing) after each iteration. I'm not sure what to do...disabling tracing for hrtimers or....
Quoted 4 lines
reduce HZ?
Ingo
I just switched from 250 to 100 HZ. And it remains the same. But I commented out the early_printk which could consume some time too.
Perhaps there is one other thing that makes it hanging. I will investigate more...
Did someone make some tests with function graph tracer on 32 bits these last days?
Steven Rostedt
maintainerQuoted 6 lines · Ingo Molnar
i noticed high stack-tracer overhead too. Which is understandable i guess:
the stack tracer keeps the mcount callbacks running all the time and can save the stack backtrace of the highest-stack-usage point in time that the kernel ever has hit in the past. That is a pretty powerful debug capability, with appropriate costs.
I was thinking of having a way to start and stop the stack tracer. This way we can actually have it on by default with anything that has dynamic ftace. To enable it durning boot would require a kernel command line option. Other than that, I would have a sysctl enable it.
-- Steve