Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit b0f4b285 authored by Linus Torvalds's avatar Linus Torvalds
Browse files

Merge branch 'tracing-core-for-linus' of...

Merge branch 'tracing-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip

* 'tracing-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip: (241 commits)
  sched, trace: update trace_sched_wakeup()
  tracing/ftrace: don't trace on early stage of a secondary cpu boot, v3
  Revert "x86: disable X86_PTRACE_BTS"
  ring-buffer: prevent false positive warning
  ring-buffer: fix dangling commit race
  ftrace: enable format arguments checking
  x86, bts: memory accounting
  x86, bts: add fork and exit handling
  ftrace: introduce tracing_reset_online_cpus() helper
  tracing: fix warnings in kernel/trace/trace_sched_switch.c
  tracing: fix warning in kernel/trace/trace.c
  tracing/ring-buffer: remove unused ring_buffer size
  trace: fix task state printout
  ftrace: add not to regex on filtering functions
  trace: better use of stack_trace_enabled for boot up code
  trace: add a way to enable or disable the stack tracer
  x86: entry_64 - introduce FTRACE_ frame macro v2
  tracing/ftrace: add the printk-msg-only option
  tracing/ftrace: use preempt_enable_no_resched_notrace in ring_buffer_time_stamp()
  x86, bts: correctly report invalid bts records
  ...

Fixed up trivial conflict in scripts/recordmcount.pl due to SH bits
being already partly merged by the SH merge.
parents be9c5ae4 5250d329
Loading
Loading
Loading
Loading
+117 −32
Original line number Diff line number Diff line
@@ -82,7 +82,7 @@ of ftrace. Here is a list of some of the key files:
		tracer is not adding more data, they will display
		the same information every time they are read.

  iter_ctrl: This file lets the user control the amount of data
  trace_options: This file lets the user control the amount of data
		that is displayed in one of the above output
		files.

@@ -94,7 +94,7 @@ of ftrace. Here is a list of some of the key files:
		only be recorded if the latency is greater than
		the value in this file. (in microseconds)

  trace_entries: This sets or displays the number of bytes each CPU
  buffer_size_kb: This sets or displays the number of kilobytes each CPU
		buffer can hold. The tracer buffers are the same size
		for each CPU. The displayed number is the size of the
		CPU buffer and not total size of all buffers. The
@@ -127,6 +127,8 @@ of ftrace. Here is a list of some of the key files:
		be traced. If a function exists in both set_ftrace_filter
		and set_ftrace_notrace,	the function will _not_ be traced.

  set_ftrace_pid: Have the function tracer only trace a single thread.

  available_filter_functions: This lists the functions that ftrace
		has processed and can trace. These are the function
		names that you can pass to "set_ftrace_filter" or
@@ -316,23 +318,23 @@ The above is mostly meaningful for kernel developers.
  The rest is the same as the 'trace' file.


iter_ctrl
---------
trace_options
-------------

The iter_ctrl file is used to control what gets printed in the trace
The trace_options file is used to control what gets printed in the trace
output. To see what is available, simply cat the file:

  cat /debug/tracing/iter_ctrl
  cat /debug/tracing/trace_options
  print-parent nosym-offset nosym-addr noverbose noraw nohex nobin \
 noblock nostacktrace nosched-tree
 noblock nostacktrace nosched-tree nouserstacktrace nosym-userobj

To disable one of the options, echo in the option prepended with "no".

  echo noprint-parent > /debug/tracing/iter_ctrl
  echo noprint-parent > /debug/tracing/trace_options

To enable an option, leave off the "no".

  echo sym-offset > /debug/tracing/iter_ctrl
  echo sym-offset > /debug/tracing/trace_options

Here are the available options:

@@ -378,6 +380,20 @@ Here are the available options:
		When a trace is recorded, so is the stack of functions.
		This allows for back traces of trace sites.

  userstacktrace - This option changes the trace.
		   It records a stacktrace of the current userspace thread.

  sym-userobj - when user stacktrace are enabled, look up which object the
		address belongs to, and print a relative address
		This is especially useful when ASLR is on, otherwise you don't
		get a chance to resolve the address to object/file/line after the app is no
		longer running

		The lookup is performed when you read trace,trace_pipe,latency_trace. Example:

		a.out-1623  [000] 40874.465068: /root/a.out[+0x480] <-/root/a.out[+0
x494] <- /root/a.out[+0x4a8] <- /lib/libc-2.7.so[+0x1e1a6]

  sched-tree - TBD (any users??)


@@ -1059,6 +1075,83 @@ For simple one time traces, the above is sufficent. For anything else,
a search through /proc/mounts may be needed to find where the debugfs
file-system is mounted.


Single thread tracing
---------------------

By writing into /debug/tracing/set_ftrace_pid you can trace a
single thread. For example:

# cat /debug/tracing/set_ftrace_pid
no pid
# echo 3111 > /debug/tracing/set_ftrace_pid
# cat /debug/tracing/set_ftrace_pid
3111
# echo function > /debug/tracing/current_tracer
# cat /debug/tracing/trace | head
 # tracer: function
 #
 #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
 #              | |       |          |         |
     yum-updatesd-3111  [003]  1637.254676: finish_task_switch <-thread_return
     yum-updatesd-3111  [003]  1637.254681: hrtimer_cancel <-schedule_hrtimeout_range
     yum-updatesd-3111  [003]  1637.254682: hrtimer_try_to_cancel <-hrtimer_cancel
     yum-updatesd-3111  [003]  1637.254683: lock_hrtimer_base <-hrtimer_try_to_cancel
     yum-updatesd-3111  [003]  1637.254685: fget_light <-do_sys_poll
     yum-updatesd-3111  [003]  1637.254686: pipe_poll <-do_sys_poll
# echo -1 > /debug/tracing/set_ftrace_pid
# cat /debug/tracing/trace |head
 # tracer: function
 #
 #           TASK-PID    CPU#    TIMESTAMP  FUNCTION
 #              | |       |          |         |
 ##### CPU 3 buffer started ####
     yum-updatesd-3111  [003]  1701.957688: free_poll_entry <-poll_freewait
     yum-updatesd-3111  [003]  1701.957689: remove_wait_queue <-free_poll_entry
     yum-updatesd-3111  [003]  1701.957691: fput <-free_poll_entry
     yum-updatesd-3111  [003]  1701.957692: audit_syscall_exit <-sysret_audit
     yum-updatesd-3111  [003]  1701.957693: path_put <-audit_syscall_exit

If you want to trace a function when executing, you could use
something like this simple program:

#include <stdio.h>
#include <stdlib.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>

int main (int argc, char **argv)
{
        if (argc < 1)
                exit(-1);

        if (fork() > 0) {
                int fd, ffd;
                char line[64];
                int s;

                ffd = open("/debug/tracing/current_tracer", O_WRONLY);
                if (ffd < 0)
                        exit(-1);
                write(ffd, "nop", 3);

                fd = open("/debug/tracing/set_ftrace_pid", O_WRONLY);
                s = sprintf(line, "%d\n", getpid());
                write(fd, line, s);

                write(ffd, "function", 8);

                close(fd);
                close(ffd);

                execvp(argv[1], argv+1);
        }

        return 0;
}

dynamic ftrace
--------------

@@ -1158,7 +1251,11 @@ These are the only wild cards which are supported.

  <match>*<match> will not work.

 # echo hrtimer_* > /debug/tracing/set_ftrace_filter
Note: It is better to use quotes to enclose the wild cards, otherwise
  the shell may expand the parameters into names of files in the local
  directory.

 # echo 'hrtimer_*' > /debug/tracing/set_ftrace_filter

Produces:

@@ -1213,7 +1310,7 @@ Again, now we want to append.
 # echo sys_nanosleep > /debug/tracing/set_ftrace_filter
 # cat /debug/tracing/set_ftrace_filter
sys_nanosleep
 # echo hrtimer_* >> /debug/tracing/set_ftrace_filter
 # echo 'hrtimer_*' >> /debug/tracing/set_ftrace_filter
 # cat /debug/tracing/set_ftrace_filter
hrtimer_run_queues
hrtimer_run_pending
@@ -1299,41 +1396,29 @@ trace entries
-------------

Having too much or not enough data can be troublesome in diagnosing
an issue in the kernel. The file trace_entries is used to modify
an issue in the kernel. The file buffer_size_kb is used to modify
the size of the internal trace buffers. The number listed
is the number of entries that can be recorded per CPU. To know
the full size, multiply the number of possible CPUS with the
number of entries.

 # cat /debug/tracing/trace_entries
65620
 # cat /debug/tracing/buffer_size_kb
1408 (units kilobytes)

Note, to modify this, you must have tracing completely disabled. To do that,
echo "nop" into the current_tracer. If the current_tracer is not set
to "nop", an EINVAL error will be returned.

 # echo nop > /debug/tracing/current_tracer
 # echo 100000 > /debug/tracing/trace_entries
 # cat /debug/tracing/trace_entries
100045


Notice that we echoed in 100,000 but the size is 100,045. The entries
are held in individual pages. It allocates the number of pages it takes
to fulfill the request. If more entries may fit on the last page
then they will be added.

 # echo 1 > /debug/tracing/trace_entries
 # cat /debug/tracing/trace_entries
85

This shows us that 85 entries can fit in a single page.
 # echo 10000 > /debug/tracing/buffer_size_kb
 # cat /debug/tracing/buffer_size_kb
10000 (units kilobytes)

The number of pages which will be allocated is limited to a percentage
of available memory. Allocating too much will produce an error.

 # echo 1000000000000 > /debug/tracing/trace_entries
 # echo 1000000000000 > /debug/tracing/buffer_size_kb
-bash: echo: write error: Cannot allocate memory
 # cat /debug/tracing/trace_entries
 # cat /debug/tracing/buffer_size_kb
85
+12 −0
Original line number Diff line number Diff line
@@ -89,6 +89,7 @@ parameter is applicable:
	SPARC	Sparc architecture is enabled.
	SWSUSP	Software suspend (hibernation) is enabled.
	SUSPEND	System suspend states are enabled.
	FTRACE	Function tracing enabled.
	TS	Appropriate touchscreen support is enabled.
	USB	USB support is enabled.
	USBHID	USB Human Interface Device support is enabled.
@@ -753,6 +754,14 @@ and is between 256 and 4096 characters. It is defined in the file
			parameter will force ia64_sal_cache_flush to call
			ia64_pal_cache_flush instead of SAL_CACHE_FLUSH.

	ftrace=[tracer]
			[ftrace] will set and start the specified tracer
			as early as possible in order to facilitate early
			boot debugging.

	ftrace_dump_on_oops
			[ftrace] will dump the trace buffers on oops.

	gamecon.map[2|3]=
			[HW,JOY] Multisystem joystick and NES/SNES/PSX pad
			support via parallel port (up to 5 devices per port)
@@ -2196,6 +2205,9 @@ and is between 256 and 4096 characters. It is defined in the file
	st=		[HW,SCSI] SCSI tape parameters (buffers, etc.)
			See Documentation/scsi/st.txt.

	stacktrace	[FTRACE]
			Enabled the stack tracer on boot up.

	sti=		[PARISC,HW]
			Format: <num>
			Set the STI (builtin display/keyboard on the HP-PARISC
+24 −5
Original line number Diff line number Diff line
@@ -51,11 +51,16 @@ to call) for the specific marker through marker_probe_register() and can be
activated by calling marker_arm(). Marker deactivation can be done by calling
marker_disarm() as many times as marker_arm() has been called. Removing a probe
is done through marker_probe_unregister(); it will disarm the probe.
marker_synchronize_unregister() must be called before the end of the module exit
function to make sure there is no caller left using the probe. This, and the
fact that preemption is disabled around the probe call, make sure that probe
removal and module unload are safe. See the "Probe example" section below for a
sample probe module.

marker_synchronize_unregister() must be called between probe unregistration and
the first occurrence of
- the end of module exit function,
  to make sure there is no caller left using the probe;
- the free of any resource used by the probes,
  to make sure the probes wont be accessing invalid data.
This, and the fact that preemption is disabled around the probe call, make sure
that probe removal and module unload are safe. See the "Probe example" section
below for a sample probe module.

The marker mechanism supports inserting multiple instances of the same marker.
Markers can be put in inline functions, inlined static functions, and
@@ -70,6 +75,20 @@ a printk warning which identifies the inconsistency:

"Format mismatch for probe probe_name (format), marker (format)"

Another way to use markers is to simply define the marker without generating any
function call to actually call into the marker. This is useful in combination
with tracepoint probes in a scheme like this :

void probe_tracepoint_name(unsigned int arg1, struct task_struct *tsk);

DEFINE_MARKER_TP(marker_eventname, tracepoint_name, probe_tracepoint_name,
	"arg1 %u pid %d");

notrace void probe_tracepoint_name(unsigned int arg1, struct task_struct *tsk)
{
	struct marker *marker = &GET_MARKER(kernel_irq_entry);
	/* write data to trace buffers ... */
}

* Probe / marker example

+54 −40
Original line number Diff line number Diff line
@@ -3,28 +3,30 @@
			    Mathieu Desnoyers


This document introduces Linux Kernel Tracepoints and their use. It provides
examples of how to insert tracepoints in the kernel and connect probe functions
to them and provides some examples of probe functions.
This document introduces Linux Kernel Tracepoints and their use. It
provides examples of how to insert tracepoints in the kernel and
connect probe functions to them and provides some examples of probe
functions.


* Purpose of tracepoints

A tracepoint placed in code provides a hook to call a function (probe) that you
can provide at runtime. A tracepoint can be "on" (a probe is connected to it) or
"off" (no probe is attached). When a tracepoint is "off" it has no effect,
except for adding a tiny time penalty (checking a condition for a branch) and
space penalty (adding a few bytes for the function call at the end of the
instrumented function and adds a data structure in a separate section).  When a
tracepoint is "on", the function you provide is called each time the tracepoint
is executed, in the execution context of the caller. When the function provided
ends its execution, it returns to the caller (continuing from the tracepoint
site).
A tracepoint placed in code provides a hook to call a function (probe)
that you can provide at runtime. A tracepoint can be "on" (a probe is
connected to it) or "off" (no probe is attached). When a tracepoint is
"off" it has no effect, except for adding a tiny time penalty
(checking a condition for a branch) and space penalty (adding a few
bytes for the function call at the end of the instrumented function
and adds a data structure in a separate section).  When a tracepoint
is "on", the function you provide is called each time the tracepoint
is executed, in the execution context of the caller. When the function
provided ends its execution, it returns to the caller (continuing from
the tracepoint site).

You can put tracepoints at important locations in the code. They are
lightweight hooks that can pass an arbitrary number of parameters,
which prototypes are described in a tracepoint declaration placed in a header
file.
which prototypes are described in a tracepoint declaration placed in a
header file.

They can be used for tracing and performance accounting.

@@ -42,14 +44,16 @@ In include/trace/subsys.h :

#include <linux/tracepoint.h>

DEFINE_TRACE(subsys_eventname,
	TPPTOTO(int firstarg, struct task_struct *p),
DECLARE_TRACE(subsys_eventname,
	TPPROTO(int firstarg, struct task_struct *p),
	TPARGS(firstarg, p));

In subsys/file.c (where the tracing statement must be added) :

#include <trace/subsys.h>

DEFINE_TRACE(subsys_eventname);

void somefct(void)
{
	...
@@ -61,31 +65,41 @@ Where :
- subsys_eventname is an identifier unique to your event
    - subsys is the name of your subsystem.
    - eventname is the name of the event to trace.
- TPPTOTO(int firstarg, struct task_struct *p) is the prototype of the function
  called by this tracepoint.
- TPARGS(firstarg, p) are the parameters names, same as found in the prototype.

Connecting a function (probe) to a tracepoint is done by providing a probe
(function to call) for the specific tracepoint through
register_trace_subsys_eventname().  Removing a probe is done through
unregister_trace_subsys_eventname(); it will remove the probe sure there is no
caller left using the probe when it returns. Probe removal is preempt-safe
because preemption is disabled around the probe call. See the "Probe example"
section below for a sample probe module.

The tracepoint mechanism supports inserting multiple instances of the same
tracepoint, but a single definition must be made of a given tracepoint name over
all the kernel to make sure no type conflict will occur. Name mangling of the
tracepoints is done using the prototypes to make sure typing is correct.
Verification of probe type correctness is done at the registration site by the
compiler. Tracepoints can be put in inline functions, inlined static functions,
and unrolled loops as well as regular functions.

The naming scheme "subsys_event" is suggested here as a convention intended
to limit collisions. Tracepoint names are global to the kernel: they are
considered as being the same whether they are in the core kernel image or in
modules.
- TPPROTO(int firstarg, struct task_struct *p) is the prototype of the
  function called by this tracepoint.

- TPARGS(firstarg, p) are the parameters names, same as found in the
  prototype.

Connecting a function (probe) to a tracepoint is done by providing a
probe (function to call) for the specific tracepoint through
register_trace_subsys_eventname().  Removing a probe is done through
unregister_trace_subsys_eventname(); it will remove the probe.

tracepoint_synchronize_unregister() must be called before the end of
the module exit function to make sure there is no caller left using
the probe. This, and the fact that preemption is disabled around the
probe call, make sure that probe removal and module unload are safe.
See the "Probe example" section below for a sample probe module.

The tracepoint mechanism supports inserting multiple instances of the
same tracepoint, but a single definition must be made of a given
tracepoint name over all the kernel to make sure no type conflict will
occur. Name mangling of the tracepoints is done using the prototypes
to make sure typing is correct. Verification of probe type correctness
is done at the registration site by the compiler. Tracepoints can be
put in inline functions, inlined static functions, and unrolled loops
as well as regular functions.

The naming scheme "subsys_event" is suggested here as a convention
intended to limit collisions. Tracepoint names are global to the
kernel: they are considered as being the same whether they are in the
core kernel image or in modules.

If the tracepoint has to be used in kernel modules, an
EXPORT_TRACEPOINT_SYMBOL_GPL() or EXPORT_TRACEPOINT_SYMBOL() can be
used to export the defined tracepoints.

* Probe / tracepoint example

+13 −1
Original line number Diff line number Diff line
@@ -7,7 +7,19 @@

#ifndef __ASSEMBLY__
extern void _mcount(void);
#endif

#ifdef CONFIG_DYNAMIC_FTRACE
static inline unsigned long ftrace_call_adjust(unsigned long addr)
{
       /* reloction of mcount call site is the same as the address */
       return addr;
}

struct dyn_arch_ftrace {
	struct module *mod;
};
#endif /*  CONFIG_DYNAMIC_FTRACE */
#endif /* __ASSEMBLY__ */

#endif

Loading