From c51ba517989efb4be3d8658f31c98786d88a89fe Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu Date: Fri, 11 Sep 2020 09:47:15 +0900 Subject: Documentation: tracing: Add tracing_on option to boot-time tracer Add tracing_on option description to the boot-time tracer. Link: https://lkml.kernel.org/r/159978523520.485820.9250337223076929279.stgit@devnote2 Signed-off-by: Masami Hiramatsu Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/boottime-trace.rst | 4 ++++ 1 file changed, 4 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/boottime-trace.rst b/Documentation/trace/boottime-trace.rst index dcb390075ca1..9bc8aceb8c0a 100644 --- a/Documentation/trace/boottime-trace.rst +++ b/Documentation/trace/boottime-trace.rst @@ -61,6 +61,10 @@ These options can be used for each instance including global ftrace node. ftrace.[instance.INSTANCE.]options = OPT1[, OPT2[...]] Enable given ftrace options. +ftrace.[instance.INSTANCE.]tracing_on = 0|1 + Enable/Disable tracing on this instance when starting boot-time tracing. + (you can enable it by the "traceon" event trigger action) + ftrace.[instance.INSTANCE.]trace_clock = CLOCK Set given CLOCK to ftrace's trace_clock. -- cgit From 638e476d1df6812fad0c700ee3e17727a4ff0d40 Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu Date: Thu, 10 Sep 2020 17:55:56 +0900 Subject: Documentation: tracing: Add %return suffix description Add a description of the %return suffix option for kprobe event and uprobe event. Link: https://lkml.kernel.org/r/159972815624.428528.10450874184415697524.stgit@devnote2 Signed-off-by: Masami Hiramatsu Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/kprobetrace.rst | 2 ++ Documentation/trace/uprobetracer.rst | 2 ++ 2 files changed, 4 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/kprobetrace.rst b/Documentation/trace/kprobetrace.rst index c1709165c553..a18eb97a263c 100644 --- a/Documentation/trace/kprobetrace.rst +++ b/Documentation/trace/kprobetrace.rst @@ -30,6 +30,7 @@ Synopsis of kprobe_events p[:[GRP/]EVENT] [MOD:]SYM[+offs]|MEMADDR [FETCHARGS] : Set a probe r[MAXACTIVE][:[GRP/]EVENT] [MOD:]SYM[+0] [FETCHARGS] : Set a return probe + p:[GRP/]EVENT] [MOD:]SYM[+0]%return [FETCHARGS] : Set a return probe -:[GRP/]EVENT : Clear a probe GRP : Group name. If omitted, use "kprobes" for it. @@ -37,6 +38,7 @@ Synopsis of kprobe_events based on SYM+offs or MEMADDR. MOD : Module name which has given SYM. SYM[+offs] : Symbol+offset where the probe is inserted. + SYM%return : Return address of the symbol MEMADDR : Address where the probe is inserted. MAXACTIVE : Maximum number of instances of the specified function that can be probed simultaneously, or 0 for the default value diff --git a/Documentation/trace/uprobetracer.rst b/Documentation/trace/uprobetracer.rst index 98cde99939d7..a8e5938f609e 100644 --- a/Documentation/trace/uprobetracer.rst +++ b/Documentation/trace/uprobetracer.rst @@ -28,6 +28,7 @@ Synopsis of uprobe_tracer p[:[GRP/]EVENT] PATH:OFFSET [FETCHARGS] : Set a uprobe r[:[GRP/]EVENT] PATH:OFFSET [FETCHARGS] : Set a return uprobe (uretprobe) + p[:[GRP/]EVENT] PATH:OFFSET%return [FETCHARGS] : Set a return uprobe (uretprobe) -:[GRP/]EVENT : Clear uprobe or uretprobe event GRP : Group name. If omitted, "uprobes" is the default value. @@ -35,6 +36,7 @@ Synopsis of uprobe_tracer on PATH+OFFSET. PATH : Path to an executable or a library. OFFSET : Offset where the probe is inserted. + OFFSET%return : Offset where the return probe is inserted. FETCHARGS : Arguments. Each probe can have up to 128 args. %REG : Fetch register REG -- cgit From 19c311ae7c0f4f2475617a8acb7ba7b7b4575f0e Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu Date: Thu, 10 Sep 2020 17:56:06 +0900 Subject: Documentation: tracing: boot: Add an example of tracing function-calls Add an example of tracing function calls on a specific function. Link: https://lkml.kernel.org/r/159972816669.428528.12390560334549382316.stgit@devnote2 Signed-off-by: Masami Hiramatsu Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/boottime-trace.rst | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/boottime-trace.rst b/Documentation/trace/boottime-trace.rst index 9bc8aceb8c0a..ab3bfd67197c 100644 --- a/Documentation/trace/boottime-trace.rst +++ b/Documentation/trace/boottime-trace.rst @@ -168,6 +168,26 @@ is for tracing functions starting with "user\_", and others tracing The instance node also accepts event nodes so that each instance can customize its event tracing. +With the trigger action and kprobes, you can trace function-graph while +a function is called. For example, this will trace all function calls in +the pci_proc_init():: + + ftrace { + tracing_on = 0 + tracer = function_graph + event.kprobes { + start_event { + probes = "pci_proc_init" + actions = "traceon" + } + end_event { + probes = "pci_proc_init%return" + actions = "traceoff" + } + } + } + + This boot-time tracing also supports ftrace kernel parameters via boot config. For example, following kernel parameters:: -- cgit From fd264ce96c382bc2e36eb1f49ac45c5980650244 Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu Date: Thu, 10 Sep 2020 21:39:27 +0900 Subject: Documentation: tracing: Add the startup timing of boot-time tracing Add the note about when to start the boot-time tracing. This will be needed for the people who wants to trace earlier boot sequence. Link: https://lkml.kernel.org/r/159974156678.478751.10215894815285734481.stgit@devnote2 Signed-off-by: Masami Hiramatsu Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/boottime-trace.rst | 14 ++++++++++++++ 1 file changed, 14 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/boottime-trace.rst b/Documentation/trace/boottime-trace.rst index ab3bfd67197c..89b64334929b 100644 --- a/Documentation/trace/boottime-trace.rst +++ b/Documentation/trace/boottime-trace.rst @@ -120,6 +120,20 @@ instance node, but those are also visible from other instances. So please take care for event name conflict. +When to Start +============= + +All boot-time tracing options starting with ``ftrace`` will be enabled at the +end of core_initcall. This means you can trace the events from postcore_initcall. +Most of the subsystems and architecture dependent drivers will be initialized +after that (arch_initcall or subsys_initcall). Thus, you can trace those with +boot-time tracing. +If you want to trace events before core_initcall, you can use the options +starting with ``kernel``. Some of them will be enabled eariler than the initcall +processing (for example,. ``kernel.ftrace=function`` and ``kernel.trace_event`` +will start before the initcall.) + + Examples ======== -- cgit From afbe7973173a7ce0a68af8b33e44c967582297be Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (VMware)" Date: Thu, 24 Sep 2020 12:30:20 -0400 Subject: tracepoints: Add helper to test if tracepoint is enabled in a header As tracepoints are discouraged from being added in a header because it can cause side effects if other tracepoints are in headers, as well as bloat the kernel as the trace_() function is not a small inline, the common workaround is to add a function call that calls a wrapper function in a C file that then calls the tracepoint. But as function calls add overhead, this function should only be called when the tracepoint in question is enabled. To get around this overhead, a static_branch can be used to only have the tracepoint wrapper get called when the tracepoint is enabled. Add a tracepoint_enabled(tp) macro that gets passed the name of the tracepoint, and this becomes a static_branch that is enabled when the tracepoint is enabled and is a nop when the tracepoint is disabled. Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/tracepoints.rst | 27 +++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/tracepoints.rst b/Documentation/trace/tracepoints.rst index 6e3ce3bf3593..0cb8d9ca3d60 100644 --- a/Documentation/trace/tracepoints.rst +++ b/Documentation/trace/tracepoints.rst @@ -146,3 +146,30 @@ with jump labels and avoid conditional branches. define tracepoints. Check http://lwn.net/Articles/379903, http://lwn.net/Articles/381064 and http://lwn.net/Articles/383362 for a series of articles with more details. + +If you require calling a tracepoint from a header file, it is not +recommended to call one directly or to use the trace__enabled() +function call, as tracepoints in header files can have side effects if a +header is included from a file that has CREATE_TRACE_POINTS set, as +well as the trace_() is not that small of an inline +and can bloat the kernel if used by other inlined functions. Instead, +include tracepoint-defs.h and use tracepoint_enabled(). + +In a C file:: + + void do_trace_foo_bar_wrapper(args) + { + trace_foo_bar(args); + } + +In the header file:: + + DECLARE_TRACEPOINT(foo_bar); + + static inline void some_inline_function() + { + [..] + if (tracepoint_enabled(foo_bar)) + do_trace_foo_bar_wrapper(args); + [..] + } -- cgit From bd82631d7ccdc894af2738e47abcba2cb6e7dea9 Mon Sep 17 00:00:00 2001 From: Tom Zanussi Date: Sun, 4 Oct 2020 17:14:06 -0500 Subject: tracing: Add support for dynamic strings to synthetic events Currently, sythetic events only support static string fields such as: # echo 'test_latency u64 lat; char somename[32]' > /sys/kernel/debug/tracing/synthetic_events Which is fine, but wastes a lot of space in the event. It also prevents the most commonly-defined strings in the existing trace events e.g. those defined using __string(), from being passed to synthetic events via the trace() action. With this change, synthetic events with dynamic fields can be defined: # echo 'test_latency u64 lat; char somename[]' > /sys/kernel/debug/tracing/synthetic_events And the trace() action can be used to generate events using either dynamic or static strings: # echo 'hist:keys=name:lat=common_timestamp.usecs-$ts0:onmatch(sys.event).test_latency($lat,name)' > /sys/kernel/debug/tracing/events The synthetic event dynamic strings are implemented in the same way as the existing __data_loc strings and appear as such in the format file. [ : added __set_synth_event_print_fmt() changes: I added the following to make it work with trace-cmd. Dynamic strings must have __get_str() for events in the print_fmt otherwise it can't be parsed correctly. ] Link: https://lore.kernel.org/r/cover.1601588066.git.zanussi@kernel.org Link: https://lkml.kernel.org/r/3ed35b6d0e390f5b94cb4a9ba1cc18f5982ab277.1601848695.git.zanussi@kernel.org Tested-by: Axel Rasmussen Signed-off-by: Tom Zanussi Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/events.rst | 15 +++++++++++++-- Documentation/trace/histogram.rst | 18 ++++++++++++++++++ 2 files changed, 31 insertions(+), 2 deletions(-) (limited to 'Documentation/trace') diff --git a/Documentation/trace/events.rst b/Documentation/trace/events.rst index f792b1959a33..2a5aa48eff6c 100644 --- a/Documentation/trace/events.rst +++ b/Documentation/trace/events.rst @@ -589,8 +589,19 @@ name:: { .type = "int", .name = "my_int_field" }, }; -See synth_field_size() for available types. If field_name contains [n] -the field is considered to be an array. +See synth_field_size() for available types. + +If field_name contains [n], the field is considered to be a static array. + +If field_names contains[] (no subscript), the field is considered to +be a dynamic array, which will only take as much space in the event as +is required to hold the array. + +Because space for an event is reserved before assigning field values +to the event, using dynamic arrays implies that the piecewise +in-kernel API described below can't be used with dynamic arrays. The +other non-piecewise in-kernel APIs can, however, be used with dynamic +arrays. If the event is created from within a module, a pointer to the module must be passed to synth_event_create(). This will ensure that the diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index 8408670d0328..b573604deabd 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1776,6 +1776,24 @@ consisting of the name of the new event along with one or more variables and their types, which can be any valid field type, separated by semicolons, to the tracing/synthetic_events file. +See synth_field_size() for available types. + +If field_name contains [n], the field is considered to be a static array. + +If field_names contains[] (no subscript), the field is considered to +be a dynamic array, which will only take as much space in the event as +is required to hold the array. + +A string field can be specified using either the static notation: + + char name[32]; + +Or the dynamic: + + char name[]; + +The size limit for either is 256. + For instance, the following creates a new event named 'wakeup_latency' with 3 fields: lat, pid, and prio. Each of those fields is simply a variable reference to a variable on another event:: -- cgit