Steven Rostedt [Mon, 12 May 2008 19:20:55 +0000 (21:20 +0200)]
ftrace: user raw_spin_lock in tracing
Lock debugging enabled cause huge performance problems for tracing. Having
the lock verification happening for every function that is called
because mcount calls spin_lock can cripple the system.
This patch converts the spin_locks used by ftrace into raw_spin_locks.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:55 +0000 (21:20 +0200)]
ftrace: irqsoff use raw_smp_processor_id
This patch changes the use of __get_cpu_var to explicitly calling
raw_smp_processor_id and using the per_cpu() macro. On some debug
configurations, the use of __get_cpu_var may cause ftrace to trigger
and this can cause problems with the irqsoff tracing.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: remove add-hoc code
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: fix dynamic ftrace selftest
With the adding of the configuration changes in the Makefile to prevent
tracing of functions in the ftrace code, all tracing of all the ftrace
code has been removed. Unfortunately, one of the selftests, relied on
a function to be traced. With the new change, the function was no longer
traced and the test failed.
This patch separates out the test function into its own file so that
we can add the "-pg" flag to the compilation of that function and the
adding of the mcount call to that function.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: add TRACE_STACK and TRACE_SPECIAL to selftest validation
The selftest validation code checks for valid entries in the trace buffer.
TRACE_STACK and TRACE_SPECIAL have been added to the code but not to
the validator. This patch adds the two to prevent them from flagging a
failure in the selftest.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: printk and trace irqsoff and wakeups
printk called from wakeup critical timings and irqs off can
cause deadlocks since printk might do a wakeup itself. If the
call to printk happens with the runqueue lock held, it can
deadlock.
This patch protects the printk from being called in trace irqs off
with a test to see if the runqueue for the current CPU is locked.
If it is locked, the printk is skipped.
The wakeup always holds the runqueue lock, so the printk is
simply removed.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: remove wakeup from function trace
trace_function is called by mcount and calling wake_up from that
can have unpredictable results. This patch removes the wakeup from
trace_function.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:54 +0000 (21:20 +0200)]
ftrace: make it more available in the Kconfig
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Peter Zijlstra [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: fix wakeup callback
Signed-off-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Peter Zijlstra [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: trace next state
Signed-off-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: sched special
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: sched tree fix
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: include cpu in stacktrace
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: iter ctrl fix
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:53 +0000 (21:20 +0200)]
ftrace: fix cmdline tracing
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: make use of tracing_cpumask
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: add tracing_cpumask
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: trace scheduler rbtree
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: fix __trace_special()
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: fix wakeups
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: trace curr/next tasks
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:52 +0000 (21:20 +0200)]
ftrace: sched tracer, trace full rbtree
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: make nostacktrace the default
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: sched tracer fix
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: add stack tracing
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: add wakeup events to sched tracer
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: remove notrace
now that we have a kbuild method for notrace, no need to pollute the
C code with the annotations.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:51 +0000 (21:20 +0200)]
ftrace: disable -pg for the tracer itself
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:50 +0000 (21:20 +0200)]
ftrace: do not profile lib/string.o
Most archs define the string and memory compare functions in assembly.
Some do not. But these functions may be used in some archs at early
boot up.
Since most archs define this code in assembly and they are not usually
traced, there's no need to trace them when they are not defined in
assembly.
This patch removes the -pg from the CFLAGS for lib/string.o.
This prevents the string functions use in either vdso or early bootup
from crashing the system.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:50 +0000 (21:20 +0200)]
ftrace: remove address of function names
PowerPC is very fragile when it comes to use of function names
and function addresses. ftrace needs to either use all function
addresses or function names (i.e. my_func as suppose to &my_func).
This patch chooses to use the names and not the addresses, and
makes ftrace consistent.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:50 +0000 (21:20 +0200)]
ftrace: cleanups
clean up recent code.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: add trace_function api for other tracers to use
A new check was added in the ftrace function that wont trace if the CPU
trace buffer is disabled. Unfortunately, other tracers used ftrace() to
write to the buffer after they disabled it. The new disable check makes
these calls into a nop.
This patch changes the __ftrace that is called without the check into a
new api for the other tracers to use, called "trace_function". The other
tracers use this interface instead when the trace CPU buffer is already
disabled.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Soeren Sandmann Pedersen [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: allow the event pipe to be polled
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: build fix
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: build fix
no need to backmerge, only affects ftrace-enabled kernels. (which is
not the default)
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: introduce the "hex" output method
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:49 +0000 (21:20 +0200)]
ftrace: build fix
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace: use cpu clock again
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace: enabled tracing by default
This patch is the correct way to have tracing enabled by default.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace: disable tracing on failure
Since ftrace touches practically every function. If we detect any
anomaly, we want to fully disable ftrace. This patch adds code
to try shutdown ftrace as much as possible without doing any more
harm is something is detected not quite correct.
This only kills ftrace, this patch does have checks for other parts of
the tracer (irqsoff, wakeup, etc.).
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace - fix dynamic ftrace memory leak
The ftrace dynamic function update allocates a record to store the
instruction pointers that are being modified. If the modified
instruction pointer fails to update, then the record is marked as
failed and nothing more is done.
Worse, if the modification fails, but the record ip function is still
called, it will allocate a new record and try again. In just a matter
of time, will this cause a serious memory leak and crash the system.
This patch plugs this memory leak. When a record fails, it is
included back into the pool of records to be used. Now a record may
fail over and over again, but the number of allocated records will
not increase.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace: pipe fixes
Some fixes for better output with the trace pipe.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:48 +0000 (21:20 +0200)]
ftrace, locking fix
should be an irq-safe lock ...
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:47 +0000 (21:20 +0200)]
ftrace: add trace_special()
for ad-hoc tracing.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:47 +0000 (21:20 +0200)]
ftrace: bin-output
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:47 +0000 (21:20 +0200)]
ftrace: add raw output
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: clean-up-pipe-iteration
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: remove-idx-sync
remove idx syncing - it's expensive on SMP.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: fast, scalable, synchronized timestamps
implement globally synchronized, fast and scalable time source for tracing.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: timestamp syncing, prepare
rename and uninline now() to ftrace_now().
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: cleanups
no code changed.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: fix locking
we can hold all cpu trace buffer locks at once - put each into a
separate lock class.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: user run time file reading
This patch creates a file called trace_pipe in the tracing
debug directory. This file is a consumer of the trace buffers.
This means that reads of this file consumes the entries from
the trace buffers so that they will not be read a second time,
as contrast to the static buffers latency_trace and trace.
Reading from the trace_pipe will remove the entries from trace
and latency_trace too.
The advantage that trace_pipe has is that it can record live
traces. It will block when there is nothing in the buffer,
and read the entries as they are entered. An EOF happens when
tracing is disabled (tracing_enabled = 0).
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:46 +0000 (21:20 +0200)]
ftrace: add a buffer for output
Later patches will need to print the same things as the seq output
does. But those outputs will not use the seq utility. This patch
adds a buffer to the iterator, that can be used by either the
seq utility or other output.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: change buffers to producer consumer
This patch changes the way the CPU trace buffers are handled.
Instead of always starting from the trace page head, the logic
is changed to a producer consumer logic. This allows for the
buffers to be drained while they are alive.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: reset selftests
The tests may leave stuff in the buffers. This resets the buffers
after each test is run. If a test fails, it does not reset the
buffer to avoid touching a buffer that is corrupted.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: disable all tracers on corrupted buffer
If the trace buffer is detected to be corrupted, then we
disable all tracers.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: fix time offset
fix time offset calculations and ordering, plus make code more consistent.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: startup tester on dynamic tracing.
This patch adds a startup self test on dynamic code modification
and filters. The test filters on a specific function, makes sure that
no other function is traced, exectutes the function, then makes sure that
the function is traced.
This patch also fixes a slight bug with the ftrace selftest, where
tracer_enabled was not being set.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: add README
make it easier for newbies to find their way around.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:45 +0000 (21:20 +0200)]
ftrace: cleanups
factor out code and clean it up.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: add self-tests
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: force recording
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: fix max latency
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: fix updates to max trace
This patch fixes some bugs to the updating of the max trace that
was caused by implementing the new buffering.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: don't use raw_local_irq_save/restore
Using raw_local_irq_save/restore confuses lockdep.
It's fine to use the normal ones.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: lockdep notrace annotations
Add notrace annotations to lockdep to keep ftrace from causing
recursive problems with lock tracing and debugging.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: irqs off smp_processor_id() fix
The irqsoff function tracer did a __get_cpu_var to determine
if it should trace the function or not. The problem is that
__get_cpu_var can preempt between getting the CPU and reading
the cpu variable. This means that the cpu variable that is
being read is not from the cpu being run on.
At worst, this can give a false positive, where we trace the
function when we should not. It will never give a false negative
since we only want to trace when interrupts are disabled
and we never preempt when they are.
This fix adds a check after reading the irq flags to only
trace if the interrupts are actually disabled. It also changes
the reading of the cpu variable to use a raw_smp_processor_id
since we now don't care if we preempt. We still catch that fact.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:44 +0000 (21:20 +0200)]
ftrace: debug smp_processor_id, use notrace preempt disable
The debug smp_processor_id caused a recursive fault in debugging
the irqsoff tracer. The tracer used a smp_processor_id in the
ftrace callback, and this function called preempt_disable which
also is traced. This caused a recursive fault (stack overload).
Since using smp_processor_id without debugging on does not cause
faults with the tracer (even when the tracer is wrong), the
debug version should not cause a system reboot.
This changes the debug_smp_processor_id to use the notrace versions
of preempt_disable and enable.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: fix kexec
disable the tracer while kexec pulls the rug from under the old
kernel.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: convert single large buffer into single pages.
Allocating large buffers for the tracer may fail easily.
This patch converts the buffer from a large ordered allocation
to single pages. It uses the struct page LRU field to link the
pages together.
Later patches may also implement dynamic increasing and decreasing
of the trace buffers.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: add filter select functions to trace
This patch adds two files to the debugfs system:
/debugfs/tracing/available_filter_functions
and
/debugfs/tracing/set_ftrace_filter
The available_filter_functions lists all functions that has been
recorded by the ftraced that has called the ftrace_record_ip function.
This is to allow users to see what functions have been converted
to nops and can be enabled for tracing.
To enable functions, simply echo the names (whitespace delimited)
into set_ftrace_filter. Simple wildcards are also allowed.
echo 'scheduler' > /debugfs/tracing/set_ftrace_filter
Will have only the scheduler be activated when tracing is enabled.
echo 'sched_*' > /debugfs/tracing/set_ftrace_filter
Will have only the functions starting with 'sched_' be activated.
echo '*lock' > /debugfs/tracing/set_ftrace_filter
Will have only functions ending with 'lock' be activated.
echo '*lock*' > /debugfs/tracing/set_ftrace_filter
Will have only functions with 'lock' in its name be activated.
Note: 'sched*lock' will not work. The only wildcards that are
allowed is an asterisk and the beginning and or end of the string
passed in.
Multiple names can be passed in with whitespace delimited:
echo 'scheduler *lock *acpi*' > /debugfs/tracing/set_ftrace_filter
is also the same as:
echo 'scheduler' > /debugfs/tracing/set_ftrace_filter
echo '*lock' >> /debugfs/tracing/set_ftrace_filter
echo '*acpi*' >> /debugfs/tracing/set_ftrace_filter
Appending does just that. It appends to the list.
To disable all filters simply echo an empty line in:
echo > /debugfs/tracing/set_ftrace_filter
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: use dynamic patching for updating mcount calls
This patch replaces the indirect call to the mcount function
pointer with a direct call that will be patched by the
dynamic ftrace routines.
On boot up, the mcount function calls the ftace_stub function.
When the dynamic ftrace code is initialized, the ftrace_stub
is replaced with a call to the ftrace_record_ip, which records
the instruction pointers of the locations that call it.
Later, the ftraced daemon will call kstop_machine and patch all
the locations to nops.
When a ftrace is enabled, the original calls to mcount will now
be set top call ftrace_caller, which will do a direct call
to the registered ftrace function. This direct call is also patched
when the function that should be called is updated.
All patching is performed by a kstop_machine routine to prevent any
type of race conditions that is associated with modifying code
on the fly.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: move memory management out of arch code
This patch moves the memory management of the ftrace
records out of the arch code and into the generic code
making the arch code simpler.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: use nops instead of jmp
This patch patches the call to mcount with nops instead
of a jmp over the mcount call.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:43 +0000 (21:20 +0200)]
ftrace: add ftrace_enabled sysctl to disable mcount function
This patch adds back the sysctl ftrace_enabled. This time it is
defaulted to on, if DYNAMIC_FTRACE is configured. When ftrace_enabled
is disabled, the ftrace function is set to the stub return.
If DYNAMIC_FTRACE is also configured, on ftrace_enabled = 0,
the registered ftrace functions will all be set to jmps, but no more
new calls to ftrace recording (used to find the ftrace calling sites)
will be called.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: dynamic enabling/disabling of function calls
This patch adds a feature to dynamically replace the ftrace code
with the jmps to allow a kernel with ftrace configured to run
as fast as it can without it configured.
The way this works, is on bootup (if ftrace is enabled), a ftrace
function is registered to record the instruction pointer of all
places that call the function.
Later, if there's still any code to patch, a kthread is awoken
(rate limited to at most once a second) that performs a stop_machine,
and replaces all the code that was called with a jmp over the call
to ftrace. It only replaces what was found the previous time. Typically
the system reaches equilibrium quickly after bootup and there's no code
patching needed at all.
e.g.
call ftrace /* 5 bytes */
is replaced with
jmp 3f /* jmp is 2 bytes and we jump 3 forward */
3:
When we want to enable ftrace for function tracing, the IP recording
is removed, and stop_machine is called again to replace all the locations
of that were recorded back to the call of ftrace. When it is disabled,
we replace the code back to the jmp.
Allocation is done by the kthread. If the ftrace recording function is
called, and we don't have any record slots available, then we simply
skip that call. Once a second a new page (if needed) is allocated for
recording new ftrace function calls. A large batch is allocated at
boot up to get most of the calls there.
Because we do this via stop_machine, we don't have to worry about another
CPU executing a ftrace call as we modify it. But we do need to worry
about NMI's so all functions that might be called via nmi must be
annotated with notrace_nmi. When this code is configured in, the NMI code
will not call notrace.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: trace preempt off critical timings
Add preempt off timings. A lot of kernel core code is taken from the RT patch
latency trace that was written by Ingo Molnar.
This adds "preemptoff" and "preemptirqsoff" to /debugfs/tracing/available_tracers
Now instead of just tracing irqs off, preemption off can be selected
to be recorded.
When this is selected, it shares the same files as irqs off timings.
One can either trace preemption off, irqs off, or one or the other off.
By echoing "preemptoff" into /debugfs/tracing/current_tracer, recording
of preempt off only is performed. "irqsoff" will only record the time
irqs are disabled, but "preemptirqsoff" will take the total time irqs
or preemption are disabled. Runtime switching of these options is now
supported by simpling echoing in the appropriate trace name into
/debugfs/tracing/current_tracer.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: trace irq disabled critical timings
This patch adds latency tracing for critical timings
(how long interrupts are disabled for).
"irqsoff" is added to /debugfs/tracing/available_tracers
Note:
tracing_max_latency
also holds the max latency for irqsoff (in usecs).
(default to large number so one must start latency tracing)
tracing_thresh
threshold (in usecs) to always print out if irqs off
is detected to be longer than stated here.
If irq_thresh is non-zero, then max_irq_latency
is ignored.
Here's an example of a trace with ftrace_enabled = 0
=======
preemption latency trace v1.1.5 on 2.6.24-rc7
Signed-off-by: Ingo Molnar <mingo@elte.hu>
--------------------------------------------------------------------
latency: 100 us, #3/3, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
-----------------
| task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
-----------------
=> started at: _spin_lock_irqsave+0x2a/0xb7
=> ended at: _spin_unlock_irqrestore+0x32/0x5f
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
swapper-0 1d.s3 0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
swapper-0 1d.s3 100us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
swapper-0 1d.s3 100us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
vim:ft=help
=======
And this is a trace with ftrace_enabled == 1
=======
preemption latency trace v1.1.5 on 2.6.24-rc7
--------------------------------------------------------------------
latency: 102 us, #12/12, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
-----------------
| task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
-----------------
=> started at: _spin_lock_irqsave+0x2a/0xb7
=> ended at: _spin_unlock_irqrestore+0x32/0x5f
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
swapper-0 1dNs3 0us+: _spin_lock_irqsave+0x2a/0xb7 (e1000_update_stats+0x47/0x64c [e1000])
swapper-0 1dNs3 46us : e1000_read_phy_reg+0x16/0x225 [e1000] (e1000_update_stats+0x5e2/0x64c [e1000])
swapper-0 1dNs3 46us : e1000_swfw_sync_acquire+0x10/0x99 [e1000] (e1000_read_phy_reg+0x49/0x225 [e1000])
swapper-0 1dNs3 46us : e1000_get_hw_eeprom_semaphore+0x12/0xa6 [e1000] (e1000_swfw_sync_acquire+0x36/0x99 [e1000])
swapper-0 1dNs3 47us : __const_udelay+0x9/0x47 (e1000_read_phy_reg+0x116/0x225 [e1000])
swapper-0 1dNs3 47us+: __delay+0x9/0x50 (__const_udelay+0x45/0x47)
swapper-0 1dNs3 97us : preempt_schedule+0xc/0x84 (__delay+0x4e/0x50)
swapper-0 1dNs3 98us : e1000_swfw_sync_release+0xc/0x55 [e1000] (e1000_read_phy_reg+0x211/0x225 [e1000])
swapper-0 1dNs3 99us+: e1000_put_hw_eeprom_semaphore+0x9/0x35 [e1000] (e1000_swfw_sync_release+0x50/0x55 [e1000])
swapper-0 1dNs3 101us : _spin_unlock_irqrestore+0xe/0x5f (e1000_update_stats+0x641/0x64c [e1000])
swapper-0 1dNs3 102us : _spin_unlock_irqrestore+0x32/0x5f (e1000_update_stats+0x641/0x64c [e1000])
swapper-0 1dNs3 102us : trace_hardirqs_on_caller+0x75/0x89 (_spin_unlock_irqrestore+0x32/0x5f)
vim:ft=help
=======
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: tracer for scheduler wakeup latency
This patch adds the tracer that tracks the wakeup latency of the
highest priority waking task.
"wakeup" is added to /debugfs/tracing/available_tracers
Also added to /debugfs/tracing
tracing_max_latency
holds the current max latency for the wakeup
wakeup_thresh
if set to other than zero, a log will be recorded
for every wakeup that takes longer than the number
entered in here (usecs for all counters)
(deletes previous trace)
Examples:
(with ftrace_enabled = 0)
============
preemption latency trace v1.1.5 on 2.6.24-rc8
Signed-off-by: Ingo Molnar <mingo@elte.hu>
--------------------------------------------------------------------
latency: 26 us, #2/2, CPU#1 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
-----------------
| task: migration/0-3 (uid:0 nice:-5 policy:1 rt_prio:99)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
quilt-8551 0d..3 0us+: wake_up_process+0x15/0x17 <
ffffffff80233e80> (sched_exec+0xc9/0x100 <
ffffffff80235343>)
quilt-8551 0d..4 26us : sched_switch_callback+0x73/0x81 <
ffffffff80338d2f> (schedule+0x483/0x6d5 <
ffffffff8048b3ee>)
vim:ft=help
============
(with ftrace_enabled = 1)
============
preemption latency trace v1.1.5 on 2.6.24-rc8
--------------------------------------------------------------------
latency: 36 us, #45/45, CPU#0 | (M:rt VP:0, KP:0, SP:0 HP:0 #P:2)
-----------------
| task: migration/1-5 (uid:0 nice:-5 policy:1 rt_prio:99)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
bash-10653 1d..3 0us : wake_up_process+0x15/0x17 <
ffffffff80233e80> (sched_exec+0xc9/0x100 <
ffffffff80235343>)
bash-10653 1d..3 1us : try_to_wake_up+0x271/0x2e7 <
ffffffff80233dcf> (sub_preempt_count+0xc/0x7a <
ffffffff8023309e>)
bash-10653 1d..2 2us : try_to_wake_up+0x296/0x2e7 <
ffffffff80233df4> (update_rq_clock+0x9/0x20 <
ffffffff802303f3>)
bash-10653 1d..2 2us : update_rq_clock+0x1e/0x20 <
ffffffff80230408> (__update_rq_clock+0xc/0x90 <
ffffffff80230366>)
bash-10653 1d..2 3us : __update_rq_clock+0x1b/0x90 <
ffffffff80230375> (sched_clock+0x9/0x29 <
ffffffff80214529>)
bash-10653 1d..2 4us : try_to_wake_up+0x2a6/0x2e7 <
ffffffff80233e04> (activate_task+0xc/0x3f <
ffffffff8022ffca>)
bash-10653 1d..2 4us : activate_task+0x2d/0x3f <
ffffffff8022ffeb> (enqueue_task+0xe/0x66 <
ffffffff8022ff66>)
bash-10653 1d..2 5us : enqueue_task+0x5b/0x66 <
ffffffff8022ffb3> (enqueue_task_rt+0x9/0x3c <
ffffffff80233351>)
bash-10653 1d..2 6us : try_to_wake_up+0x2ba/0x2e7 <
ffffffff80233e18> (check_preempt_wakeup+0x12/0x99 <
ffffffff80234f84>)
[...]
bash-10653 1d..5 33us : tracing_record_cmdline+0xcf/0xd4 <
ffffffff80338aad> (_spin_unlock+0x9/0x33 <
ffffffff8048d3ec>)
bash-10653 1d..5 34us : _spin_unlock+0x19/0x33 <
ffffffff8048d3fc> (sub_preempt_count+0xc/0x7a <
ffffffff8023309e>)
bash-10653 1d..4 35us : wakeup_sched_switch+0x65/0x2ff <
ffffffff80339f66> (_spin_lock_irqsave+0xc/0xa9 <
ffffffff8048d08b>)
bash-10653 1d..4 35us : _spin_lock_irqsave+0x19/0xa9 <
ffffffff8048d098> (add_preempt_count+0xe/0x77 <
ffffffff8023311a>)
bash-10653 1d..4 36us : sched_switch_callback+0x73/0x81 <
ffffffff80338d2f> (schedule+0x483/0x6d5 <
ffffffff8048b3ee>)
vim:ft=help
============
The [...] was added here to not waste your email box space.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: add tracing of context switches
This patch adds context switch tracing, of the format of:
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | pid:prio:state
\ / ||||| \ | /
swapper-0 1d..3 137us+: 0:140:R --> 2912:120
sshd-2912 1d..3 216us+: 2912:120:S --> 0:140
swapper-0 1d..3 261us+: 0:140:R --> 2912:120
bash-2920 0d..3 267us+: 2920:120:S --> 0:140
sshd-2912 1d..3 330us!: 2912:120:S --> 0:140
swapper-0 1d..3 2389us+: 0:140:R --> 2847:120
yum-upda-2847 1d..3 2411us!: 2847:120:S --> 0:140
swapper-0 0d..3 11089us+: 0:140:R --> 3139:120
gdm-bina-3139 0d..3 11113us!: 3139:120:S --> 0:140
swapper-0 1d..3 102328us+: 0:140:R --> 2847:120
yum-upda-2847 1d..3 102348us!: 2847:120:S --> 0:140
"sched_switch" is added to /debugfs/tracing/available_tracers
[ Eugene Teo <eugeneteo@kernel.sg: remove unused tracing_sched_switch_enabled ]
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Cc: Mathieu Desnoyers <mathieu.desnoyers@polymtl.ca>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: function tracer
This is a simple trace that uses the ftrace infrastructure. It is
designed to be fast and small, and easy to use. It is useful to
record things that happen over a very short period of time, and
not to analyze the system in general.
Updates:
available_tracers
"function" is added to this file.
current_tracer
To enable the function tracer:
echo function > /debugfs/tracing/current_tracer
To disable the tracer:
echo disable > /debugfs/tracing/current_tracer
The output of the function_trace file is as follows
"echo noverbose > /debugfs/tracing/iter_ctrl"
preemption latency trace v1.1.5 on 2.6.24-rc7-tst
Signed-off-by: Ingo Molnar <mingo@elte.hu>
--------------------------------------------------------------------
latency: 0 us, #419428/
4361791, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
-----------------
| task: -0 (uid:0 nice:0 policy:0 rt_prio:0)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
swapper-0 0d.h. 1595128us+: set_normalized_timespec+0x8/0x2d <
c043841d> (ktime_get_ts+0x4a/0x4e <
c04499d4>)
swapper-0 0d.h. 1595131us+: _spin_lock+0x8/0x18 <
c0630690> (hrtimer_interrupt+0x6e/0x1b0 <
c0449c56>)
Or with verbose turned on:
"echo verbose > /debugfs/tracing/iter_ctrl"
preemption latency trace v1.1.5 on 2.6.24-rc7-tst
--------------------------------------------------------------------
latency: 0 us, #419428/
4361791, CPU#1 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
-----------------
| task: -0 (uid:0 nice:0 policy:0 rt_prio:0)
-----------------
swapper 0 0 9
00000000 00000000 [
f3675f41] 1595.128ms (+0.003ms): set_normalized_timespec+0x8/0x2d <
c043841d> (ktime_get_ts+0x4a/0x4e <
c04499d4>)
swapper 0 0 9
00000000 00000001 [
f3675f45] 1595.131ms (+0.003ms): _spin_lock+0x8/0x18 <
c0630690> (hrtimer_interrupt+0x6e/0x1b0 <
c0449c56>)
swapper 0 0 9
00000000 00000002 [
f3675f48] 1595.135ms (+0.003ms): _spin_lock+0x8/0x18 <
c0630690> (hrtimer_interrupt+0x6e/0x1b0 <
c0449c56>)
The "trace" file is not affected by the verbose mode, but is by the symonly.
echo "nosymonly" > /debugfs/tracing/iter_ctrl
tracer:
[ 81.479967] CPU 0: bash:3154 register_ftrace_function+0x5f/0x66 <
ffffffff80337a4d> <-- _spin_unlock_irqrestore+0xe/0x5a <
ffffffff8048cc8f>
[ 81.479967] CPU 0: bash:3154 _spin_unlock_irqrestore+0x3e/0x5a <
ffffffff8048ccbf> <-- sub_preempt_count+0xc/0x7a <
ffffffff80233d7b>
[ 81.479968] CPU 0: bash:3154 sub_preempt_count+0x30/0x7a <
ffffffff80233d9f> <-- in_lock_functions+0x9/0x24 <
ffffffff8025a75d>
[ 81.479968] CPU 0: bash:3154 vfs_write+0x11d/0x155 <
ffffffff8029a043> <-- dnotify_parent+0x12/0x78 <
ffffffff802d54fb>
[ 81.479968] CPU 0: bash:3154 dnotify_parent+0x2d/0x78 <
ffffffff802d5516> <-- _spin_lock+0xe/0x70 <
ffffffff8048c910>
[ 81.479969] CPU 0: bash:3154 _spin_lock+0x1b/0x70 <
ffffffff8048c91d> <-- add_preempt_count+0xe/0x77 <
ffffffff80233df7>
[ 81.479969] CPU 0: bash:3154 add_preempt_count+0x3e/0x77 <
ffffffff80233e27> <-- in_lock_functions+0x9/0x24 <
ffffffff8025a75d>
echo "symonly" > /debugfs/tracing/iter_ctrl
tracer:
[ 81.479913] CPU 0: bash:3154 register_ftrace_function+0x5f/0x66 <-- _spin_unlock_irqrestore+0xe/0x5a
[ 81.479913] CPU 0: bash:3154 _spin_unlock_irqrestore+0x3e/0x5a <-- sub_preempt_count+0xc/0x7a
[ 81.479913] CPU 0: bash:3154 sub_preempt_count+0x30/0x7a <-- in_lock_functions+0x9/0x24
[ 81.479914] CPU 0: bash:3154 vfs_write+0x11d/0x155 <-- dnotify_parent+0x12/0x78
[ 81.479914] CPU 0: bash:3154 dnotify_parent+0x2d/0x78 <-- _spin_lock+0xe/0x70
[ 81.479914] CPU 0: bash:3154 _spin_lock+0x1b/0x70 <-- add_preempt_count+0xe/0x77
[ 81.479914] CPU 0: bash:3154 add_preempt_count+0x3e/0x77 <-- in_lock_functions+0x9/0x24
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: latency tracer infrastructure
This patch adds the latency tracer infrastructure. This patch
does not add anything that will select and turn it on, but will
be used by later patches.
If it were to be compiled, it would add the following files
to the debugfs:
The root tracing directory:
/debugfs/tracing/
This patch also adds the following files:
available_tracers
list of available tracers. Currently no tracers are
available. Looking into this file only shows
"none" which is used to unregister all tracers.
current_tracer
The trace that is currently active. Empty on start up.
To switch to a tracer simply echo one of the tracers that
are listed in available_tracers:
example: (used with later patches)
echo function > /debugfs/tracing/current_tracer
To disable the tracer:
echo disable > /debugfs/tracing/current_tracer
tracing_enabled
echoing "1" into this file starts the ftrace function tracing
(if sysctl kernel.ftrace_enabled=1)
echoing "0" turns it off.
latency_trace
This file is readonly and holds the result of the trace.
trace
This file outputs a easier to read version of the trace.
iter_ctrl
Controls the way the output of traces look.
So far there's two controls:
echoing in "symonly" will only show the kallsyms variables
without the addresses (if kallsyms was configured)
echoing in "verbose" will change the output to show
a lot more data, but not very easy to understand by
humans.
echoing in "nosymonly" turns off symonly.
echoing in "noverbose" turns off verbose.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Arnaldo Carvalho de Melo [Mon, 12 May 2008 19:20:42 +0000 (21:20 +0200)]
ftrace: add basic support for gcc profiler instrumentation
If CONFIG_FTRACE is selected and /proc/sys/kernel/ftrace_enabled is
set to a non-zero value the ftrace routine will be called everytime
we enter a kernel function that is not marked with the "notrace"
attribute.
The ftrace routine will then call a registered function if a function
happens to be registered.
[ This code has been highly hacked by Steven Rostedt and Ingo Molnar,
so don't blame Arnaldo for all of this ;-) ]
Update:
It is now possible to register more than one ftrace function.
If only one ftrace function is registered, that will be the
function that ftrace calls directly. If more than one function
is registered, then ftrace will call a function that will loop
through the functions to call.
Signed-off-by: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Arnaldo Carvalho de Melo [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
ftrace: annotate core code that should not be traced
Mark with "notrace" functions in core code that should not be
traced. The "notrace" attribute will prevent gcc from adding
a call to ftrace on the annotated funtions.
Signed-off-by: Arnaldo Carvalho de Melo <acme@ghostprotocols.net>
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
x86: add notrace annotations to vsyscall.
Add the notrace annotations to the vsyscall functions - there we are
not in kernel context yet, so the tracer function cannot (and must not)
be called.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
tracing: add notrace to linkage.h
notrace signals that a function should not be traced. Most of the
time this is used by tracers to annotate code that cannot be
traced - it's in a volatile state (such as in user vdso context
or NMI context) or it's in the tracer internals.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
ftrace: add preempt_enable/disable notrace macros
The tracer may need to call preempt_enable and disable functions
for time keeping and such. The trace gets ugly when we see these
functions show up for all traces. To make the output cleaner
this patch adds preempt_enable_notrace and preempt_disable_notrace
to be used by tracer (and debugging) functions.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Steven Rostedt [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
ftrace: make the task state char-string visible to all
The tracer wants to be able to convert the state number
into a user visible character. This patch pulls that conversion
string out the scheduler into the header. This way if it were to
ever change, other parts of the kernel will know.
Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Ingo Molnar [Mon, 12 May 2008 19:20:41 +0000 (21:20 +0200)]
sched: add latency tracer callbacks to the scheduler
add 3 lightweight callbacks to the tracer backend.
zero impact if tracing is turned off.
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Linus Torvalds [Thu, 22 May 2008 15:08:25 +0000 (08:08 -0700)]
Merge git://git./linux/kernel/git/sfrench/cifs-2.6
* git://git.kernel.org/pub/scm/linux/kernel/git/sfrench/cifs-2.6:
[CIFS] Fix reversed memset arguments
Adds username in the upcall key for unattended mounts with keytab
[CIFS] Remove redundant NULL check
Dave Jones [Thu, 22 May 2008 14:20:21 +0000 (14:20 +0000)]
[CIFS] Fix reversed memset arguments
Signed-off-by: Dave Jones <davej@redhat.com>
Signed-off-by: Steve French <sfrench@us.ibm.com>
Igor Mammedov [Wed, 2 Apr 2008 13:33:47 +0000 (17:33 +0400)]
Adds username in the upcall key for unattended mounts with keytab
Signed-off-by: Igor Mammedov <niallain@gmail.com>
Signed-off-by: Steve French <sfrench@us.ibm.com>
Linus Torvalds [Thu, 22 May 2008 05:14:39 +0000 (22:14 -0700)]
Merge git://git./linux/kernel/git/davem/net-2.6
* git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6:
net: The world is not perfect patch.
tcp: Make prior_ssthresh a u32
xfrm_user: Remove zero length key checks.
net/ipv4/arp.c: Use common hex_asc helpers
cassini: Only use chip checksum for ipv4 packets.
tcp: TCP connection times out if ICMP frag needed is delayed
netfilter: Move linux/types.h inclusions outside of #ifdef __KERNEL__
af_key: Fix selector family initialization.
libertas: Fix ethtool statistics
mac80211: fix NULL pointer dereference in ieee80211_compatible_rates
mac80211: don't claim iwspy support
orinoco_cs: add ID for SpeedStream wireless adapters
hostap_cs: add ID for Conceptronic CON11CPro
rtl8187: resource leak in error case
ath5k: Fix loop variable initializations
Linus Torvalds [Thu, 22 May 2008 05:00:12 +0000 (22:00 -0700)]
Merge git://git./linux/kernel/git/davem/sparc-2.6
* git://git.kernel.org/pub/scm/linux/kernel/git/davem/sparc-2.6:
sparc64: Prevent stack backtrace false positives on trap frames.
sparc64: Fix stack tracing through trap frames.
sparc64: Fix kernel thread stack termination.
sunhv: Fix locking in non-paged I/O case.
David S. Miller [Thu, 22 May 2008 04:50:01 +0000 (21:50 -0700)]
sparc64: Prevent stack backtrace false positives on trap frames.
When we fully commit to returning back to kernel mode from
a trap, zero out the regs->magic value to prevent false
positives during stack backtraces.
Signed-off-by: David S. Miller <davem@davemloft.net>
Steve French [Thu, 22 May 2008 02:02:03 +0000 (02:02 +0000)]
[CIFS] Remove redundant NULL check
Noticed by Coverity checker.
Signed-off-by: Steve French <sfrench@us.ibm.com>
David S. Miller [Thu, 22 May 2008 01:15:53 +0000 (18:15 -0700)]
sparc64: Fix stack tracing through trap frames.
The offset to the pt_regs area was wrong, so we weren't
looking at the right location for the magic cookie.
A trap frame is composed of a "struct sparc_stackf" then
a "struct pt_regs", the code was using "struct reg_window"
instead of "struct sparc_stackf".
Signed-off-by: David S. Miller <davem@davemloft.net>
David S. Miller [Thu, 22 May 2008 01:14:28 +0000 (18:14 -0700)]
sparc64: Fix kernel thread stack termination.
Because of the silly way I set up the initial stack for
new kernel threads, there is a loop at the top of the
stack.
To fix this, properly add another stack frame that is copied
from the parent and terminate it in the child by setting
the frame pointer in that frame to zero.
Signed-off-by: David S. Miller <davem@davemloft.net>
Rami Rosen [Thu, 22 May 2008 00:47:54 +0000 (17:47 -0700)]
net: The world is not perfect patch.
Unless there will be any objection here, I suggest consider the
following patch which simply removes the code for the
-DI_WISH_WORLD_WERE_PERFECT in the three methods which use it.
The compilation errors we get when using -DI_WISH_WORLD_WERE_PERFECT
show that this code was not built and not used for really a long time.
Signed-off-by: Rami Rosen <ramirose@gmail.com>
Signed-off-by: David S. Miller <davem@davemloft.net>
This page took 0.04735 seconds and 5 git commands to generate.