From 7f09d639b8c4959736ff112d0fb42780c37ff6db Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Mon, 19 Dec 2022 13:31:08 -0500 Subject: tracing/selftests: Add test for event filtering on function name With the new filter logic of passing in the name of a function to match an instruction pointer (or the address of the function), add a test to make sure that it is functional. This is also the first test to test plain filtering. The filtering has been tested via the trigger logic, which uses the same code, but there was nothing to test just the event filter, so this test is the first to add such a case. Link: https://lkml.kernel.org/r/20221219183214.075559302@goodmis.org Cc: Andrew Morton Cc: Tom Zanussi Cc: Zheng Yejian Cc: linux-kselftest@vger.kernel.org Suggested-by: Masami Hiramatsu (Google) Reviewed-by: Ross Zwisler Acked-by: Shuah Khan Signed-off-by: Steven Rostedt (Google) --- .../ftrace/test.d/filter/event-filter-function.tc | 58 ++++++++++++++++++++++ 1 file changed, 58 insertions(+) create mode 100644 tools/testing/selftests/ftrace/test.d/filter/event-filter-function.tc (limited to 'tools') diff --git a/tools/testing/selftests/ftrace/test.d/filter/event-filter-function.tc b/tools/testing/selftests/ftrace/test.d/filter/event-filter-function.tc new file mode 100644 index 000000000000..e2ff3bf4df80 --- /dev/null +++ b/tools/testing/selftests/ftrace/test.d/filter/event-filter-function.tc @@ -0,0 +1,58 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: event filter function - test event filtering on functions +# requires: set_event events/kmem/kmem_cache_free/filter +# flags: instance + +fail() { #msg + echo $1 + exit_fail +} + +echo "Test event filter function name" +echo 0 > tracing_on +echo 0 > events/enable +echo > trace +echo 'call_site.function == exit_mmap' > events/kmem/kmem_cache_free/filter +echo 1 > events/kmem/kmem_cache_free/enable +echo 1 > tracing_on +ls > /dev/null +echo 0 > events/kmem/kmem_cache_free/enable + +hitcnt=`grep kmem_cache_free trace| grep exit_mmap | wc -l` +misscnt=`grep kmem_cache_free trace| grep -v exit_mmap | wc -l` + +if [ $hitcnt -eq 0 ]; then + exit_fail +fi + +if [ $misscnt -gt 0 ]; then + exit_fail +fi + +address=`grep ' exit_mmap$' /proc/kallsyms | cut -d' ' -f1` + +echo "Test event filter function address" +echo 0 > tracing_on +echo 0 > events/enable +echo > trace +echo "call_site.function == 0x$address" > events/kmem/kmem_cache_free/filter +echo 1 > events/kmem/kmem_cache_free/enable +echo 1 > tracing_on +sleep 1 +echo 0 > events/kmem/kmem_cache_free/enable + +hitcnt=`grep kmem_cache_free trace| grep exit_mmap | wc -l` +misscnt=`grep kmem_cache_free trace| grep -v exit_mmap | wc -l` + +if [ $hitcnt -eq 0 ]; then + exit_fail +fi + +if [ $misscnt -gt 0 ]; then + exit_fail +fi + +reset_events_filter + +exit 0 -- cgit v1.2.3 From b81a3a100cca1bd63d897efa339d047986615c9f Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" Date: Tue, 17 Jan 2023 10:21:31 -0500 Subject: tracing/histogram: Add simple tests for stacktrace usage of synthetic events Update the selftests to include a test of passing a stacktrace between the events of a synthetic event. Link: https://lkml.kernel.org/r/20230117152236.475439286@goodmis.org Cc: Masami Hiramatsu Cc: Andrew Morton Cc: Tom Zanussi Cc: Ross Zwisler Cc: Ching-lin Yu Signed-off-by: Steven Rostedt (Google) --- kernel/trace/trace.c | 2 +- .../inter-event/trigger-synthetic-event-stack.tc | 24 ++++++++++++++++++++++ .../inter-event/trigger-synthetic-event-syntax.tc | 6 ++++++ 3 files changed, 31 insertions(+), 1 deletion(-) create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-stack.tc (limited to 'tools') diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 78ed5f1baa8c..b90eecd27dfc 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -5757,7 +5757,7 @@ static const char readme_msg[] = #ifdef CONFIG_SYNTH_EVENTS " events/synthetic_events\t- Create/append/remove/show synthetic events\n" "\t Write into this file to define/undefine new synthetic events.\n" - "\t example: echo 'myevent u64 lat; char name[]' >> synthetic_events\n" + "\t example: echo 'myevent u64 lat; char name[]; long[] stack' >> synthetic_events\n" #endif #endif ; diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-stack.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-stack.tc new file mode 100644 index 000000000000..755dbe94ccf4 --- /dev/null +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-stack.tc @@ -0,0 +1,24 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: event trigger - test inter-event histogram trigger trace action with dynamic string param +# requires: set_event synthetic_events events/sched/sched_process_exec/hist "long[]' >> synthetic_events":README + +fail() { #msg + echo $1 + exit_fail +} + +echo "Test create synthetic event with stack" + + +echo 's:wake_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events +echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 1||prev_state == 2' >> events/sched/sched_switch/trigger +echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(wake_lat,prev_pid,$delta,$s)' >> events/sched/sched_switch/trigger +echo 1 > events/synthetic/wake_lat/enable +sleep 1 + +if ! grep -q "=>.*sched" trace; then + fail "Failed to create synthetic event with stack" +fi + +exit 0 diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-syntax.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-syntax.tc index 2968cdc7df30..366f1f3ad906 100644 --- a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-syntax.tc +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-syntax.tc @@ -70,6 +70,12 @@ grep "myevent[[:space:]]unsigned long var" synthetic_events echo "myevent char var[10]" > synthetic_events grep "myevent[[:space:]]char\[10\] var" synthetic_events +if grep -q 'long\[\]' README; then + # test stacktrace type + echo "myevent unsigned long[] var" > synthetic_events + grep "myevent[[:space:]]unsigned long\[\] var" synthetic_events +fi + do_reset exit 0 -- cgit v1.2.3 From 2455f0e124d317dd08d337a7550a78a224d4ba41 Mon Sep 17 00:00:00 2001 From: Ross Zwisler Date: Wed, 15 Feb 2023 15:33:45 -0700 Subject: tracing: Always use canonical ftrace path The canonical location for the tracefs filesystem is at /sys/kernel/tracing. But, from Documentation/trace/ftrace.rst: Before 4.1, all ftrace tracing control files were within the debugfs file system, which is typically located at /sys/kernel/debug/tracing. For backward compatibility, when mounting the debugfs file system, the tracefs file system will be automatically mounted at: /sys/kernel/debug/tracing Many comments and Kconfig help messages in the tracing code still refer to this older debugfs path, so let's update them to avoid confusion. Link: https://lore.kernel.org/linux-trace-kernel/20230215223350.2658616-2-zwisler@google.com Acked-by: Masami Hiramatsu (Google) Reviewed-by: Mukesh Ojha Signed-off-by: Ross Zwisler Signed-off-by: Steven Rostedt (Google) --- include/linux/kernel.h | 2 +- include/linux/tracepoint.h | 4 ++-- kernel/trace/Kconfig | 20 ++++++++++---------- kernel/trace/kprobe_event_gen_test.c | 2 +- kernel/trace/ring_buffer.c | 2 +- kernel/trace/synth_event_gen_test.c | 2 +- kernel/trace/trace.c | 2 +- samples/user_events/example.c | 4 ++-- scripts/tracing/draw_functrace.py | 6 +++--- tools/lib/api/fs/tracing_path.c | 4 ++-- tools/tracing/latency/latency-collector.c | 2 +- 11 files changed, 25 insertions(+), 25 deletions(-) (limited to 'tools') diff --git a/include/linux/kernel.h b/include/linux/kernel.h index fe6efb24d151..40bce7495af8 100644 --- a/include/linux/kernel.h +++ b/include/linux/kernel.h @@ -297,7 +297,7 @@ bool mac_pton(const char *s, u8 *mac); * * Use tracing_on/tracing_off when you want to quickly turn on or off * tracing. It simply enables or disables the recording of the trace events. - * This also corresponds to the user space /sys/kernel/debug/tracing/tracing_on + * This also corresponds to the user space /sys/kernel/tracing/tracing_on * file, which gives a means for the kernel and userspace to interact. * Place a tracing_off() in the kernel where you want tracing to end. * From user space, examine the trace, and then echo 1 > tracing_on diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h index 4b33b95eb8be..fa1004fcf810 100644 --- a/include/linux/tracepoint.h +++ b/include/linux/tracepoint.h @@ -471,7 +471,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p) * * This is how the trace record is structured and will * * be saved into the ring buffer. These are the fields * * that will be exposed to user-space in - * * /sys/kernel/debug/tracing/events/<*>/format. + * * /sys/kernel/tracing/events/<*>/format. * * * * The declared 'local variable' is called '__entry' * * @@ -531,7 +531,7 @@ static inline struct tracepoint *tracepoint_ptr_deref(tracepoint_ptr_t *p) * tracepoint callback (this is used by programmatic plugins and * can also by used by generic instrumentation like SystemTap), and * it is also used to expose a structured trace record in - * /sys/kernel/debug/tracing/events/. + * /sys/kernel/tracing/events/. * * A set of (un)registration functions can be passed to the variant * TRACE_EVENT_FN to perform any (un)registration work. diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig index d7043043f59c..5f5e64f9e715 100644 --- a/kernel/trace/Kconfig +++ b/kernel/trace/Kconfig @@ -239,7 +239,7 @@ config DYNAMIC_FTRACE enabled, and the functions not enabled will not affect performance of the system. - See the files in /sys/kernel/debug/tracing: + See the files in /sys/kernel/tracing: available_filter_functions set_ftrace_filter set_ftrace_notrace @@ -299,7 +299,7 @@ config STACK_TRACER select KALLSYMS help This special tracer records the maximum stack footprint of the - kernel and displays it in /sys/kernel/debug/tracing/stack_trace. + kernel and displays it in /sys/kernel/tracing/stack_trace. This tracer works by hooking into every function call that the kernel executes, and keeping a maximum stack depth value and @@ -339,7 +339,7 @@ config IRQSOFF_TRACER disabled by default and can be runtime (re-)started via: - echo 0 > /sys/kernel/debug/tracing/tracing_max_latency + echo 0 > /sys/kernel/tracing/tracing_max_latency (Note that kernel size and overhead increase with this option enabled. This option and the preempt-off timing option can be @@ -363,7 +363,7 @@ config PREEMPT_TRACER disabled by default and can be runtime (re-)started via: - echo 0 > /sys/kernel/debug/tracing/tracing_max_latency + echo 0 > /sys/kernel/tracing/tracing_max_latency (Note that kernel size and overhead increase with this option enabled. This option and the irqs-off timing option can be @@ -515,7 +515,7 @@ config TRACER_SNAPSHOT Allow tracing users to take snapshot of the current buffer using the ftrace interface, e.g.: - echo 1 > /sys/kernel/debug/tracing/snapshot + echo 1 > /sys/kernel/tracing/snapshot cat snapshot config TRACER_SNAPSHOT_PER_CPU_SWAP @@ -527,7 +527,7 @@ config TRACER_SNAPSHOT_PER_CPU_SWAP full swap (all buffers). If this is set, then the following is allowed: - echo 1 > /sys/kernel/debug/tracing/per_cpu/cpu2/snapshot + echo 1 > /sys/kernel/tracing/per_cpu/cpu2/snapshot After which, only the tracing buffer for CPU 2 was swapped with the main tracing buffer, and the other CPU buffers remain the same. @@ -574,7 +574,7 @@ config PROFILE_ANNOTATED_BRANCHES This tracer profiles all likely and unlikely macros in the kernel. It will display the results in: - /sys/kernel/debug/tracing/trace_stat/branch_annotated + /sys/kernel/tracing/trace_stat/branch_annotated Note: this will add a significant overhead; only turn this on if you need to profile the system's use of these macros. @@ -587,7 +587,7 @@ config PROFILE_ALL_BRANCHES taken in the kernel is recorded whether it hit or miss. The results will be displayed in: - /sys/kernel/debug/tracing/trace_stat/branch_all + /sys/kernel/tracing/trace_stat/branch_all This option also enables the likely/unlikely profiler. @@ -638,8 +638,8 @@ config BLK_DEV_IO_TRACE Tracing also is possible using the ftrace interface, e.g.: echo 1 > /sys/block/sda/sda1/trace/enable - echo blk > /sys/kernel/debug/tracing/current_tracer - cat /sys/kernel/debug/tracing/trace_pipe + echo blk > /sys/kernel/tracing/current_tracer + cat /sys/kernel/tracing/trace_pipe If unsure, say N. diff --git a/kernel/trace/kprobe_event_gen_test.c b/kernel/trace/kprobe_event_gen_test.c index c736487fc0e4..4850fdfe27f1 100644 --- a/kernel/trace/kprobe_event_gen_test.c +++ b/kernel/trace/kprobe_event_gen_test.c @@ -21,7 +21,7 @@ * Then: * * # insmod kernel/trace/kprobe_event_gen_test.ko - * # cat /sys/kernel/debug/tracing/trace + * # cat /sys/kernel/tracing/trace * * You should see many instances of the "gen_kprobe_test" and * "gen_kretprobe_test" events in the trace buffer. diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c index 45d4a23d6044..071184324d18 100644 --- a/kernel/trace/ring_buffer.c +++ b/kernel/trace/ring_buffer.c @@ -2886,7 +2886,7 @@ rb_check_timestamp(struct ring_buffer_per_cpu *cpu_buffer, sched_clock_stable() ? "" : "If you just came from a suspend/resume,\n" "please switch to the trace global clock:\n" - " echo global > /sys/kernel/debug/tracing/trace_clock\n" + " echo global > /sys/kernel/tracing/trace_clock\n" "or add trace_clock=global to the kernel command line\n"); } diff --git a/kernel/trace/synth_event_gen_test.c b/kernel/trace/synth_event_gen_test.c index 8d77526892f4..8dfe85499d4a 100644 --- a/kernel/trace/synth_event_gen_test.c +++ b/kernel/trace/synth_event_gen_test.c @@ -22,7 +22,7 @@ * Then: * * # insmod kernel/trace/synth_event_gen_test.ko - * # cat /sys/kernel/debug/tracing/trace + * # cat /sys/kernel/tracing/trace * * You should see several events in the trace buffer - * "create_synth_test", "empty_synth_test", and several instances of diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 97c88711f270..fbb602a8b64b 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -1187,7 +1187,7 @@ void tracing_snapshot_instance(struct trace_array *tr) * * Note, make sure to allocate the snapshot with either * a tracing_snapshot_alloc(), or by doing it manually - * with: echo 1 > /sys/kernel/debug/tracing/snapshot + * with: echo 1 > /sys/kernel/tracing/snapshot * * If the snapshot buffer is not allocated, it will stop tracing. * Basically making a permanent snapshot. diff --git a/samples/user_events/example.c b/samples/user_events/example.c index d06dc24156ec..18e34c9d708e 100644 --- a/samples/user_events/example.c +++ b/samples/user_events/example.c @@ -23,8 +23,8 @@ #endif /* Assumes debugfs is mounted */ -const char *data_file = "/sys/kernel/debug/tracing/user_events_data"; -const char *status_file = "/sys/kernel/debug/tracing/user_events_status"; +const char *data_file = "/sys/kernel/tracing/user_events_data"; +const char *status_file = "/sys/kernel/tracing/user_events_status"; static int event_status(long **status) { diff --git a/scripts/tracing/draw_functrace.py b/scripts/tracing/draw_functrace.py index 438516bdfb3c..42fa87300941 100755 --- a/scripts/tracing/draw_functrace.py +++ b/scripts/tracing/draw_functrace.py @@ -12,9 +12,9 @@ calls. Only the functions's names and the call time are provided. Usage: Be sure that you have CONFIG_FUNCTION_TRACER - # mount -t debugfs nodev /sys/kernel/debug - # echo function > /sys/kernel/debug/tracing/current_tracer - $ cat /sys/kernel/debug/tracing/trace_pipe > ~/raw_trace_func + # mount -t tracefs nodev /sys/kernel/tracing + # echo function > /sys/kernel/tracing/current_tracer + $ cat /sys/kernel/tracing/trace_pipe > ~/raw_trace_func Wait some times but not too much, the script is a bit slow. Break the pipe (Ctrl + Z) $ scripts/tracing/draw_functrace.py < ~/raw_trace_func > draw_functrace diff --git a/tools/lib/api/fs/tracing_path.c b/tools/lib/api/fs/tracing_path.c index b8e457c841ab..7ba3e81274e8 100644 --- a/tools/lib/api/fs/tracing_path.c +++ b/tools/lib/api/fs/tracing_path.c @@ -14,8 +14,8 @@ #include "tracing_path.h" static char tracing_mnt[PATH_MAX] = "/sys/kernel/debug"; -static char tracing_path[PATH_MAX] = "/sys/kernel/debug/tracing"; -static char tracing_events_path[PATH_MAX] = "/sys/kernel/debug/tracing/events"; +static char tracing_path[PATH_MAX] = "/sys/kernel/tracing"; +static char tracing_events_path[PATH_MAX] = "/sys/kernel/tracing/events"; static void __tracing_path_set(const char *tracing, const char *mountpoint) { diff --git a/tools/tracing/latency/latency-collector.c b/tools/tracing/latency/latency-collector.c index 59a7f2346eab..0fd9c747d396 100644 --- a/tools/tracing/latency/latency-collector.c +++ b/tools/tracing/latency/latency-collector.c @@ -1584,7 +1584,7 @@ static void *do_printloop(void *arg) /* * Toss a coin to decide if we want to sleep before printing * out the backtrace. The reason for this is that opening - * /sys/kernel/debug/tracing/trace will cause a blackout of + * /sys/kernel/tracing/trace will cause a blackout of * hundreds of ms, where no latencies will be noted by the * latency tracer. Thus by randomly sleeping we try to avoid * missing traces systematically due to this. With this option -- cgit v1.2.3