tracing: Updates for 7.4
Subsystems (4)
cover tracing: Updates for 7.4
git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace.git
trace/for-next
Head SHA1: d3e0dfc1ba49a0ab6aeddbb4bcde4bfc0e171a02
Chen Jun (1):
tracing: Add "within" filter for call-stack-based event filtering
Donggeun Yoo (7):
tracing: Print the bucket size as unsigned
tracing: Add the bucket size to expr_field_str()
tracing: Only report the stacktrace modifier on a real field
tracing: Unregister field variable histograms when the command fails
tracing: Clamp the printed end of a histogram bucket at U64_MAX
tracing: Fix 64-bit and signed histogram fields on 32-bit kernels
tracing: Print a signed histogram key as signed
Steven Rostedt (1):
tracnig: Add proper error message for glob use with "within" filter
Thomas Weißschuh (6):
tracing: Remove duplicate declaration of ftrace_set_clr_event()
tracing: Stop modifying the input buffer in ftrace_set_clr_event()
tracing: Split the event string parsing logic into a dedicated function
tracing: Add a test for ftrace_parse_event_string()
tracing: Add a filter argument to __ftrace_set_clr_event()
tracing: Parse filter from boot event string
Vincent Donnefort (3):
ring-buffer: Rename ring_buffer_size() to ring_buffer_capacity()
tracing: Rename trace_array::entries to capacity
tracing: Rename tracing_entries_fops to tracing_capacity_fops
----
Documentation/admin-guide/kernel-parameters.txt | 9 +- Documentation/trace/events.rst | 17 ++++ Documentation/trace/histogram.rst | 3 + include/linux/ring_buffer.h | 2 +- include/linux/trace_events.h | 3 +- kernel/trace/Kconfig | 8 ++ kernel/trace/Makefile | 1 + kernel/trace/ring_buffer.c | 13 ++- kernel/trace/trace.c | 51 +++++----- kernel/trace/trace.h | 13 ++- kernel/trace/trace_boot.c | 2 +- kernel/trace/trace_events.c | 128 +++++++++++++++--------- kernel/trace/trace_events_filter.c | 44 +++++++- kernel/trace/trace_events_hist.c | 42 ++++++-- kernel/trace/trace_events_test.c | 122 ++++++++++++++++++++++ kernel/trace/trace_snapshot.c | 14 +-- 16 files changed, 365 insertions(+), 107 deletions(-) create mode 100644 kernel/trace/trace_events_test.c
PATCH 1/18 tracing: Add "within" filter for call-stack-based event filtering
From: Chen Jun <[email protected]>
Low-level kernel functions are called from many different paths. When debugging, it is often useful to filter trace events to only those occurring within a specific call chain.
Add a "within" filter predicate that tests whether a given function appears in the current call stack at event time. The function name is resolved to its address range via kallsyms during filter setup; at runtime, stack_trace_save() captures the call stack and compares each return address against the stored range.
Example:
echo 'within == "vfs_read"' > events/sched/sched_switch/filter
Only "==" and "!=" operators are supported. The filter depends on CONFIG_STACKTRACE.
--- Documentation/trace/events.rst | 12 +++++++++ include/linux/trace_events.h | 1 + kernel/trace/trace.h | 3 ++- kernel/trace/trace_events.c | 3 +++ kernel/trace/trace_events_filter.c | 41 ++++++++++++++++++++++++++++-- 5 files changed, 57 insertions(+), 3 deletions(-)
Documentation/trace/events.rst +12 -0
@@ -243,6 +243,18 @@ the function "security_prepare_creds" and less than the end of that function. The ".function" postfix can only be attached to values of size long, and can only be compared with "==" or "!=". +The special field "within" can be used to filter events based on whether +a specific function appears in the current call stack:: + + within == "function_name" + within != "function_name" + +For example, to only trace events where "vfs_read" is in the call stack:: + + # echo 'within == "vfs_read"' > events/sched/sched_switch/filter + +The within field supports only the "==" and "!=" operators. + Cpumask fields or scalar fields that encode a CPU number can be filtered using a user-provided cpumask in cpulist format. The format is as follows::
include/linux/trace_events.h +1 -0
@@ -872,6 +872,7 @@ enum {FILTER_COMM ,FILTER_CPU ,FILTER_STACKTRACE , + FILTER_WITHIN, };extern int trace_event_raw_init (struct trace_event_call *call);
kernel/trace/trace.h +2 -1
@@ -1826,7 +1826,8 @@ static inline bool is_string_field(struct ftrace_event_field *field) field->filter_type ==FILTER_RDYN_STRING || field->filter_type ==FILTER_STATIC_STRING || field->filter_type ==FILTER_PTR_STRING || - field->filter_type ==FILTER_COMM ; + field->filter_type ==FILTER_COMM || + field->filter_type ==FILTER_WITHIN ; }static inline bool is_function_field (struct ftrace_event_field *field)
kernel/trace/trace_events.c +3 -0
@@ -201,6 +201,9 @@ static int trace_define_generic_fields(void) __generic_field(char *, comm, FILTER_COMM); __generic_field(char *, stacktrace, FILTER_STACKTRACE); __generic_field(char *, STACKTRACE, FILTER_STACKTRACE); +#ifdef CONFIG_STACKTRACE + __generic_field(char *, within, FILTER_WITHIN); +#endif return ret; }
kernel/trace/trace_events_filter.c +39 -2
67 lines not on this page · raw message
Signature · 1 line
2.53.0
PATCH 2/18 tracnig: Add proper error message for glob use with "within" filter
In reply to Steven RostedtFrom: Steven Rostedt <[email protected]>
If a user were to use a glob expression with the "within" filter, it currently just fails with an errno return but does not update the error_log to tell the user why it failed. Update it to use the parsing error log to tell the user why it failed.
# echo 'within ~ "*_read"' > events/kmem/kmem_cache_alloc/filter -bash: echo: write error: Invalid argument
# cat error_log
[ 4676.606481] event filter parse error: error: 'within' filter cannot take glob expressions
Command: within ~ "*_read"
^--- kernel/trace/trace_events_filter.c | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-)
kernel/trace/trace_events_filter.c +4 -1
@@ -118,6 +118,7 @@ struct filter_pred {C (IP_FIELD_ONLY ,"Only 'ip' field is supported for function trace" ), \C (INVALID_VALUE ,"Invalid value (did you forget quotes)?" ), \C (NO_FUNCTION ,"Function not found" ), \ +C (GLOB_WITHIN ,"'within' filter cannot take glob expressions" ), \C (ERRNO ,"Error" ), \C (NO_FILTER ,"No filter found" )
@@ -2027,8 +2028,10 @@ static int parse_pred(const char *str, void *data, }else if (field->filter_type ==FILTER_WITHIN ) {unsigned long func; -if (op ==OP_GLOB ) +if (op ==OP_GLOB ) { +parse_error (pe,FILT_ERR_GLOB_WITHIN , pos + i); goto err_free; + } pred->fn_num =FILTER_PRED_FN_WITHIN ; func =kallsyms_lookup_name (pred->regex->pattern);
Signature · 1 line
2.53.0
PATCH 3/18 tracing: Remove duplicate declaration of ftrace_set_clr_event()
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
The function is also declared in include/linux/trace_events.h which is even included from kernel/trace/trace.h.
Having two declarations creates churn when changing the signature.
Remove the unnecessary, duplicate declaration.
--- kernel/trace/trace.h | 1 - 1 file changed, 1 deletion(-)
kernel/trace/trace.h +0 -1
@@ -2290,7 +2290,6 @@ static inline const char *get_syscall_name(int syscall)void trace_event_init (void );void trace_event_update_all (struct trace_eval_map **map,int len,struct module *mod);/* Used from boot time tracer */ -extern int ftrace_set_clr_event (struct trace_array *tr,char *buf,int set);extern int trigger_process_regex (struct trace_event_file *file,char *buff);#else static inline void __init trace_event_init (void ) { }
Signature · 1 line
2.53.0
PATCH 4/18 tracing: Stop modifying the input buffer in ftrace_set_clr_event()
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
ftrace_set_clr_event() modifies its input buffer during parsing. Before returning to the caller these modifications are undone. This is restoration is error prone and was forgotten before. Upcoming changes will also make it more complicated.
Copy the input argument and modify that copy and drop the restoration logic.
Also mark the input argument as const.
--- include/linux/trace_events.h | 2 +- kernel/trace/trace_events.c | 19 ++++++++----------- 2 files changed, 9 insertions(+), 12 deletions(-)
include/linux/trace_events.h +1 -1
@@ -883,7 +883,7 @@ extern int trace_add_event_call(struct trace_event_call *call);extern int trace_remove_event_call (struct trace_event_call *call);extern int trace_event_get_offsets (struct trace_event_call *call); -int ftrace_set_clr_event (struct trace_array *tr,char *buf,int set); +int ftrace_set_clr_event (struct trace_array *tr,const char *buf,int set);int trace_set_clr_event (const char *system,const char *event,int set);int trace_array_set_clr_event (struct trace_array *tr,const char *system,const char *event,bool enable);
kernel/trace/trace_events.c +8 -11
@@ -1443,14 +1443,19 @@ static int __ftrace_set_clr_event(struct trace_array *tr, const char *match,return ret; } -int ftrace_set_clr_event (struct trace_array *tr,char *buf,int set) +int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set) {char *event =NULL , *sub =NULL , *match, *mod; -int ret; +char *buf;if (!tr)return -ENOENT ; + char *dupped_buf __free(kfree) = kstrdup(arg_buf, GFP_KERNEL); +if (!dupped_buf) +return -ENOMEM ; + buf = dupped_buf; +/* Modules events can be appended with :mod:<module> */ mod =strstr (buf,":mod:" );if (mod) {
@@ -1487,15 +1492,7 @@ int ftrace_set_clr_event(struct trace_array *tr, char *buf, int set) match =NULL ; } - ret =__ftrace_set_clr_event (tr, match, sub, event, set, mod); - -/* Put back the colon to allow this to be called again */ -if (buf) - *(buf -1 ) =':' ; -if (mod) - *(mod -5 ) =':' ; - -return ret; +return __ftrace_set_clr_event (tr, match, sub, event, set, mod); }/**
Signature · 1 line
2.53.0
PATCH 5/18 tracing: Split the event string parsing logic into a dedicated function
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
This new function can be tested with a KUnit test to prevent regressions when adding new fields to the format.
--- kernel/trace/trace_events.c | 61 +++++++++++++++++++++---------------- 1 file changed, 34 insertions(+), 27 deletions(-)
kernel/trace/trace_events.c +34 -27
@@ -1443,25 +1443,18 @@ static int __ftrace_set_clr_event(struct trace_array *tr, const char *match,return ret; } -int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set) +static void +ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod) { -char *event =NULL , *sub =NULL , *match, *mod; -char *buf; - -if (!tr) -return -ENOENT ; - - char *dupped_buf __free(kfree) = kstrdup(arg_buf, GFP_KERNEL); -if (!dupped_buf) -return -ENOMEM ; - buf = dupped_buf; + *event =NULL ; + *sub =NULL ;/* Modules events can be appended with :mod:<module> */ - mod =strstr (buf,":mod:" ); -if (mod) { - *mod ='\0' ; + *mod =strstr (buf,":mod:" ); +if (*mod) { + **mod ='\0' ;/* move to the module name */ - mod +=5 ; + *mod +=5 ; }/*
@@ -1476,21 +1469,35 @@ int ftrace_set_clr_event(struct trace_array *tr, const char *arg_buf, int set)* the name <name> or any event that matches <name> */ - match =strsep (&buf,":" ); + *match =strsep (&buf,":" );if (buf) { - sub = match; - event = buf; - match =NULL ; - -if (!strlen (sub) ||strcmp (sub,"*" ) ==0 ) - sub =NULL ; -if (!strlen (event) ||strcmp (event,"*" ) ==0 ) - event =NULL ; - }else if (mod) { + *sub = *match; + *event = buf; + *match =NULL ; + +if (!strlen (*sub) ||strcmp (*sub,"*" ) ==0 ) + *sub =NULL ; +if (!strlen (*event) ||strcmp (*event,"*" ) ==0 ) + *event =NULL ; + }else if (*mod) {/* Allow wildcard for no length or star */ -if (!strlen (match) ||strcmp (match,"*" ) ==0 ) - match =NULL ; +if (!strlen (*match) ||strcmp (*match,"*" ) ==0 ) + *match =NULL ; } +} + +int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set) +{ +char *event, *sub, *match, *mod; + +if (!tr) +return -ENOENT ; + + char *dupped_buf __free(kfree) = kstrdup(arg_buf, GFP_KERNEL); +if (!dupped_buf) +return -ENOMEM ; + +ftrace_parse_event_string (dupped_buf, &match, &sub, &event, &mod);return __ftrace_set_clr_event (tr, match, sub, event, set, mod); }
Signature · 1 line
2.53.0
PATCH 6/18 tracing: Add a test for ftrace_parse_event_string()
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
The parsing logic is a bit complicated and about to become more so.
Add a unit test to avoid regressions.
--- kernel/trace/Kconfig | 8 +++ kernel/trace/Makefile | 1 + kernel/trace/trace.h | 4 ++ kernel/trace/trace_events.c | 5 +- kernel/trace/trace_events_test.c | 102 +++++++++++++++++++++++++++++++ 5 files changed, 119 insertions(+), 1 deletion(-) create mode 100644 kernel/trace/trace_events_test.c
kernel/trace/Kconfig +8 -0
@@ -151,6 +151,14 @@ config EVENT_TRACING select GLOB bool +config EVENT_TRACING_TEST + tristate "Test for event tracing" if !KUNIT_ALL_TESTS + depends on EVENT_TRACING + depends on KUNIT + default KUNIT_ALL_TESTS + help + KUnit test for the event tracing implementation. + config CONTEXT_SWITCH_TRACER bool
kernel/trace/Makefile +1 -0
@@ -96,6 +96,7 @@ obj-$(CONFIG_EVENT_TRACING) += blktrace.o endif obj-$(CONFIG_EVENT_TRACING) += trace_events.o obj-$(CONFIG_EVENT_TRACING) += trace_export.o +obj-$(CONFIG_EVENT_TRACING_TEST) += trace_events_test.o obj-$(CONFIG_FTRACE_SYSCALLS) += trace_syscalls.o ifeq ($(CONFIG_PERF_EVENTS),y) obj-$(CONFIG_EVENT_TRACING) += trace_event_perf.o
kernel/trace/trace.h +4 -0
@@ -2509,3 +2509,7 @@ static inline int rv_init_interface(void) })#endif /* _LINUX_KERNEL_TRACE_H */ + +#if IS_ENABLED (CONFIG_KUNIT ) +void ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod); +#endif
kernel/trace/trace_events.c +4 -1
@@ -25,6 +25,8 @@#include <linux/delay.h> #include <linux/btf.h> +#include <kunit/visibility.h> +#include <trace/events/sched.h> #include <trace/syscall.h>
@@ -1443,7 +1445,7 @@ static int __ftrace_set_clr_event(struct trace_array *tr, const char *match,return ret; } -static void +VISIBLE_IF_KUNIT voidftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod) { *event =NULL ;
@@ -1485,6 +1487,7 @@ ftrace_parse_event_string(char *buf, char **match, char **sub, char **event, cha *match =NULL ; } } +EXPORT_SYMBOL_IF_KUNIT (ftrace_parse_event_string);int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set) {
kernel/trace/trace_events_test.c new file +102 -0
102 lines not on this page · raw message
Signature · 1 line
2.53.0
PATCH 7/18 tracing: Add a filter argument to __ftrace_set_clr_event()
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
Make it possible to directly enable a filter when enabling an event.
For now this is unused, an upcoming patch will wire it up.
--- kernel/trace/trace_events.c | 47 +++++++++++++++++++++++-------------- 1 file changed, 30 insertions(+), 17 deletions(-)
kernel/trace/trace_events.c +30 -17
@@ -946,6 +946,7 @@ struct event_mod_load {char *match;char *system;char *event; +char *filter; };static void free_event_mod (struct event_mod_load *event_mod)
@@ -955,6 +956,7 @@ static void free_event_mod(struct event_mod_load *event_mod)kfree (event_mod->match);kfree (event_mod->system);kfree (event_mod->event); +kfree (event_mod->filter);kfree (event_mod); }
@@ -996,7 +998,7 @@ static int remove_cache_mod(struct trace_array *tr, const char *mod, }static int cache_mod (struct trace_array *tr,const char *mod,int set, -const char *match,const char *system,const char *event) +const char *match,const char *system,const char *event,const char *filter) {struct event_mod_load *event_mod;
@@ -1035,6 +1037,12 @@ static int cache_mod(struct trace_array *tr, const char *mod, int set, goto out_free; } +if (filter) { + event_mod->filter =kstrdup (filter,GFP_KERNEL ); +if (!event_mod->filter) + goto out_free; + } +list_add (&event_mod->list, &tr->mod_events);return 0 ;
@@ -1047,7 +1055,7 @@ static int cache_mod(struct trace_array *tr, const char *mod, int set,#else /* CONFIG_MODULES */ static inline void clear_mod_events (struct trace_array *tr) { }static int cache_mod (struct trace_array *tr,const char *mod,int set, -const char *match,const char *system,const char *event) +const char *match,const char *system,const char *event,const char *filter) {return -EINVAL ; }
@@ -1356,7 +1364,7 @@ static void remove_event_file_dir(struct trace_event_file *file)static int __ftrace_set_clr_event_nolock (struct trace_array *tr,const char *match,const char *sub,const char *event,int set, -const char *mod) +const char *mod,char *filter) {struct trace_event_file *file;struct trace_event_call *call;
@@ -1406,7 +1414,11 @@ __ftrace_set_clr_event_nolock(struct trace_array *tr, const char *match,if (event &&strcmp (event, name) !=0 )continue ; - ret =ftrace_event_enable_disable (file, set); +if (filter) + ret =apply_event_filter (file, filter); + +if (!filter || !ret) + ret =ftrace_event_enable_disable (file, set);/* * Save the first error and return that. Some events
@@ -1424,14 +1436,14 @@ __ftrace_set_clr_event_nolock(struct trace_array *tr, const char *match,* check if the module was loaded. If it wasn't cache it. */ if (module && ret == -EINVAL && !eret) - ret =cache_mod (tr, module, set, match, sub, event); + ret =cache_mod (tr, module, set, match, sub, event, filter);return ret; }static int __ftrace_set_clr_event (struct trace_array *tr,const char *match,const char *sub,const char *event,int set, -const char *mod) +const char *mod,char *filter) {int ret;
@@ -1439,7 +1451,7 @@ static int __ftrace_set_clr_event(struct trace_array *tr, const char *match,return -EACCES ;mutex_lock (&event_mutex); - ret =__ftrace_set_clr_event_nolock (tr, match, sub, event, set, mod); + ret =__ftrace_set_clr_event_nolock (tr, match, sub, event, set, mod, filter);mutex_unlock (&event_mutex);return ret;
@@ -1502,7 +1514,7 @@ int ftrace_set_clr_event(struct trace_array *tr, const char *arg_buf, int set)ftrace_parse_event_string (dupped_buf, &match, &sub, &event, &mod); -return __ftrace_set_clr_event (tr, match, sub, event, set, mod); +return __ftrace_set_clr_event (tr, match, sub, event, set, mod,NULL ); }/**
@@ -1524,7 +1536,7 @@ int trace_set_clr_event(const char *system, const char *event, int set)if (!tr)return -ENODEV ; -return __ftrace_set_clr_event (tr,NULL , system, event, set,NULL ); +return __ftrace_set_clr_event (tr,NULL , system, event, set,NULL ,NULL ); }EXPORT_SYMBOL_GPL (trace_set_clr_event);
@@ -1550,7 +1562,7 @@ int trace_array_set_clr_event(struct trace_array *tr, const char *system,return -ENOENT ; set = (enable == true) ?1 :0 ; -return __ftrace_set_clr_event (tr,NULL , system, event, set,NULL ); +return __ftrace_set_clr_event (tr,NULL , system, event, set,NULL ,NULL ); }EXPORT_SYMBOL_GPL (trace_array_set_clr_event);
@@ -2070,7 +2082,7 @@ system_enable_write(struct file *filp, const char __user *ubuf, size_t cnt,if (system) name = system->name; - ret =__ftrace_set_clr_event (dir->tr,NULL , name,NULL , val,NULL ); + ret =__ftrace_set_clr_event (dir->tr,NULL , name,NULL , val,NULL ,NULL );if (ret) goto out;
@@ -4045,7 +4057,8 @@ static void update_mod_cache(struct trace_array *tr, struct module *mod)__ftrace_set_clr_event_nolock (tr, event_mod->match, event_mod->system, - event_mod->event,1 , mod->name); + event_mod->event,1 , mod->name, + event_mod->filter);free_event_mod (event_mod); } }
@@ -4819,7 +4832,7 @@ int event_trace_del_tracer(struct trace_array *tr)__ftrace_clear_event_pids (tr,TRACE_PIDS |TRACE_NO_PIDS );/* Disable any running events */ -__ftrace_set_clr_event_nolock (tr,NULL ,NULL ,NULL ,0 ,NULL ); +__ftrace_set_clr_event_nolock (tr,NULL ,NULL ,NULL ,0 ,NULL ,NULL );/* Make sure no more events are being executed */ tracepoint_synchronize_unregister ();
@@ -5129,7 +5142,7 @@ static __init void event_trace_self_tests(void)pr_info ("Testing event system %s: " , system->name); - ret =__ftrace_set_clr_event (tr,NULL , system->name,NULL ,1 ,NULL ); + ret =__ftrace_set_clr_event (tr,NULL , system->name,NULL ,1 ,NULL ,NULL );if (WARN_ON_ONCE (ret)) {pr_warn ("error enabling system %s\n" , system->name);
@@ -5138,7 +5151,7 @@ static __init void event_trace_self_tests(void)event_test_stuff (); - ret =__ftrace_set_clr_event (tr,NULL , system->name,NULL ,0 ,NULL ); + ret =__ftrace_set_clr_event (tr,NULL , system->name,NULL ,0 ,NULL ,NULL );if (WARN_ON_ONCE (ret)) {pr_warn ("error disabling system %s\n" , system->name);
@@ -5153,7 +5166,7 @@ static __init void event_trace_self_tests(void)pr_info ("Running tests on all trace events:\n" );pr_info ("Testing all events: " ); - ret =__ftrace_set_clr_event (tr,NULL ,NULL ,NULL ,1 ,NULL ); + ret =__ftrace_set_clr_event (tr,NULL ,NULL ,NULL ,1 ,NULL ,NULL );if (WARN_ON_ONCE (ret)) {pr_warn ("error enabling all events\n" );return ;
@@ -5162,7 +5175,7 @@ static __init void event_trace_self_tests(void)event_test_stuff ();/* reset sysname */ - ret =__ftrace_set_clr_event (tr,NULL ,NULL ,NULL ,0 ,NULL ); + ret =__ftrace_set_clr_event (tr,NULL ,NULL ,NULL ,0 ,NULL ,NULL );if (WARN_ON_ONCE (ret)) {pr_warn ("error disabling all events\n" );return ;
Signature · 1 line
2.53.0
PATCH 8/18 tracing: Parse filter from boot event string
In reply to Steven RostedtFrom: =?UTF-8?q?Thomas=20Wei=C3=9Fschuh?= <[email protected]>
Make it possible to specify a trace event filter from the kernel command line.
Example:
trace_event=syscalls:sys_enter_clock_nanosleep:filter:which_clock==0
--- .../admin-guide/kernel-parameters.txt | 9 +++++-- Documentation/trace/events.rst | 5 ++++ include/linux/trace_events.h | 2 +- kernel/trace/trace.h | 3 ++- kernel/trace/trace_boot.c | 2 +- kernel/trace/trace_events.c | 27 +++++++++++++------ kernel/trace/trace_events_test.c | 26 +++++++++++++++--- 7 files changed, 58 insertions(+), 16 deletions(-)
Documentation/admin-guide/kernel-parameters.txt +7 -2
@@ -7733,8 +7733,13 @@ Kernel parameters trace_event=:mod:<module> The value before :mod: will only enable specific events - that are part of the module. See the above mentioned - document for more information. + that are part of the module. + + To apply a filter, use the :filter: keyword: + + trace_event=...:filter:<filter> + + See the above mentioned document for more information. trace_instance=[instance-info] [FTRACE] Create a ring buffer instance early in boot up.
Documentation/trace/events.rst +5 -0
@@ -118,6 +118,11 @@ In order to facilitate early boot debugging, use boot option:: event-list is a comma separated list of events. See section 2.1 for event format. +The boot option also supports the ``:filter:`` keyword to apply a filter. +The ``:filter:`` keyword needs to be at the end of the event specification:: + + <system>:<event>:mod:<module>:filter:<filter> + 3. Defining an event-enabled tracepoint =======================================
include/linux/trace_events.h +1 -1
@@ -883,7 +883,7 @@ extern int trace_add_event_call(struct trace_event_call *call);extern int trace_remove_event_call (struct trace_event_call *call);extern int trace_event_get_offsets (struct trace_event_call *call); -int ftrace_set_clr_event (struct trace_array *tr,const char *buf,int set); +int ftrace_set_clr_event (struct trace_array *tr,const char *buf,int set,bool handle_filter);int trace_set_clr_event (const char *system,const char *event,int set);int trace_array_set_clr_event (struct trace_array *tr,const char *system,const char *event,bool enable);
kernel/trace/trace.h +2 -1
@@ -2511,5 +2511,6 @@ static inline int rv_init_interface(void)#endif /* _LINUX_KERNEL_TRACE_H */ #if IS_ENABLED (CONFIG_KUNIT ) -void ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod); +void ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod, +bool handle_filter,char **filter);#endif
kernel/trace/trace_boot.c +1 -1
@@ -94,7 +94,7 @@ trace_boot_enable_events(struct trace_array *tr, struct xbc_node *node)continue ; } -if (ftrace_set_clr_event (tr, buf,1 ) <0 ) +if (ftrace_set_clr_event (tr, buf,1 , false) <0 )pr_err ("Failed to enable event: %s\n" , p); } }
kernel/trace/trace_events.c +19 -8
@@ -1458,10 +1458,21 @@ static int __ftrace_set_clr_event(struct trace_array *tr, const char *match, } VISIBLE_IF_KUNIT void -ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod) +ftrace_parse_event_string (char *buf,char **match,char **sub,char **event,char **mod, +bool handle_filter,char **filter) { *event =NULL ; *sub =NULL ; + *filter =NULL ; + +/* event filters can be appended with :filter:<filter> */ +if (handle_filter) { + *filter =strstr (buf,":filter:" ); +if (*filter) { + **filter ='\0' ; + *filter +=8 ; + } + }/* Modules events can be appended with :mod:<module> */ *mod =strstr (buf,":mod:" );
@@ -1501,9 +1512,9 @@ ftrace_parse_event_string(char *buf, char **match, char **sub, char **event, cha }EXPORT_SYMBOL_IF_KUNIT (ftrace_parse_event_string); -int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set) +int ftrace_set_clr_event (struct trace_array *tr,const char *arg_buf,int set,bool handle_filter) { -char *event, *sub, *match, *mod; +char *event, *sub, *match, *mod, *filter;if (!tr)return -ENOENT ;
@@ -1512,9 +1523,9 @@ int ftrace_set_clr_event(struct trace_array *tr, const char *arg_buf, int set)if (!dupped_buf)return -ENOMEM ; -ftrace_parse_event_string (dupped_buf, &match, &sub, &event, &mod); +ftrace_parse_event_string (dupped_buf, &match, &sub, &event, &mod, handle_filter, &filter); -return __ftrace_set_clr_event (tr, match, sub, event, set, mod,NULL ); +return __ftrace_set_clr_event (tr, match, sub, event, set, mod, filter); }/**
@@ -1596,7 +1607,7 @@ ftrace_event_write(struct file *file, const char __user *ubuf,if (*parser.buffer =='!' ) set =0 ; - ret =ftrace_set_clr_event (tr, parser.buffer + !set, set); + ret =ftrace_set_clr_event (tr, parser.buffer + !set, set, false);if (ret) goto out_put; }
@@ -4865,10 +4876,10 @@ static __init void __early_set_events(struct trace_array *tr, char *buf, bool enwhile ((token =strsep (&buf,"," ))) {if (*token) {if (enable) { -if (ftrace_set_clr_event (tr, token,1 )) +if (ftrace_set_clr_event (tr, token,1 , true))pr_warn ("Failed to enable trace event: %s\n" , token); }else { -ftrace_set_clr_event (tr, token,0 ); +ftrace_set_clr_event (tr, token,0 , true); } }
kernel/trace/trace_events_test.c +23 -3
@@ -8,7 +8,7 @@struct parse_event_string_test_case {const char *input; -const char *match, *sub, *event, *mod; +const char *match, *sub, *event, *mod, *filter; };static const struct parse_event_string_test_case parse_event_string_test_cases[] = {
@@ -37,6 +37,12 @@ static const struct parse_event_string_test_case parse_event_string_test_cases[] .sub = "sub", .event = "event", }, + { + "sub:event:filter:filter", + .sub = "sub", + .event = "event", + .filter ="filter" , + }, {"match" , .match = "match",
@@ -51,6 +57,19 @@ static const struct parse_event_string_test_case parse_event_string_test_cases[] .event = "event", .mod = "module", }, + { + "sub:event:mod:module:filter:filter", + .sub = "sub", + .event = "event", + .mod = "module", + .filter ="filter" , + }, + { +"sub:event:mod:module:filter:unexpected-filter" , + .sub = "sub", + .event = "event", + .mod = "module:filter:unexpected-filter", + }, }; static void
@@ -72,18 +91,19 @@ KUNIT_ARRAY_PARAM(parse_event_string, parse_event_string_test_cases, parse_eventstatic void parse_event_string (struct kunit *test) {const struct parse_event_string_test_case *params = test->param_value; -char *input, *match, *sub, *event, *mod; +char *input, *match, *sub, *event, *mod, *filter; input =kunit_kstrdup (test, params->input,GFP_KERNEL );if (!input)kunit_skip (test,"ENOMEM" ); -ftrace_parse_event_string (input, &match, &sub, &event, &mod); +ftrace_parse_event_string (input, &match, &sub, &event, &mod, params->filter, &filter);EXPECT_NULL_OR_STR_EQ (test, match, params->match);EXPECT_NULL_OR_STR_EQ (test, sub, params->sub);EXPECT_NULL_OR_STR_EQ (test, event, params->event);EXPECT_NULL_OR_STR_EQ (test, mod, params->mod); +EXPECT_NULL_OR_STR_EQ (test, filter, params->filter); }static struct kunit_case trace_events_test_cases[] = {
Signature · 1 line
2.53.0
PATCH 9/18 ring-buffer: Rename ring_buffer_size() to ring_buffer_capacity()
In reply to Steven RostedtFrom: Vincent Donnefort <[email protected]>
Since commit 8a5f63637890 ("ring-buffer: Fix subbuf resize race with ring buffer readers"), "capacity" refers to the memory available for events (excluding subbuffer headers) while "size" refers to the raw allocation. ring_buffer_size() actually calculates this event capacity. Rename it to ring_buffer_capacity() to align with this convention.
--- include/linux/ring_buffer.h | 2 +- kernel/trace/ring_buffer.c | 13 +++++++++---- kernel/trace/trace.c | 6 +++--- 3 files changed, 13 insertions(+), 8 deletions(-)
include/linux/ring_buffer.h +1 -1
@@ -166,7 +166,7 @@ void ring_buffer_iter_reset(struct ring_buffer_iter *iter);int ring_buffer_iter_empty (struct ring_buffer_iter *iter);bool ring_buffer_iter_dropped (struct ring_buffer_iter *iter); -unsigned long ring_buffer_size (struct trace_buffer *buffer,int cpu); +unsigned long ring_buffer_capacity (struct trace_buffer *buffer,int cpu);unsigned long ring_buffer_max_event_size (struct trace_buffer *buffer);void ring_buffer_reset_cpu (struct trace_buffer *buffer,int cpu);
kernel/trace/ring_buffer.c +9 -4
@@ -6546,18 +6546,23 @@ void ring_buffer_iter_advance(struct ring_buffer_iter *iter)EXPORT_SYMBOL_GPL (ring_buffer_iter_advance);/** -* ring_buffer_size - return the size of the ring buffer (in bytes) +* ring_buffer_capacity - return the capacity of the ring buffer (in bytes) * @buffer: The ring buffer. -* @cpu: The CPU to get ring buffer size from. +* @cpu: The CPU to get ring buffer capacity from. +* +* Capacity is the total memory available for recording event data in the +* ring buffer. It excludes subbuffer headers. +* +* Returns the capacity in bytes, or 0 if the CPU is not set in the buffer mask. */ -unsigned long ring_buffer_size (struct trace_buffer *buffer,int cpu) +unsigned long ring_buffer_capacity (struct trace_buffer *buffer,int cpu) {if (!cpumask_test_cpu (cpu, buffer->cpumask))return 0 ;return rb_subbuf_capacity (buffer) * buffer->buffers[cpu]->nr_pages; } -EXPORT_SYMBOL_GPL (ring_buffer_size); +EXPORT_SYMBOL_GPL (ring_buffer_capacity);/** * ring_buffer_max_event_size - return the max data size of an event
kernel/trace/trace.c +3 -3
@@ -4712,9 +4712,9 @@ void trace_set_buffer_entries(struct array_buffer *buf, unsigned long val)static void update_buffer_entries (struct array_buffer *buf,int cpu) {if (cpu ==RING_BUFFER_ALL_CPUS ) { -trace_set_buffer_entries (buf,ring_buffer_size (buf->buffer,0 )); +trace_set_buffer_entries (buf,ring_buffer_capacity (buf->buffer,0 )); }else { -per_cpu_ptr (buf->data, cpu)->entries =ring_buffer_size (buf->buffer, cpu); +per_cpu_ptr (buf->data, cpu)->entries =ring_buffer_capacity (buf->buffer, cpu); } }
@@ -8520,7 +8520,7 @@ int allocate_trace_buffer(struct trace_array *tr, struct array_buffer *buf, int/* Allocate the first page for all buffers */ trace_set_buffer_entries (&tr->array_buffer, -ring_buffer_size (tr->array_buffer.buffer,0 )); +ring_buffer_capacity (tr->array_buffer.buffer,0 ));return 0 ; }
Signature · 1 line
2.53.0
PATCH 10/18 tracing: Rename trace_array::entries to capacity
In reply to Steven RostedtFrom: Vincent Donnefort <[email protected]>
Since commit 8a5f63637890 ("ring-buffer: Fix subbuf resize race with ring buffer readers"), "capacity" refers to the memory available for events, while "entries" refers to the number of events in a ring buffer. As a consequence, rename trace_array::entries to capacity to align with this convention and avoid any confusion.
Rename also the helper functions trace_set_buffer_entries and update_buffer_entries.
--- kernel/trace/trace.c | 26 +++++++++++++------------- kernel/trace/trace.h | 4 ++-- kernel/trace/trace_snapshot.c | 14 +++++++------- 3 files changed, 22 insertions(+), 22 deletions(-)
kernel/trace/trace.c +13 -13
@@ -4701,20 +4701,20 @@ int tracer_init(struct tracer *t, struct trace_array *tr)return t->init (tr); } -void trace_set_buffer_entries (struct array_buffer *buf,unsigned long val) +void trace_set_buffer_capacity (struct array_buffer *buf,unsigned long val) {int cpu;for_each_tracing_cpu (cpu) -per_cpu_ptr (buf->data, cpu)->entries = val; +per_cpu_ptr (buf->data, cpu)->capacity = val; } -static void update_buffer_entries (struct array_buffer *buf,int cpu) +static void update_buffer_capacity (struct array_buffer *buf,int cpu) {if (cpu ==RING_BUFFER_ALL_CPUS ) { -trace_set_buffer_entries (buf,ring_buffer_capacity (buf->buffer,0 )); +trace_set_buffer_capacity (buf,ring_buffer_capacity (buf->buffer,0 )); }else { -per_cpu_ptr (buf->data, cpu)->entries =ring_buffer_capacity (buf->buffer, cpu); +per_cpu_ptr (buf->data, cpu)->capacity =ring_buffer_capacity (buf->buffer, cpu); } }
@@ -4770,12 +4770,12 @@ static int __tracing_resize_ring_buffer(struct trace_array *tr, goto out_start; } -update_buffer_entries (&tr->snapshot_buffer, cpu); +update_buffer_capacity (&tr->snapshot_buffer, cpu); out:#endif /* CONFIG_TRACER_SNAPSHOT */ -update_buffer_entries (&tr->array_buffer, cpu); +update_buffer_capacity (&tr->array_buffer, cpu); out_start:tracing_start_tr (tr);return ret;
@@ -5694,8 +5694,8 @@ tracing_entries_read(struct file *filp, char __user *ubuf,for_each_tracing_cpu (cpu) {/* fill in the size from first enabled cpu */ if (size ==0 ) - size =per_cpu_ptr (tr->array_buffer.data, cpu)->entries; -if (size !=per_cpu_ptr (tr->array_buffer.data, cpu)->entries) { + size =per_cpu_ptr (tr->array_buffer.data, cpu)->capacity; +if (size !=per_cpu_ptr (tr->array_buffer.data, cpu)->capacity) { buf_size_same =0 ;break ; }
@@ -5711,7 +5711,7 @@ tracing_entries_read(struct file *filp, char __user *ubuf, }else r =sprintf (buf,"X\n" ); }else - r =sprintf (buf,"%lu\n" ,per_cpu_ptr (tr->array_buffer.data, cpu)->entries >>10 ); + r =sprintf (buf,"%lu\n" ,per_cpu_ptr (tr->array_buffer.data, cpu)->capacity >>10 );mutex_unlock (&trace_types_lock);
@@ -5758,7 +5758,7 @@ tracing_total_entries_read(struct file *filp, char __user *ubuf,mutex_lock (&trace_types_lock);for_each_tracing_cpu (cpu) { - size +=per_cpu_ptr (tr->array_buffer.data, cpu)->entries >>10 ; + size +=per_cpu_ptr (tr->array_buffer.data, cpu)->capacity >>10 ;if (!tr->ring_buffer_expanded) expanded_size += trace_buf_size >>10 ; }
@@ -8519,8 +8519,8 @@ int allocate_trace_buffer(struct trace_array *tr, struct array_buffer *buf, int }/* Allocate the first page for all buffers */ -trace_set_buffer_entries (&tr->array_buffer, -ring_buffer_capacity (tr->array_buffer.buffer,0 )); +trace_set_buffer_capacity (&tr->array_buffer, +ring_buffer_capacity (tr->array_buffer.buffer,0 ));return 0 ; }
kernel/trace/trace.h +2 -2
@@ -191,7 +191,7 @@ struct trace_array;struct trace_array_cpu {local_t disabled; -unsigned long entries; +unsigned long capacity;unsigned long saved_latency;unsigned long critical_start;unsigned long critical_end;
@@ -731,7 +731,7 @@ ssize_t tracing_nsecs_read(unsigned long *ptr, char __user *ubuf,ssize_t tracing_nsecs_write (unsigned long *ptr,const char __user *ubuf,size_t cnt,loff_t *ppos); -void trace_set_buffer_entries (struct array_buffer *buf,unsigned long val); +void trace_set_buffer_capacity (struct array_buffer *buf,unsigned long val);/* * Should be used after trace_array_get(), trace_types_lock
kernel/trace/trace_snapshot.c +7 -7
@@ -142,18 +142,18 @@ int resize_buffer_duplicate_size(struct array_buffer *trace_buf,if (cpu_id ==RING_BUFFER_ALL_CPUS ) {for_each_tracing_cpu (cpu) { ret =ring_buffer_resize (trace_buf->buffer, -per_cpu_ptr (size_buf->data, cpu)->entries, cpu); +per_cpu_ptr (size_buf->data, cpu)->capacity, cpu);if (ret <0 )break ; -per_cpu_ptr (trace_buf->data, cpu)->entries = -per_cpu_ptr (size_buf->data, cpu)->entries; +per_cpu_ptr (trace_buf->data, cpu)->capacity = +per_cpu_ptr (size_buf->data, cpu)->capacity; } }else { ret =ring_buffer_resize (trace_buf->buffer, -per_cpu_ptr (size_buf->data, cpu_id)->entries, cpu_id); +per_cpu_ptr (size_buf->data, cpu_id)->capacity, cpu_id);if (ret ==0 ) -per_cpu_ptr (trace_buf->data, cpu_id)->entries = -per_cpu_ptr (size_buf->data, cpu_id)->entries; +per_cpu_ptr (trace_buf->data, cpu_id)->capacity = +per_cpu_ptr (size_buf->data, cpu_id)->capacity; }return ret;
@@ -193,7 +193,7 @@ void free_snapshot(struct trace_array *tr)*/ ring_buffer_subbuf_order_set (tr->snapshot_buffer.buffer,0 );ring_buffer_resize (tr->snapshot_buffer.buffer,1 ,RING_BUFFER_ALL_CPUS ); -trace_set_buffer_entries (&tr->snapshot_buffer,1 ); +trace_set_buffer_capacity (&tr->snapshot_buffer,1 );tracing_reset_online_cpus (&tr->snapshot_buffer); tr->allocated_snapshot = false; }
Signature · 1 line
2.53.0
PATCH 11/18 tracing: Rename tracing_entries_fops to tracing_capacity_fops
In reply to Steven RostedtFrom: Vincent Donnefort <[email protected]>
Since commit 8a5f63637890 ("ring-buffer: Fix subbuf resize race with ring buffer readers"), "capacity" refers to the memory available for events, while "entries" refers to the number of events in a ring buffer. As a consequence, rename trace_array::entries to capacity to align with this convention.
While at it, rename also tracing_total_entries_fops. It is the aggragate of all ring buffer capacities.
--- kernel/trace/trace.c | 25 +++++++++++-------------- 1 file changed, 11 insertions(+), 14 deletions(-)
kernel/trace/trace.c +11 -14
@@ -5672,8 +5672,7 @@ tracing_syscall_buf_write(struct file *filp, const char __user *ubuf, }static ssize_t -tracing_entries_read (struct file *filp,char __user *ubuf, -size_t cnt,loff_t *ppos) +tracing_capacity_read (struct file *filp,char __user *ubuf,size_t cnt,loff_t *ppos) {struct inode *inode =file_inode (filp);struct trace_array *tr = inode->i_private;
@@ -5720,8 +5719,7 @@ tracing_entries_read(struct file *filp, char __user *ubuf, }static ssize_t -tracing_entries_write (struct file *filp,const char __user *ubuf, -size_t cnt,loff_t *ppos) +tracing_capacity_write (struct file *filp,const char __user *ubuf,size_t cnt,loff_t *ppos) {struct inode *inode =file_inode (filp);struct trace_array *tr = inode->i_private;
@@ -5748,8 +5746,7 @@ tracing_entries_write(struct file *filp, const char __user *ubuf, }static ssize_t -tracing_total_entries_read (struct file *filp,char __user *ubuf, -size_t cnt,loff_t *ppos) +tracing_total_capacity_read (struct file *filp,char __user *ubuf,size_t cnt,loff_t *ppos) {struct trace_array *tr = filp->private_data;char buf[64 ];
@@ -6600,10 +6597,10 @@ static const struct file_operations tracing_pipe_fops = { .release = tracing_release_pipe, }; -static const struct file_operations tracing_entries_fops = { +static const struct file_operations tracing_capacity_fops = { .open = tracing_open_generic_tr, - .read = tracing_entries_read, - .write = tracing_entries_write, + .read = tracing_capacity_read, + .write = tracing_capacity_write, .llseek = generic_file_llseek, .release = tracing_release_generic_tr, };
@@ -6623,9 +6620,9 @@ static const struct file_operations tracing_buffer_meta_fops = { .release = tracing_seq_release, }; -static const struct file_operations tracing_total_entries_fops = { +static const struct file_operations tracing_total_capacity_fops = { .open = tracing_open_generic_tr, - .read = tracing_total_entries_read, + .read = tracing_total_capacity_read, .llseek = generic_file_llseek, .release = tracing_release_generic_tr, };
@@ -7653,7 +7650,7 @@ tracing_init_tracefs_percpu(struct trace_array *tr, long cpu) tr, cpu, &tracing_stats_fops);trace_create_cpu_file ("buffer_size_kb" ,TRACE_MODE_WRITE , d_cpu, - tr, cpu, &tracing_entries_fops); + tr, cpu, &tracing_capacity_fops);if (tr->range_addr_start) trace_create_cpu_file("buffer_meta", TRACE_MODE_READ, d_cpu,
@@ -8998,10 +8995,10 @@ init_tracer_tracefs(struct trace_array *tr, struct dentry *d_tracer) tr, &tracing_pipe_fops);trace_create_file ("buffer_size_kb" , writable_mode, d_tracer, - tr, &tracing_entries_fops); + tr, &tracing_capacity_fops);trace_create_file ("buffer_total_size_kb" ,TRACE_MODE_READ , d_tracer, - tr, &tracing_total_entries_fops); + tr, &tracing_total_capacity_fops);trace_create_file ("trace_clock" , writable_mode, d_tracer, tr, &trace_clock_fops);
Signature · 1 line
2.53.0
PATCH 12/18 tracing: Print the bucket size as unsigned
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
A key's bucket size reads back negative once it exceeds LONG_MAX:
# echo 'hist:keys=next_pid.buckets=18446744073709551615' > trigger # cat trigger hist:keys=next_pid.buckets=-1:vals=hitcount:...
parse_field() takes the size with kstrtoul() and rejects only zero, so the whole unsigned long range is accepted and stored, but hist_field_print() renders it with %ld.
Print it with %lu.
--- kernel/trace/trace_events_hist.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/trace_events_hist.c +1 -1
@@ -6200,7 +6200,7 @@ static void hist_field_print(struct seq_file *m, struct hist_field *hist_field) } }if (hist_field->buckets) -seq_printf (m,"=%ld" , hist_field->buckets); +seq_printf (m,"=%lu" , hist_field->buckets); } static int event_hist_trigger_print(struct seq_file *m,
Signature · 1 line
2.53.0
PATCH 13/18 tracing: Add the bucket size to expr_field_str()
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
expr_field_str() renders a HIST_FIELD_FL_BUCKET field as "pid.buckets", dropping the count, and parse_field() rejects that spelling.
get_hist_field_flags() returns the bare string "buckets" and keeps the count in hist_field->buckets. hist_field_print() appends it, expr_field_str() never did. Nothing reaches it today, since .buckets is refused on a value and no expression can carry one, but the next patch renders histogram keys with expr_field_str(), where a .buckets key is legal.
Append the count, as hist_field_print() does.
--- kernel/trace/trace_events_hist.c | 3 +++ 1 file changed, 3 insertions(+)
kernel/trace/trace_events_hist.c +3 -0
@@ -1754,6 +1754,9 @@ static bool expr_field_str(struct hist_field *field, struct seq_buf *s)seq_buf_printf (s,".%s" , flags_str); } +if (field->buckets) +seq_buf_printf (s,"=%lu" , field->buckets); +return !seq_buf_has_overflowed (s); }
Signature · 1 line
2.53.0
PATCH 14/18 tracing: Only report the stacktrace modifier on a real field
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
get_hist_field_flags() returns "stacktrace" for any field carrying HIST_FIELD_FL_STACKTRACE, including the common_stacktrace pseudo-field, which has no ftrace_event_field behind it. parse_field() no longer takes the modifier there:
if (stack_modifier &&
(!field || field->filter_type != FILTER_STACKTRACE)) {
hist_err(tr, HIST_ERR_BAD_FIELD_MODIFIER, errpos(field_str));so expr_field_str() renders "common_stacktrace.stacktrace", a spelling that cannot be parsed back.
Report the modifier only when there is a field to report it for.
hist_field_print(), the other caller of get_hist_field_flags(), excludes HIST_FIELD_FL_STACKTRACE before it calls, so this is confined to expr_field_str(), whose only key renderer arrives in the next patch.
--- kernel/trace/trace_events_hist.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/trace_events_hist.c +1 -1
@@ -1725,7 +1725,7 @@ static const char *get_hist_field_flags(struct hist_field *hist_field) flags_str ="percent" ; else if (hist_field->flags & HIST_FIELD_FL_GRAPH) flags_str ="graph" ; - else if (hist_field->flags & HIST_FIELD_FL_STACKTRACE) + else if (hist_field->flags & HIST_FIELD_FL_STACKTRACE && hist_field->field) flags_str ="stacktrace" ;return flags_str;
Signature · 1 line
2.53.0
PATCH 15/18 tracing: Unregister field variable histograms when the command fails
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
An action that names a field on another event needs that field as a variable, so create_field_var_hist() registers a second hist trigger on that event to provide it, and records it in target_hist_data->field_var_hists[].
If a later part of the same command fails, create_actions() returns an error and event_hist_trigger_parse() jumps to out_free. The write fails with -EINVAL and sched_switch gets no trigger, but:
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> \
events/sched/sched_waking/trigger
# echo 'my_synth u64 lat; int a; int b' >> synthetic_events
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
onmatch(sched.sched_waking).my_synth($wakeup_lat,prio,nosuchfld)'\
>> events/sched/sched_switch/trigger
# cat events/sched/sched_waking/trigger
hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
hist:keys=pid:vals=hitcount:synthetic_prio=prio:sort=hitcount:size=2048 [active]The second histogram is the one created for 'prio'. It is still active and still counting.
out_free reaches destroy_field_var_hists(), which frees the field_var_hists[] entries, but never unregister_field_var_hists(), which is what removes the triggers and runs only from event_hist_trigger_free(). The entry is freed and the trigger is left with nothing tracking it.
Unregister the field variable histograms in out_free as well, and record each one as soon as its trigger is registered rather than after the lookup that follows it, so no exit can leave a registered trigger untracked. The entry then belongs to field_var_hists[] and is released by destroy_field_var_hists(), so freeing it on that exit would be a double free.
--- kernel/trace/trace_events_hist.c | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-)
kernel/trace/trace_events_hist.c +6 -6
@@ -3137,20 +3137,18 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data,kfree (cmd); + n = target_hist_data->n_field_var_hists; + target_hist_data->field_var_hists[n] = var_hist; + target_hist_data->n_field_var_hists++; +/* If we can't find the variable, something went wrong */ event_var =find_synthetic_field_var (target_hist_data, subsys_name, event_name, field_name);if (IS_ERR_OR_NULL (event_var)) { -kfree (var_hist->cmd); -kfree (var_hist);hist_err (tr,HIST_ERR_SYNTH_VAR_NOT_FOUND ,errpos (field_name));return ERR_PTR (-EINVAL ); } - n = target_hist_data->n_field_var_hists; - target_hist_data->field_var_hists[n] = var_hist; - target_hist_data->n_field_var_hists++; -return event_var; }
@@ -6983,6 +6981,8 @@ static int event_hist_trigger_parse(struct event_command *cmd_ops,trigger_data_free (trigger_data); +unregister_field_var_hists (hist_data); +destroy_hist_data (hist_data); goto out; }
Signature · 1 line
2.53.0
PATCH 16/18 tracing: Clamp the printed end of a histogram bucket at U64_MAX
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
A key with the ".buckets=N" modifier is stored as the start of its bucket, and hist_trigger_print_key() prints the range it covers as start to start + N - 1. That addition overflows once the start is within N of U64_MAX:
# echo 'hist:keys=offset.buckets=10' >> \
events/syscalls/sys_enter_lseek/trigger
# ./seeker 5 -1 # lseek(0, 5) and lseek(0, -1)
# cat events/syscalls/sys_enter_lseek/hist
...
{ offset: ~ 18446744073709551610-3 } hitcount: 1
{ offset: ~ 0-9 } hitcount: 1
...18446744073709551610 + 10 - 1 does not fit in 64 bits, so the range ends below where it starts.
The bucket does end at U64_MAX: it holds every value hist_field_bucket() maps onto its start, and there is no value above U64_MAX. Clamp the printed end there. Printed honestly the group is shorter than the size asked for, which histogram.rst does not mention, so say it there.
--- Documentation/trace/histogram.rst | 3 +++ kernel/trace/trace_events_hist.c | 7 ++++++- 2 files changed, 9 insertions(+), 1 deletion(-)
Documentation/trace/histogram.rst +3 -0
@@ -1943,6 +1943,9 @@ the ".buckets" modifier and specify a size (in this case groups of 10):: Entries: 16 Dropped: 0 +Keys are 64-bit, so the group holding the largest values is truncated where +that range ends and can be smaller than the size asked for. + To save stacktraces, create a synthetic event with a field of type "unsigned long[]" or even just "long[]". For example, to see how long a task is blocked in an uninterruptible state::
kernel/trace/trace_events_hist.c +6 -1
@@ -5561,9 +5561,14 @@ static void hist_trigger_print_key(struct seq_file *m, *(u64 *)(key + key_field->offset)); }else if (key_field->flags &HIST_FIELD_FL_BUCKET ) {unsigned long buckets = key_field->buckets; +u64 end; + uval = *(u64 *)(key + key_field->offset); + end = uval + buckets -1 ; +if (end < uval) + end =U64_MAX ;seq_printf (m,"%s: ~ %llu-%llu" , field_name, - uval, uval + buckets -1 ); + uval, end); }else if (key_field->flags &HIST_FIELD_FL_STRING ) {seq_printf (m,"%s: %-50s" , field_name, (char *)(key + key_field->offset));
Signature · 1 line
2.53.0
PATCH 17/18 tracing: Fix 64-bit and signed histogram fields on 32-bit kernels
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
DEFINE_HIST_FIELD_FN() reads a trace event field and widens it to the u64 the histogram uses as a key or a value:
type *addr = (type *)(event + hist_field->field->offset); return (u64)(unsigned long)*addr;
unsigned long is 32 bits on a 32-bit kernel, so the intermediate cast discards the upper half of a 64-bit field, and widens a signed field by zero extension from 32 bits rather than sign extension from its own width. Five of the eight instantiations are wrong there: s64, u64, s32, s16 and s8.
The cast came in with commit 79e577cbce4c ("tracing: Support string type key properly"), which also added hist_field_dynstring() and hist_field_pstring(). Those convert a char * to u64 and do warn without an unsigned long in between on 32-bit. DEFINE_HIST_FIELD_FN() converts an integer and never a pointer, so it gains nothing from the cast and only loses information.
Drop the intermediate cast and let the usual arithmetic conversions widen *addr according to its own type. unsigned long is 64 bits on LP64, so the two forms are identical there and 64-bit kernels are unaffected.
--- kernel/trace/trace_events_hist.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/trace_events_hist.c +1 -1
@@ -466,7 +466,7 @@ static u64 hist_field_unary_minus(struct hist_field *hist_field, { \type *addr = (type *)(event + hist_field->field->offset); \ \ -return (u64 )(unsigned long )*addr; \ +return (u64)*addr; \ }DEFINE_HIST_FIELD_FN (s64);
Signature · 1 line
2.53.0
PATCH 18/18 tracing: Print a signed histogram key as signed
In reply to Steven RostedtFrom: Donggeun Yoo <[email protected]>
A histogram sorts its rows by the key named in sort=, and for a key over a signed event field it sorts them signed: create_tracing_map_fields() picks the comparison function with
else cmp_fn = tracing_map_cmp_num(field->size, field->is_signed);
hist_trigger_print_key() does not look at is_signed at all. Every numeric key is printed with %llu, so a sorted histogram over a signed field comes out looking unsorted. syscalls/sys_exit_lseek carries "long ret", which SYSCALL_FIELD() marks signed and which is negative on every error:
# echo 'hist:keys=ret:sort=ret' > events/syscalls/sys_exit_lseek/trigger # echo 1 > events/syscalls/sys_exit_lseek/enable # (five lseek(2) calls returning -ESPIPE, -EINVAL, -EBADF, 0 and 100) # cat events/syscalls/sys_exit_lseek/hist
{ ret: 18446744073709551587 } hitcount: 1
{ ret: 18446744073709551594 } hitcount: 1
{ ret: 18446744073709551607 } hitcount: 1 { ret: 0 } hitcount: 1
{ ret: 100 } hitcount: 1
The rows are in ascending order and the numbers are not, because the three leading ones are -29, -22 and -9 rendered as their two's complement.
Take the rendering from the same place the sort order comes from: the event field when the key has one, and the hist_field itself when it does not. The same histogram then reads
{ ret: -29 } hitcount: 1
{ ret: -22 } hitcount: 1
{ ret: -9 } hitcount: 1
{ ret: 0 } hitcount: 1
{ ret: 100 } hitcount: 1A ".buckets" key stays unsigned here, and not because it is right. hist_field_bucket() divides as unsigned, so the group holding S64_MAX also holds S64_MIN, reported at
https://lore.kernel.org/all/[email protected]/
Printing that group signed would name a range that does not contain S64_MIN, so the grouping has to be fixed with it, in a patch of its own.
--- kernel/trace/trace_events_hist.c | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-)
kernel/trace/trace_events_hist.c +13 -1
@@ -279,6 +279,14 @@ static u64 hist_field_pstring(struct hist_field *hist_field,return (u64 )(unsigned long )*addr; } +static bool hist_field_is_signed (struct hist_field *hist_field) +{ +if (hist_field->field) +return hist_field->field->is_signed; + +return hist_field->is_signed; +} + static u64 hist_field_log2(struct hist_field *hist_field, struct tracing_map_elt *elt, struct trace_buffer *buffer,
@@ -5574,7 +5582,11 @@ static void hist_trigger_print_key(struct seq_file *m, (char *)(key + key_field->offset)); }else { uval = *(u64 *)(key + key_field->offset); -seq_printf (m,"%s: %10llu" , field_name, uval); +if (hist_field_is_signed (key_field)) +seq_printf (m,"%s: %10lld" , field_name, + (s64 )uval); +else +seq_printf (m,"%s: %10llu" , field_name, uval); } }
Signature · 1 line
2.53.0