* [PATCH 0/5] tracing: Synthetic event dynamic string fixes
@ 2020-10-09 15:17 Tom Zanussi
2020-10-09 15:17 ` [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi
` (6 more replies)
0 siblings, 7 replies; 17+ messages in thread
From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw)
To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel
These patches provide fixes for the problems observed by Masami in the
new synthetic event dynamic string patchset.
The first patch (tracing: Don't show dynamic string internals in
synthetic event description) removes the __data_loc from the event
description but leaves it in the format.
The patch (tracing: Add synthetic event error logging) addresses the
lack of error messages when parse errors occur.
The remaining three patches address the other problems Masami noted
which result from allowing illegal characters in synthetic event and
field names when defining an event. The is_good_name() function is
used to check that's not possible for the probe events, but should
also be used for the synthetic events as well.
(tracing: Move is_good_name() from trace_probe.h to trace.h) makes
that function available to other trace subsystems by putting it in
trace.h. (tracing: Check that the synthetic event and field names are
legal) applies it to the synthetic events, and (selftests/ftrace:
Change synthetic event name for inter-event-combined test) changes a
testcase that now fails because it uses an illegal name.
The following changes since commit 848183553e431e6e9c2ea2f72421a7a1bbc6532e:
tracing: Fix synthetic print fmt check for use of __get_str() (2020-10-08 15:29:07 -0400)
are available in the Git repository at:
git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/dynstring-fixes-v1
Tom Zanussi (5):
tracing: Don't show dynamic string internals in synthetic event
description
tracing: Move is_good_name() from trace_probe.h to trace.h
tracing: Check that the synthetic event and field names are legal
tracing: Add synthetic event error logging
selftests/ftrace: Change synthetic event name for inter-event-combined
test
kernel/trace/trace.h | 13 ++
kernel/trace/trace_events_synth.c | 133 +++++++++++++++++-
kernel/trace/trace_probe.h | 13 --
.../trigger-inter-event-combined-hist.tc | 8 +-
4 files changed, 147 insertions(+), 20 deletions(-)
--
2.17.1
^ permalink raw reply [flat|nested] 17+ messages in thread* [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi @ 2020-10-09 15:17 ` Tom Zanussi 2020-10-10 15:03 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi ` (5 subsequent siblings) 6 siblings, 1 reply; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel For synthetic event dynamic fields, the type contains "__data_loc", which is basically an internal part of the type which is only meant to be displayed in the format, not in the event description itself, which is confusing to users since they can't use __data_loc on the command-line to define an event field, which printing it would lead them to believe. So filter it out from the description, while leaving it in the type. Reported-by: Masami Hiramatsu <mhiramat@kernel.org> Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_synth.c | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index 3b2dcc42b8ee..b19e2f4159ab 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -1867,14 +1867,22 @@ static int __synth_event_show(struct seq_file *m, struct synth_event *event) { struct synth_field *field; unsigned int i; + char *type, *t; seq_printf(m, "%s\t", event->name); for (i = 0; i < event->n_fields; i++) { field = event->fields[i]; + type = field->type; + t = strstr(type, "__data_loc"); + if (t) { /* __data_loc belongs in format but not event desc */ + t += sizeof("__data_loc"); + type = t; + } + /* parameter values */ - seq_printf(m, "%s %s%s", field->type, field->name, + seq_printf(m, "%s %s%s", type, field->name, i == event->n_fields - 1 ? "" : "; "); } -- 2.17.1 ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description 2020-10-09 15:17 ` [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi @ 2020-10-10 15:03 ` Masami Hiramatsu 2020-10-12 15:37 ` Tom Zanussi 0 siblings, 1 reply; 17+ messages in thread From: Masami Hiramatsu @ 2020-10-10 15:03 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel Hi Tom, On Fri, 9 Oct 2020 10:17:07 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > For synthetic event dynamic fields, the type contains "__data_loc", > which is basically an internal part of the type which is only meant to > be displayed in the format, not in the event description itself, which > is confusing to users since they can't use __data_loc on the > command-line to define an event field, which printing it would lead > them to believe. > > So filter it out from the description, while leaving it in the type. > OK, I confirmed this removes __data_loc from synth_events interface. However, I also found another issue. /sys/kernel/debug/tracing # echo "myevent char str[]; int v" >> synthetic_events /sys/kernel/debug/tracing # cat synthetic_events myevent char[]; str; int v It seems that the type "char[]" includes ";" as a type, this results /sys/kernel/debug/tracing # cat events/synthetic/myevent/format name: myevent ID: 1220 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:__data_loc char[]; str; offset:8; size:8; signed:1; field:int v; offset:16; size:4; signed:1; print fmt: "str=%.*s, v=%d", __get_str(str), REC->v As you can see, the field type has ";" in format file too. This will prevent parsing event information correctly. I also try to remove ";" as below, it seems to work correctly. /sys/kernel/debug/tracing # echo "myevent char[] str; int v" >> synthetic_events /sys/kernel/debug/tracing # cat events/synthetic/myevent/format name: myevent ID: 1221 format: field:unsigned short common_type; offset:0; size:2; signed:0; field:unsigned char common_flags; offset:2; size:1; signed:0; field:unsigned char common_preempt_count; offset:3; size:1; signed:0; field:int common_pid; offset:4; size:4; signed:1; field:__data_loc char[] str; offset:8; size:8; signed:1; field:int v; offset:16; size:4; signed:1; print fmt: "str=%.*s, v=%d", __get_str(str), REC->v Thank you, > Reported-by: Masami Hiramatsu <mhiramat@kernel.org> > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > --- > kernel/trace/trace_events_synth.c | 10 +++++++++- > 1 file changed, 9 insertions(+), 1 deletion(-) > > diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c > index 3b2dcc42b8ee..b19e2f4159ab 100644 > --- a/kernel/trace/trace_events_synth.c > +++ b/kernel/trace/trace_events_synth.c > @@ -1867,14 +1867,22 @@ static int __synth_event_show(struct seq_file *m, struct synth_event *event) > { > struct synth_field *field; > unsigned int i; > + char *type, *t; > > seq_printf(m, "%s\t", event->name); > > for (i = 0; i < event->n_fields; i++) { > field = event->fields[i]; > > + type = field->type; > + t = strstr(type, "__data_loc"); > + if (t) { /* __data_loc belongs in format but not event desc */ > + t += sizeof("__data_loc"); > + type = t; > + } > + > /* parameter values */ > - seq_printf(m, "%s %s%s", field->type, field->name, > + seq_printf(m, "%s %s%s", type, field->name, > i == event->n_fields - 1 ? "" : "; "); > } > > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description 2020-10-10 15:03 ` Masami Hiramatsu @ 2020-10-12 15:37 ` Tom Zanussi 0 siblings, 0 replies; 17+ messages in thread From: Tom Zanussi @ 2020-10-12 15:37 UTC (permalink / raw) To: Masami Hiramatsu; +Cc: rostedt, axelrasmussen, linux-kernel Hi Masami, On Sun, 2020-10-11 at 00:03 +0900, Masami Hiramatsu wrote: > Hi Tom, > > On Fri, 9 Oct 2020 10:17:07 -0500 > Tom Zanussi <zanussi@kernel.org> wrote: > > > For synthetic event dynamic fields, the type contains "__data_loc", > > which is basically an internal part of the type which is only meant > > to > > be displayed in the format, not in the event description itself, > > which > > is confusing to users since they can't use __data_loc on the > > command-line to define an event field, which printing it would lead > > them to believe. > > > > So filter it out from the description, while leaving it in the > > type. > > > > OK, I confirmed this removes __data_loc from synth_events interface. > However, I also found another issue. > > /sys/kernel/debug/tracing # echo "myevent char str[]; int v" >> > synthetic_events > /sys/kernel/debug/tracing # cat synthetic_events > myevent char[]; str; int v > > It seems that the type "char[]" includes ";" as a type, this results > Yeah, this isn't a result of this patchset - it's a different bug which I'll submit a new fix for. Basically in the array case it doesn't effectively strip off trailing characters when creating the array type. Thanks, Tom > > /sys/kernel/debug/tracing # cat events/synthetic/myevent/format > name: myevent > ID: 1220 > format: > field:unsigned short common_type; offset:0; size:2; signe > d:0; > field:unsigned char common_flags; offset:2; size:1; signe > d:0; > field:unsigned char common_preempt_count; offset:3; size: > 1; signed:0; > field:int common_pid; offset:4; size:4; signed:1; > > field:__data_loc char[]; str; offset:8; size:8; signe > d:1; > field:int v; offset:16; size:4; signed:1; > > print fmt: "str=%.*s, v=%d", __get_str(str), REC->v > > > As you can see, the field type has ";" in format file too. This will > prevent > parsing event information correctly. > I also try to remove ";" as below, it seems to work correctly. > > /sys/kernel/debug/tracing # echo "myevent char[] str; int v" >> > synthetic_events > /sys/kernel/debug/tracing # cat events/synthetic/myevent/format > name: myevent > ID: 1221 > format: > field:unsigned short common_type; offset:0; size:2; signe > d:0; > field:unsigned char common_flags; offset:2; size:1; signe > d:0; > field:unsigned char common_preempt_count; offset:3; size: > 1; signed:0; > field:int common_pid; offset:4; size:4; signed:1; > > field:__data_loc char[] str; offset:8; size:8; signe > d:1; > field:int v; offset:16; size:4; signed:1; > > print fmt: "str=%.*s, v=%d", __get_str(str), REC->v > > > Thank you, > > > Reported-by: Masami Hiramatsu <mhiramat@kernel.org> > > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > > --- > > kernel/trace/trace_events_synth.c | 10 +++++++++- > > 1 file changed, 9 insertions(+), 1 deletion(-) > > > > diff --git a/kernel/trace/trace_events_synth.c > > b/kernel/trace/trace_events_synth.c > > index 3b2dcc42b8ee..b19e2f4159ab 100644 > > --- a/kernel/trace/trace_events_synth.c > > +++ b/kernel/trace/trace_events_synth.c > > @@ -1867,14 +1867,22 @@ static int __synth_event_show(struct > > seq_file *m, struct synth_event *event) > > { > > struct synth_field *field; > > unsigned int i; > > + char *type, *t; > > > > seq_printf(m, "%s\t", event->name); > > > > for (i = 0; i < event->n_fields; i++) { > > field = event->fields[i]; > > > > + type = field->type; > > + t = strstr(type, "__data_loc"); > > + if (t) { /* __data_loc belongs in format but not event > > desc */ > > + t += sizeof("__data_loc"); > > + type = t; > > + } > > + > > /* parameter values */ > > - seq_printf(m, "%s %s%s", field->type, field->name, > > + seq_printf(m, "%s %s%s", type, field->name, > > i == event->n_fields - 1 ? "" : "; "); > > } > > > > -- > > 2.17.1 > > > > ^ permalink raw reply [flat|nested] 17+ messages in thread
* [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi 2020-10-09 15:17 ` [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi @ 2020-10-09 15:17 ` Tom Zanussi 2020-10-10 14:39 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 3/5] tracing: Check that the synthetic event and field names are legal Tom Zanussi ` (4 subsequent siblings) 6 siblings, 1 reply; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel is_good_name() is useful for other trace infrastructure, such as synthetic events, so make it available via trace.h. Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace.h | 13 +++++++++++++ kernel/trace/trace_probe.h | 13 ------------- 2 files changed, 13 insertions(+), 13 deletions(-) diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h index 5b0e797cacdd..a94852838491 100644 --- a/kernel/trace/trace.h +++ b/kernel/trace/trace.h @@ -19,6 +19,7 @@ #include <linux/glob.h> #include <linux/irq_work.h> #include <linux/workqueue.h> +#include <linux/ctype.h> #ifdef CONFIG_FTRACE_SYSCALLS #include <asm/unistd.h> /* For NR_SYSCALLS */ @@ -2090,4 +2091,16 @@ static __always_inline void trace_iterator_reset(struct trace_iterator *iter) iter->pos = -1; } +/* Check the name is good for event/group/fields */ +static inline bool is_good_name(const char *name) +{ + if (!isalpha(*name) && *name != '_') + return false; + while (*++name != '\0') { + if (!isalpha(*name) && !isdigit(*name) && *name != '_') + return false; + } + return true; +} + #endif /* _LINUX_KERNEL_TRACE_H */ diff --git a/kernel/trace/trace_probe.h b/kernel/trace/trace_probe.h index 04d00987da69..2f703a20c724 100644 --- a/kernel/trace/trace_probe.h +++ b/kernel/trace/trace_probe.h @@ -16,7 +16,6 @@ #include <linux/tracefs.h> #include <linux/types.h> #include <linux/string.h> -#include <linux/ctype.h> #include <linux/ptrace.h> #include <linux/perf_event.h> #include <linux/kprobes.h> @@ -348,18 +347,6 @@ bool trace_probe_match_command_args(struct trace_probe *tp, #define trace_probe_for_each_link_rcu(pos, tp) \ list_for_each_entry_rcu(pos, &(tp)->event->files, list) -/* Check the name is good for event/group/fields */ -static inline bool is_good_name(const char *name) -{ - if (!isalpha(*name) && *name != '_') - return false; - while (*++name != '\0') { - if (!isalpha(*name) && !isdigit(*name) && *name != '_') - return false; - } - return true; -} - #define TPARG_FL_RETURN BIT(0) #define TPARG_FL_KERNEL BIT(1) #define TPARG_FL_FENTRY BIT(2) -- 2.17.1 ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h 2020-10-09 15:17 ` [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi @ 2020-10-10 14:39 ` Masami Hiramatsu 0 siblings, 0 replies; 17+ messages in thread From: Masami Hiramatsu @ 2020-10-10 14:39 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel On Fri, 9 Oct 2020 10:17:08 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > is_good_name() is useful for other trace infrastructure, such as > synthetic events, so make it available via trace.h. > This looks good to me. Acked-by: Masami Hiramatsu <mhiramat@kernel.org> Thanks! > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > --- > kernel/trace/trace.h | 13 +++++++++++++ > kernel/trace/trace_probe.h | 13 ------------- > 2 files changed, 13 insertions(+), 13 deletions(-) > > diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h > index 5b0e797cacdd..a94852838491 100644 > --- a/kernel/trace/trace.h > +++ b/kernel/trace/trace.h > @@ -19,6 +19,7 @@ > #include <linux/glob.h> > #include <linux/irq_work.h> > #include <linux/workqueue.h> > +#include <linux/ctype.h> > > #ifdef CONFIG_FTRACE_SYSCALLS > #include <asm/unistd.h> /* For NR_SYSCALLS */ > @@ -2090,4 +2091,16 @@ static __always_inline void trace_iterator_reset(struct trace_iterator *iter) > iter->pos = -1; > } > > +/* Check the name is good for event/group/fields */ > +static inline bool is_good_name(const char *name) > +{ > + if (!isalpha(*name) && *name != '_') > + return false; > + while (*++name != '\0') { > + if (!isalpha(*name) && !isdigit(*name) && *name != '_') > + return false; > + } > + return true; > +} > + > #endif /* _LINUX_KERNEL_TRACE_H */ > diff --git a/kernel/trace/trace_probe.h b/kernel/trace/trace_probe.h > index 04d00987da69..2f703a20c724 100644 > --- a/kernel/trace/trace_probe.h > +++ b/kernel/trace/trace_probe.h > @@ -16,7 +16,6 @@ > #include <linux/tracefs.h> > #include <linux/types.h> > #include <linux/string.h> > -#include <linux/ctype.h> > #include <linux/ptrace.h> > #include <linux/perf_event.h> > #include <linux/kprobes.h> > @@ -348,18 +347,6 @@ bool trace_probe_match_command_args(struct trace_probe *tp, > #define trace_probe_for_each_link_rcu(pos, tp) \ > list_for_each_entry_rcu(pos, &(tp)->event->files, list) > > -/* Check the name is good for event/group/fields */ > -static inline bool is_good_name(const char *name) > -{ > - if (!isalpha(*name) && *name != '_') > - return false; > - while (*++name != '\0') { > - if (!isalpha(*name) && !isdigit(*name) && *name != '_') > - return false; > - } > - return true; > -} > - > #define TPARG_FL_RETURN BIT(0) > #define TPARG_FL_KERNEL BIT(1) > #define TPARG_FL_FENTRY BIT(2) > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 17+ messages in thread
* [PATCH 3/5] tracing: Check that the synthetic event and field names are legal 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi 2020-10-09 15:17 ` [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi 2020-10-09 15:17 ` [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi @ 2020-10-09 15:17 ` Tom Zanussi 2020-10-10 14:41 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 4/5] tracing: Add synthetic event error logging Tom Zanussi ` (3 subsequent siblings) 6 siblings, 1 reply; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Call the is_good_name() function used by probe events to make sure synthetic event and field names don't contain illegal characters and cause unexpected parsing of synthetic event commands. Fixes: 4b147936fa50 (tracing: Add support for 'synthetic' events) Reported-by: Masami Hiramatsu <mhiramat@kernel.org> Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_synth.c | 9 +++++++++ 1 file changed, 9 insertions(+) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index b19e2f4159ab..8c9d6e464da0 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -572,6 +572,10 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, ret = -ENOMEM; goto free; } + if (!is_good_name(field->name)) { + ret = -EINVAL; + goto free; + } if (field_type[0] == ';') field_type++; @@ -1112,6 +1116,11 @@ static int __create_synth_event(int argc, const char *name, const char **argv) mutex_lock(&event_mutex); + if (!is_good_name(name)) { + ret = -EINVAL; + goto out; + } + event = find_synth_event(name); if (event) { ret = -EEXIST; -- 2.17.1 ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: [PATCH 3/5] tracing: Check that the synthetic event and field names are legal 2020-10-09 15:17 ` [PATCH 3/5] tracing: Check that the synthetic event and field names are legal Tom Zanussi @ 2020-10-10 14:41 ` Masami Hiramatsu 0 siblings, 0 replies; 17+ messages in thread From: Masami Hiramatsu @ 2020-10-10 14:41 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel On Fri, 9 Oct 2020 10:17:09 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > Call the is_good_name() function used by probe events to make sure > synthetic event and field names don't contain illegal characters and > cause unexpected parsing of synthetic event commands. > I've tested it. This looks good to me. /sys/kernel/debug/tracing # echo "myevent char str]" >> synthetic_events sh: write error: Invalid argument /sys/kernel/debug/tracing # echo "myevent char str;[]" >> synthetic_events sh: write error: Invalid argument It works correctly now :) Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org> Tested-by: Masami Hiramatsu <mhiramat@kernel.org> Thanks! > Fixes: 4b147936fa50 (tracing: Add support for 'synthetic' events) > Reported-by: Masami Hiramatsu <mhiramat@kernel.org> > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > --- > kernel/trace/trace_events_synth.c | 9 +++++++++ > 1 file changed, 9 insertions(+) > > diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c > index b19e2f4159ab..8c9d6e464da0 100644 > --- a/kernel/trace/trace_events_synth.c > +++ b/kernel/trace/trace_events_synth.c > @@ -572,6 +572,10 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, > ret = -ENOMEM; > goto free; > } > + if (!is_good_name(field->name)) { > + ret = -EINVAL; > + goto free; > + } > > if (field_type[0] == ';') > field_type++; > @@ -1112,6 +1116,11 @@ static int __create_synth_event(int argc, const char *name, const char **argv) > > mutex_lock(&event_mutex); > > + if (!is_good_name(name)) { > + ret = -EINVAL; > + goto out; > + } > + > event = find_synth_event(name); > if (event) { > ret = -EEXIST; > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 17+ messages in thread
* [PATCH 4/5] tracing: Add synthetic event error logging 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi ` (2 preceding siblings ...) 2020-10-09 15:17 ` [PATCH 3/5] tracing: Check that the synthetic event and field names are legal Tom Zanussi @ 2020-10-09 15:17 ` Tom Zanussi 2020-10-10 14:57 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi ` (2 subsequent siblings) 6 siblings, 1 reply; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Add support for synthetic event error logging, which entails adding a logging function for it, a way to save the synthetic event command, and a set of specific synthetic event parse error strings and handling. Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_synth.c | 114 +++++++++++++++++++++++++++++- 1 file changed, 112 insertions(+), 2 deletions(-) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index 8c9d6e464da0..ce4cae5cfd47 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -20,6 +20,53 @@ #include "trace_synth.h" +#undef ERRORS +#define ERRORS \ + C(BAD_NAME, "Illegal name"), \ + C(CMD_INCOMPLETE, "Incomplete command"), \ + C(EVENT_EXISTS, "Event already exists"), \ + C(TOO_MANY_FIELDS, "Too many fields"), \ + C(INCOMPLETE_TYPE, "Incomplete type"), \ + C(INVALID_TYPE, "Invalid type"), \ + C(INVALID_FIELD, "Invalid field"), \ + C(CMD_TOO_LONG, "Command too long"), + +#undef C +#define C(a, b) SYNTH_ERR_##a + +enum { ERRORS }; + +#undef C +#define C(a, b) b + +static const char *err_text[] = { ERRORS }; + +static char last_cmd[MAX_FILTER_STR_VAL]; + +static int errpos(const char *str) +{ + return err_pos(last_cmd, str); +} + +static void last_cmd_set(char *str) +{ + if (!str) + return; + + strncat(last_cmd, str, MAX_FILTER_STR_VAL - 1); +} + +static void synth_err(u8 err_type, u8 err_pos) +{ + tracing_log_err(NULL, "synthetic_events", last_cmd, err_text, + err_type, err_pos); +} + +static void synth_err_clear(void) +{ + last_cmd[0] = '\0'; +} + static int create_synth_event(int argc, const char **argv); static int synth_event_show(struct seq_file *m, struct dyn_event *ev); static int synth_event_release(struct dyn_event *ev); @@ -545,8 +592,10 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, field_type++; if (!strcmp(field_type, "unsigned")) { - if (argc < 3) + if (argc < 3) { + synth_err(SYNTH_ERR_INCOMPLETE_TYPE, errpos(field_type)); return ERR_PTR(-EINVAL); + } prefix = "unsigned "; field_type = argv[1]; field_name = argv[2]; @@ -573,6 +622,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, goto free; } if (!is_good_name(field->name)) { + synth_err(SYNTH_ERR_BAD_NAME, errpos(field_name)); ret = -EINVAL; goto free; } @@ -601,6 +651,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, size = synth_field_size(field->type); if (size < 0) { + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field->name)); ret = -EINVAL; goto free; } else if (size == 0) { @@ -621,6 +672,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, field->is_dynamic = true; size = sizeof(u64); } else { + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field->name)); ret = -EINVAL; goto free; } @@ -1098,12 +1150,64 @@ int synth_event_gen_cmd_array_start(struct dynevent_cmd *cmd, const char *name, } EXPORT_SYMBOL_GPL(synth_event_gen_cmd_array_start); +static int cmdstr_append(char *buf, const char *str, int *remaining) +{ + int len = strlen(str); + + if (len + 1 >= *remaining) { + synth_err(SYNTH_ERR_CMD_TOO_LONG, 0); + return -EINVAL; + } + + strcat(buf, str); + strcat(buf, " "); + *remaining -= len + 1; + + return 0; +} + +static int save_cmdstr(int argc, const char *name, const char **argv) +{ + int i, ret, remaining = MAX_DYNEVENT_CMD_LEN; + char *buf; + + synth_err_clear(); + + buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL); + if (!buf) + return -ENOMEM; + + ret = cmdstr_append(buf, name, &remaining); + if (ret) { + kfree(buf); + return ret; + } + + for (i = 0; i < argc; i++) { + ret = cmdstr_append(buf, argv[i], &remaining); + if (ret) { + kfree(buf); + return ret; + } + } + + last_cmd_set(buf); + + kfree(buf); + + return ret; +} + static int __create_synth_event(int argc, const char *name, const char **argv) { struct synth_field *field, *fields[SYNTH_FIELDS_MAX]; struct synth_event *event = NULL; int i, consumed = 0, n_fields = 0, ret = 0; + ret = save_cmdstr(argc, name, argv); + if (ret) + return ret; + /* * Argument syntax: * - Add synthetic event: <event_name> field[;field] ... @@ -1111,18 +1215,22 @@ static int __create_synth_event(int argc, const char *name, const char **argv) * where 'field' = type field_name */ - if (name[0] == '\0' || argc < 1) + if (name[0] == '\0' || argc < 1) { + synth_err(SYNTH_ERR_CMD_INCOMPLETE, 0); return -EINVAL; + } mutex_lock(&event_mutex); if (!is_good_name(name)) { + synth_err(SYNTH_ERR_BAD_NAME, errpos(name)); ret = -EINVAL; goto out; } event = find_synth_event(name); if (event) { + synth_err(SYNTH_ERR_EVENT_EXISTS, errpos(name)); ret = -EEXIST; goto out; } @@ -1131,6 +1239,7 @@ static int __create_synth_event(int argc, const char *name, const char **argv) if (strcmp(argv[i], ";") == 0) continue; if (n_fields == SYNTH_FIELDS_MAX) { + synth_err(SYNTH_ERR_TOO_MANY_FIELDS, 0); ret = -EINVAL; goto err; } @@ -1145,6 +1254,7 @@ static int __create_synth_event(int argc, const char *name, const char **argv) } if (i < argc && strcmp(argv[i], ";") != 0) { + synth_err(SYNTH_ERR_INVALID_FIELD, errpos(argv[i])); ret = -EINVAL; goto err; } -- 2.17.1 ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: [PATCH 4/5] tracing: Add synthetic event error logging 2020-10-09 15:17 ` [PATCH 4/5] tracing: Add synthetic event error logging Tom Zanussi @ 2020-10-10 14:57 ` Masami Hiramatsu 2020-10-12 15:34 ` Tom Zanussi 0 siblings, 1 reply; 17+ messages in thread From: Masami Hiramatsu @ 2020-10-10 14:57 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel On Fri, 9 Oct 2020 10:17:10 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > Add support for synthetic event error logging, which entails adding a > logging function for it, a way to save the synthetic event command, > and a set of specific synthetic event parse error strings and > handling. Thanks for fixing this. But it seems that the INVALID_TYPE error position is not correct. /sys/kernel/debug/tracing # echo "myevent chr arg" >> synthetic_events sh: write error: Invalid argument /sys/kernel/debug/tracing # cat error_log [ 1354.611660] synthetic_events: error: Invalid type Command: myevent chr arg ^ If the type is invalid, it should point "chr" instead of "arg". If you add a syntax error testcase as same as kprobe_events, you can check the error position too. Thank you, > > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > --- > kernel/trace/trace_events_synth.c | 114 +++++++++++++++++++++++++++++- > 1 file changed, 112 insertions(+), 2 deletions(-) > > diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c > index 8c9d6e464da0..ce4cae5cfd47 100644 > --- a/kernel/trace/trace_events_synth.c > +++ b/kernel/trace/trace_events_synth.c > @@ -20,6 +20,53 @@ > > #include "trace_synth.h" > > +#undef ERRORS > +#define ERRORS \ > + C(BAD_NAME, "Illegal name"), \ > + C(CMD_INCOMPLETE, "Incomplete command"), \ > + C(EVENT_EXISTS, "Event already exists"), \ > + C(TOO_MANY_FIELDS, "Too many fields"), \ > + C(INCOMPLETE_TYPE, "Incomplete type"), \ > + C(INVALID_TYPE, "Invalid type"), \ > + C(INVALID_FIELD, "Invalid field"), \ > + C(CMD_TOO_LONG, "Command too long"), > + > +#undef C > +#define C(a, b) SYNTH_ERR_##a > + > +enum { ERRORS }; > + > +#undef C > +#define C(a, b) b > + > +static const char *err_text[] = { ERRORS }; > + > +static char last_cmd[MAX_FILTER_STR_VAL]; > + > +static int errpos(const char *str) > +{ > + return err_pos(last_cmd, str); > +} > + > +static void last_cmd_set(char *str) > +{ > + if (!str) > + return; > + > + strncat(last_cmd, str, MAX_FILTER_STR_VAL - 1); > +} > + > +static void synth_err(u8 err_type, u8 err_pos) > +{ > + tracing_log_err(NULL, "synthetic_events", last_cmd, err_text, > + err_type, err_pos); > +} > + > +static void synth_err_clear(void) > +{ > + last_cmd[0] = '\0'; > +} > + > static int create_synth_event(int argc, const char **argv); > static int synth_event_show(struct seq_file *m, struct dyn_event *ev); > static int synth_event_release(struct dyn_event *ev); > @@ -545,8 +592,10 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, > field_type++; > > if (!strcmp(field_type, "unsigned")) { > - if (argc < 3) > + if (argc < 3) { > + synth_err(SYNTH_ERR_INCOMPLETE_TYPE, errpos(field_type)); > return ERR_PTR(-EINVAL); > + } > prefix = "unsigned "; > field_type = argv[1]; > field_name = argv[2]; > @@ -573,6 +622,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, > goto free; > } > if (!is_good_name(field->name)) { > + synth_err(SYNTH_ERR_BAD_NAME, errpos(field_name)); > ret = -EINVAL; > goto free; > } > @@ -601,6 +651,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, > > size = synth_field_size(field->type); > if (size < 0) { > + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field->name)); > ret = -EINVAL; > goto free; > } else if (size == 0) { > @@ -621,6 +672,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, > field->is_dynamic = true; > size = sizeof(u64); > } else { > + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field->name)); > ret = -EINVAL; > goto free; > } > @@ -1098,12 +1150,64 @@ int synth_event_gen_cmd_array_start(struct dynevent_cmd *cmd, const char *name, > } > EXPORT_SYMBOL_GPL(synth_event_gen_cmd_array_start); > > +static int cmdstr_append(char *buf, const char *str, int *remaining) > +{ > + int len = strlen(str); > + > + if (len + 1 >= *remaining) { > + synth_err(SYNTH_ERR_CMD_TOO_LONG, 0); > + return -EINVAL; > + } > + > + strcat(buf, str); > + strcat(buf, " "); > + *remaining -= len + 1; > + > + return 0; > +} > + > +static int save_cmdstr(int argc, const char *name, const char **argv) > +{ > + int i, ret, remaining = MAX_DYNEVENT_CMD_LEN; > + char *buf; > + > + synth_err_clear(); > + > + buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL); > + if (!buf) > + return -ENOMEM; > + > + ret = cmdstr_append(buf, name, &remaining); > + if (ret) { > + kfree(buf); > + return ret; > + } > + > + for (i = 0; i < argc; i++) { > + ret = cmdstr_append(buf, argv[i], &remaining); > + if (ret) { > + kfree(buf); > + return ret; > + } > + } > + > + last_cmd_set(buf); > + > + kfree(buf); > + > + return ret; > +} > + > static int __create_synth_event(int argc, const char *name, const char **argv) > { > struct synth_field *field, *fields[SYNTH_FIELDS_MAX]; > struct synth_event *event = NULL; > int i, consumed = 0, n_fields = 0, ret = 0; > > + ret = save_cmdstr(argc, name, argv); > + if (ret) > + return ret; > + > /* > * Argument syntax: > * - Add synthetic event: <event_name> field[;field] ... > @@ -1111,18 +1215,22 @@ static int __create_synth_event(int argc, const char *name, const char **argv) > * where 'field' = type field_name > */ > > - if (name[0] == '\0' || argc < 1) > + if (name[0] == '\0' || argc < 1) { > + synth_err(SYNTH_ERR_CMD_INCOMPLETE, 0); > return -EINVAL; > + } > > mutex_lock(&event_mutex); > > if (!is_good_name(name)) { > + synth_err(SYNTH_ERR_BAD_NAME, errpos(name)); > ret = -EINVAL; > goto out; > } > > event = find_synth_event(name); > if (event) { > + synth_err(SYNTH_ERR_EVENT_EXISTS, errpos(name)); > ret = -EEXIST; > goto out; > } > @@ -1131,6 +1239,7 @@ static int __create_synth_event(int argc, const char *name, const char **argv) > if (strcmp(argv[i], ";") == 0) > continue; > if (n_fields == SYNTH_FIELDS_MAX) { > + synth_err(SYNTH_ERR_TOO_MANY_FIELDS, 0); > ret = -EINVAL; > goto err; > } > @@ -1145,6 +1254,7 @@ static int __create_synth_event(int argc, const char *name, const char **argv) > } > > if (i < argc && strcmp(argv[i], ";") != 0) { > + synth_err(SYNTH_ERR_INVALID_FIELD, errpos(argv[i])); > ret = -EINVAL; > goto err; > } > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 4/5] tracing: Add synthetic event error logging 2020-10-10 14:57 ` Masami Hiramatsu @ 2020-10-12 15:34 ` Tom Zanussi 0 siblings, 0 replies; 17+ messages in thread From: Tom Zanussi @ 2020-10-12 15:34 UTC (permalink / raw) To: Masami Hiramatsu; +Cc: rostedt, axelrasmussen, linux-kernel Hi Masami, On Sat, 2020-10-10 at 23:57 +0900, Masami Hiramatsu wrote: > On Fri, 9 Oct 2020 10:17:10 -0500 > Tom Zanussi <zanussi@kernel.org> wrote: > > > Add support for synthetic event error logging, which entails adding > > a > > logging function for it, a way to save the synthetic event command, > > and a set of specific synthetic event parse error strings and > > handling. > > Thanks for fixing this. But it seems that the INVALID_TYPE error > position is not correct. > > /sys/kernel/debug/tracing # echo "myevent chr arg" >> > synthetic_events > sh: write error: Invalid argument > /sys/kernel/debug/tracing # cat error_log > [ 1354.611660] synthetic_events: error: Invalid type > Command: myevent chr arg > ^ > > If the type is invalid, it should point "chr" instead of "arg". > If you add a syntax error testcase as same as kprobe_events, you can > check the error position too. > Right, it's using name where it should be using type. Will fix in the next version. Thanks, Tom > Thank you, > > > > > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > > --- > > kernel/trace/trace_events_synth.c | 114 > > +++++++++++++++++++++++++++++- > > 1 file changed, 112 insertions(+), 2 deletions(-) > > > > diff --git a/kernel/trace/trace_events_synth.c > > b/kernel/trace/trace_events_synth.c > > index 8c9d6e464da0..ce4cae5cfd47 100644 > > --- a/kernel/trace/trace_events_synth.c > > +++ b/kernel/trace/trace_events_synth.c > > @@ -20,6 +20,53 @@ > > > > #include "trace_synth.h" > > > > +#undef ERRORS > > +#define ERRORS \ > > + C(BAD_NAME, "Illegal name"), \ > > + C(CMD_INCOMPLETE, "Incomplete command"), \ > > + C(EVENT_EXISTS, "Event already exists"), \ > > + C(TOO_MANY_FIELDS, "Too many fields"), \ > > + C(INCOMPLETE_TYPE, "Incomplete type"), \ > > + C(INVALID_TYPE, "Invalid type"), \ > > + C(INVALID_FIELD, "Invalid field"), \ > > + C(CMD_TOO_LONG, "Command too long"), > > + > > +#undef C > > +#define C(a, b) SYNTH_ERR_##a > > + > > +enum { ERRORS }; > > + > > +#undef C > > +#define C(a, b) b > > + > > +static const char *err_text[] = { ERRORS }; > > + > > +static char last_cmd[MAX_FILTER_STR_VAL]; > > + > > +static int errpos(const char *str) > > +{ > > + return err_pos(last_cmd, str); > > +} > > + > > +static void last_cmd_set(char *str) > > +{ > > + if (!str) > > + return; > > + > > + strncat(last_cmd, str, MAX_FILTER_STR_VAL - 1); > > +} > > + > > +static void synth_err(u8 err_type, u8 err_pos) > > +{ > > + tracing_log_err(NULL, "synthetic_events", last_cmd, err_text, > > + err_type, err_pos); > > +} > > + > > +static void synth_err_clear(void) > > +{ > > + last_cmd[0] = '\0'; > > +} > > + > > static int create_synth_event(int argc, const char **argv); > > static int synth_event_show(struct seq_file *m, struct dyn_event > > *ev); > > static int synth_event_release(struct dyn_event *ev); > > @@ -545,8 +592,10 @@ static struct synth_field > > *parse_synth_field(int argc, const char **argv, > > field_type++; > > > > if (!strcmp(field_type, "unsigned")) { > > - if (argc < 3) > > + if (argc < 3) { > > + synth_err(SYNTH_ERR_INCOMPLETE_TYPE, > > errpos(field_type)); > > return ERR_PTR(-EINVAL); > > + } > > prefix = "unsigned "; > > field_type = argv[1]; > > field_name = argv[2]; > > @@ -573,6 +622,7 @@ static struct synth_field > > *parse_synth_field(int argc, const char **argv, > > goto free; > > } > > if (!is_good_name(field->name)) { > > + synth_err(SYNTH_ERR_BAD_NAME, errpos(field_name)); > > ret = -EINVAL; > > goto free; > > } > > @@ -601,6 +651,7 @@ static struct synth_field > > *parse_synth_field(int argc, const char **argv, > > > > size = synth_field_size(field->type); > > if (size < 0) { > > + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field->name)); > > ret = -EINVAL; > > goto free; > > } else if (size == 0) { > > @@ -621,6 +672,7 @@ static struct synth_field > > *parse_synth_field(int argc, const char **argv, > > field->is_dynamic = true; > > size = sizeof(u64); > > } else { > > + synth_err(SYNTH_ERR_INVALID_TYPE, errpos(field- > > >name)); > > ret = -EINVAL; > > goto free; > > } > > @@ -1098,12 +1150,64 @@ int synth_event_gen_cmd_array_start(struct > > dynevent_cmd *cmd, const char *name, > > } > > EXPORT_SYMBOL_GPL(synth_event_gen_cmd_array_start); > > > > +static int cmdstr_append(char *buf, const char *str, int > > *remaining) > > +{ > > + int len = strlen(str); > > + > > + if (len + 1 >= *remaining) { > > + synth_err(SYNTH_ERR_CMD_TOO_LONG, 0); > > + return -EINVAL; > > + } > > + > > + strcat(buf, str); > > + strcat(buf, " "); > > + *remaining -= len + 1; > > + > > + return 0; > > +} > > + > > +static int save_cmdstr(int argc, const char *name, const char > > **argv) > > +{ > > + int i, ret, remaining = MAX_DYNEVENT_CMD_LEN; > > + char *buf; > > + > > + synth_err_clear(); > > + > > + buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL); > > + if (!buf) > > + return -ENOMEM; > > + > > + ret = cmdstr_append(buf, name, &remaining); > > + if (ret) { > > + kfree(buf); > > + return ret; > > + } > > + > > + for (i = 0; i < argc; i++) { > > + ret = cmdstr_append(buf, argv[i], &remaining); > > + if (ret) { > > + kfree(buf); > > + return ret; > > + } > > + } > > + > > + last_cmd_set(buf); > > + > > + kfree(buf); > > + > > + return ret; > > +} > > + > > static int __create_synth_event(int argc, const char *name, const > > char **argv) > > { > > struct synth_field *field, *fields[SYNTH_FIELDS_MAX]; > > struct synth_event *event = NULL; > > int i, consumed = 0, n_fields = 0, ret = 0; > > > > + ret = save_cmdstr(argc, name, argv); > > + if (ret) > > + return ret; > > + > > /* > > * Argument syntax: > > * - Add synthetic event: <event_name> field[;field] ... > > @@ -1111,18 +1215,22 @@ static int __create_synth_event(int argc, > > const char *name, const char **argv) > > * where 'field' = type field_name > > */ > > > > - if (name[0] == '\0' || argc < 1) > > + if (name[0] == '\0' || argc < 1) { > > + synth_err(SYNTH_ERR_CMD_INCOMPLETE, 0); > > return -EINVAL; > > + } > > > > mutex_lock(&event_mutex); > > > > if (!is_good_name(name)) { > > + synth_err(SYNTH_ERR_BAD_NAME, errpos(name)); > > ret = -EINVAL; > > goto out; > > } > > > > event = find_synth_event(name); > > if (event) { > > + synth_err(SYNTH_ERR_EVENT_EXISTS, errpos(name)); > > ret = -EEXIST; > > goto out; > > } > > @@ -1131,6 +1239,7 @@ static int __create_synth_event(int argc, > > const char *name, const char **argv) > > if (strcmp(argv[i], ";") == 0) > > continue; > > if (n_fields == SYNTH_FIELDS_MAX) { > > + synth_err(SYNTH_ERR_TOO_MANY_FIELDS, 0); > > ret = -EINVAL; > > goto err; > > } > > @@ -1145,6 +1254,7 @@ static int __create_synth_event(int argc, > > const char *name, const char **argv) > > } > > > > if (i < argc && strcmp(argv[i], ";") != 0) { > > + synth_err(SYNTH_ERR_INVALID_FIELD, errpos(argv[i])); > > ret = -EINVAL; > > goto err; > > } > > -- > > 2.17.1 > > > > ^ permalink raw reply [flat|nested] 17+ messages in thread
* [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi ` (3 preceding siblings ...) 2020-10-09 15:17 ` [PATCH 4/5] tracing: Add synthetic event error logging Tom Zanussi @ 2020-10-09 15:17 ` Tom Zanussi 2020-10-10 14:43 ` Masami Hiramatsu 2020-10-09 20:35 ` [PATCH 0/5] tracing: Synthetic event dynamic string fixes Axel Rasmussen 2020-10-12 15:13 ` Steven Rostedt 6 siblings, 1 reply; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 15:17 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel This test uses waking+wakeup_latency as an event name, which doesn't make sense since it includes an operator. Illegal names are now detected by the synthetic event command parsing, which causes this test to fail. Change the name to 'waking_plus_wakeup_latency' to prevent this. Fixes: f06eec4d0f2c (selftests: ftrace: Add inter-event hist triggers testcases) Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- .../inter-event/trigger-inter-event-combined-hist.tc | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc index 7449a4b8f1f9..9098f1e7433f 100644 --- a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc @@ -25,12 +25,12 @@ echo 'wakeup_latency u64 lat pid_t pid' >> synthetic_events echo 'hist:keys=pid:ts1=common_timestamp.usecs if comm=="ping"' >> events/sched/sched_wakeup/trigger echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts1:onmatch(sched.sched_wakeup).wakeup_latency($wakeup_lat,next_pid) if next_comm=="ping"' > events/sched/sched_switch/trigger -echo 'waking+wakeup_latency u64 lat; pid_t pid' >> synthetic_events -echo 'hist:keys=pid,lat:sort=pid,lat:ww_lat=$waking_lat+$wakeup_lat:onmatch(synthetic.wakeup_latency).waking+wakeup_latency($ww_lat,pid)' >> events/synthetic/wakeup_latency/trigger -echo 'hist:keys=pid,lat:sort=pid,lat' >> events/synthetic/waking+wakeup_latency/trigger +echo 'waking_plus_wakeup_latency u64 lat; pid_t pid' >> synthetic_events +echo 'hist:keys=pid,lat:sort=pid,lat:ww_lat=$waking_lat+$wakeup_lat:onmatch(synthetic.wakeup_latency).waking_plus_wakeup_latency($ww_lat,pid)' >> events/synthetic/wakeup_latency/trigger +echo 'hist:keys=pid,lat:sort=pid,lat' >> events/synthetic/waking_plus_wakeup_latency/trigger ping $LOCALHOST -c 3 -if ! grep -q "pid:" events/synthetic/waking+wakeup_latency/hist; then +if ! grep -q "pid:" events/synthetic/waking_plus_wakeup_latency/hist; then fail "Failed to create combined histogram" fi -- 2.17.1 ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test 2020-10-09 15:17 ` [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi @ 2020-10-10 14:43 ` Masami Hiramatsu 0 siblings, 0 replies; 17+ messages in thread From: Masami Hiramatsu @ 2020-10-10 14:43 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel On Fri, 9 Oct 2020 10:17:11 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > This test uses waking+wakeup_latency as an event name, which doesn't > make sense since it includes an operator. Illegal names are now > detected by the synthetic event command parsing, which causes this > test to fail. Change the name to 'waking_plus_wakeup_latency' to > prevent this. Good catch! Acked-by: Masami Hiramatsu <mhiramat@kernel.org> Thanks! > > Fixes: f06eec4d0f2c (selftests: ftrace: Add inter-event hist triggers testcases) > Signed-off-by: Tom Zanussi <zanussi@kernel.org> > --- > .../inter-event/trigger-inter-event-combined-hist.tc | 8 ++++---- > 1 file changed, 4 insertions(+), 4 deletions(-) > > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc > index 7449a4b8f1f9..9098f1e7433f 100644 > --- a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc > +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-inter-event-combined-hist.tc > @@ -25,12 +25,12 @@ echo 'wakeup_latency u64 lat pid_t pid' >> synthetic_events > echo 'hist:keys=pid:ts1=common_timestamp.usecs if comm=="ping"' >> events/sched/sched_wakeup/trigger > echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts1:onmatch(sched.sched_wakeup).wakeup_latency($wakeup_lat,next_pid) if next_comm=="ping"' > events/sched/sched_switch/trigger > > -echo 'waking+wakeup_latency u64 lat; pid_t pid' >> synthetic_events > -echo 'hist:keys=pid,lat:sort=pid,lat:ww_lat=$waking_lat+$wakeup_lat:onmatch(synthetic.wakeup_latency).waking+wakeup_latency($ww_lat,pid)' >> events/synthetic/wakeup_latency/trigger > -echo 'hist:keys=pid,lat:sort=pid,lat' >> events/synthetic/waking+wakeup_latency/trigger > +echo 'waking_plus_wakeup_latency u64 lat; pid_t pid' >> synthetic_events > +echo 'hist:keys=pid,lat:sort=pid,lat:ww_lat=$waking_lat+$wakeup_lat:onmatch(synthetic.wakeup_latency).waking_plus_wakeup_latency($ww_lat,pid)' >> events/synthetic/wakeup_latency/trigger > +echo 'hist:keys=pid,lat:sort=pid,lat' >> events/synthetic/waking_plus_wakeup_latency/trigger > > ping $LOCALHOST -c 3 > -if ! grep -q "pid:" events/synthetic/waking+wakeup_latency/hist; then > +if ! grep -q "pid:" events/synthetic/waking_plus_wakeup_latency/hist; then > fail "Failed to create combined histogram" > fi > > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi ` (4 preceding siblings ...) 2020-10-09 15:17 ` [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi @ 2020-10-09 20:35 ` Axel Rasmussen 2020-10-09 21:10 ` Tom Zanussi 2020-10-12 15:13 ` Steven Rostedt 6 siblings, 1 reply; 17+ messages in thread From: Axel Rasmussen @ 2020-10-09 20:35 UTC (permalink / raw) To: Tom Zanussi; +Cc: Steven Rostedt, Masami Hiramatsu, LKML On Fri, Oct 9, 2020 at 8:17 AM Tom Zanussi <zanussi@kernel.org> wrote: > > These patches provide fixes for the problems observed by Masami in the > new synthetic event dynamic string patchset. > > The first patch (tracing: Don't show dynamic string internals in > synthetic event description) removes the __data_loc from the event > description but leaves it in the format. > > The patch (tracing: Add synthetic event error logging) addresses the > lack of error messages when parse errors occur. > > The remaining three patches address the other problems Masami noted > which result from allowing illegal characters in synthetic event and > field names when defining an event. The is_good_name() function is > used to check that's not possible for the probe events, but should > also be used for the synthetic events as well. > > (tracing: Move is_good_name() from trace_probe.h to trace.h) makes > that function available to other trace subsystems by putting it in > trace.h. (tracing: Check that the synthetic event and field names are > legal) applies it to the synthetic events, and (selftests/ftrace: > Change synthetic event name for inter-event-combined test) changes a > testcase that now fails because it uses an illegal name. > > The following changes since commit 848183553e431e6e9c2ea2f72421a7a1bbc6532e: > > tracing: Fix synthetic print fmt check for use of __get_str() (2020-10-08 15:29:07 -0400) > > are available in the Git repository at: > > git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/dynstring-fixes-v1 I applied this series, and then my mmap_lock tracepoints series, onto v5.9-rc8. I played with the edge cases Masami raised in the other thread, and I also tried constructing a synthetic event as we discussed on the thread about my series. As far as I can see, this addresses the edge cases Masami pointed out, and it all seems to work as intended. It works fine with the kind of synthetic event I'm hoping to define for my particular use case. So, for what it's worth: Tested-By: Axel Rasmussen <axelrasmussen@google.com> > > Tom Zanussi (5): > tracing: Don't show dynamic string internals in synthetic event > description > tracing: Move is_good_name() from trace_probe.h to trace.h > tracing: Check that the synthetic event and field names are legal > tracing: Add synthetic event error logging > selftests/ftrace: Change synthetic event name for inter-event-combined > test > > kernel/trace/trace.h | 13 ++ > kernel/trace/trace_events_synth.c | 133 +++++++++++++++++- > kernel/trace/trace_probe.h | 13 -- > .../trigger-inter-event-combined-hist.tc | 8 +- > 4 files changed, 147 insertions(+), 20 deletions(-) > > -- > 2.17.1 > ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes 2020-10-09 20:35 ` [PATCH 0/5] tracing: Synthetic event dynamic string fixes Axel Rasmussen @ 2020-10-09 21:10 ` Tom Zanussi 0 siblings, 0 replies; 17+ messages in thread From: Tom Zanussi @ 2020-10-09 21:10 UTC (permalink / raw) To: Axel Rasmussen; +Cc: Steven Rostedt, Masami Hiramatsu, LKML Hi Axel, On Fri, 2020-10-09 at 13:35 -0700, Axel Rasmussen wrote: > On Fri, Oct 9, 2020 at 8:17 AM Tom Zanussi <zanussi@kernel.org> > wrote: > > > > These patches provide fixes for the problems observed by Masami in > > the > > new synthetic event dynamic string patchset. > > > > The first patch (tracing: Don't show dynamic string internals in > > synthetic event description) removes the __data_loc from the event > > description but leaves it in the format. > > > > The patch (tracing: Add synthetic event error logging) addresses > > the > > lack of error messages when parse errors occur. > > > > The remaining three patches address the other problems Masami noted > > which result from allowing illegal characters in synthetic event > > and > > field names when defining an event. The is_good_name() function is > > used to check that's not possible for the probe events, but should > > also be used for the synthetic events as well. > > > > (tracing: Move is_good_name() from trace_probe.h to trace.h) makes > > that function available to other trace subsystems by putting it in > > trace.h. (tracing: Check that the synthetic event and field names > > are > > legal) applies it to the synthetic events, and (selftests/ftrace: > > Change synthetic event name for inter-event-combined test) changes > > a > > testcase that now fails because it uses an illegal name. > > > > The following changes since commit > > 848183553e431e6e9c2ea2f72421a7a1bbc6532e: > > > > tracing: Fix synthetic print fmt check for use of __get_str() > > (2020-10-08 15:29:07 -0400) > > > > are available in the Git repository at: > > > > git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux- > > trace.git ftrace/dynstring-fixes-v1 > > I applied this series, and then my mmap_lock tracepoints series, onto > v5.9-rc8. I played with the edge cases Masami raised in the other > thread, and I also tried constructing a synthetic event as we > discussed on the thread about my series. > > As far as I can see, this addresses the edge cases Masami pointed > out, > and it all seems to work as intended. It works fine with the kind of > synthetic event I'm hoping to define for my particular use case. > > So, for what it's worth: > > Tested-By: Axel Rasmussen <axelrasmussen@google.com> > Great, thanks for (re-)testing! Tom > > > > Tom Zanussi (5): > > tracing: Don't show dynamic string internals in synthetic event > > description > > tracing: Move is_good_name() from trace_probe.h to trace.h > > tracing: Check that the synthetic event and field names are legal > > tracing: Add synthetic event error logging > > selftests/ftrace: Change synthetic event name for inter-event- > > combined > > test > > > > kernel/trace/trace.h | 13 ++ > > kernel/trace/trace_events_synth.c | 133 > > +++++++++++++++++- > > kernel/trace/trace_probe.h | 13 -- > > .../trigger-inter-event-combined-hist.tc | 8 +- > > 4 files changed, 147 insertions(+), 20 deletions(-) > > > > -- > > 2.17.1 > > ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi ` (5 preceding siblings ...) 2020-10-09 20:35 ` [PATCH 0/5] tracing: Synthetic event dynamic string fixes Axel Rasmussen @ 2020-10-12 15:13 ` Steven Rostedt 2020-10-12 15:38 ` Tom Zanussi 6 siblings, 1 reply; 17+ messages in thread From: Steven Rostedt @ 2020-10-12 15:13 UTC (permalink / raw) To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel On Fri, 9 Oct 2020 10:17:06 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > These patches provide fixes for the problems observed by Masami in the > new synthetic event dynamic string patchset. > > The first patch (tracing: Don't show dynamic string internals in > synthetic event description) removes the __data_loc from the event > description but leaves it in the format. > > The patch (tracing: Add synthetic event error logging) addresses the > lack of error messages when parse errors occur. > > The remaining three patches address the other problems Masami noted > which result from allowing illegal characters in synthetic event and > field names when defining an event. The is_good_name() function is > used to check that's not possible for the probe events, but should > also be used for the synthetic events as well. > > (tracing: Move is_good_name() from trace_probe.h to trace.h) makes > that function available to other trace subsystems by putting it in > trace.h. (tracing: Check that the synthetic event and field names are > legal) applies it to the synthetic events, and (selftests/ftrace: > Change synthetic event name for inter-event-combined test) changes a > testcase that now fails because it uses an illegal name. > Hi Tom, Would you be able to address Masami's concerns on patches 1 and 4? -- Steve ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes 2020-10-12 15:13 ` Steven Rostedt @ 2020-10-12 15:38 ` Tom Zanussi 0 siblings, 0 replies; 17+ messages in thread From: Tom Zanussi @ 2020-10-12 15:38 UTC (permalink / raw) To: Steven Rostedt; +Cc: axelrasmussen, mhiramat, linux-kernel Hi Steve, On Mon, 2020-10-12 at 11:13 -0400, Steven Rostedt wrote: > On Fri, 9 Oct 2020 10:17:06 -0500 > Tom Zanussi <zanussi@kernel.org> wrote: > > > These patches provide fixes for the problems observed by Masami in > > the > > new synthetic event dynamic string patchset. > > > > The first patch (tracing: Don't show dynamic string internals in > > synthetic event description) removes the __data_loc from the event > > description but leaves it in the format. > > > > The patch (tracing: Add synthetic event error logging) addresses > > the > > lack of error messages when parse errors occur. > > > > The remaining three patches address the other problems Masami noted > > which result from allowing illegal characters in synthetic event > > and > > field names when defining an event. The is_good_name() function is > > used to check that's not possible for the probe events, but should > > also be used for the synthetic events as well. > > > > (tracing: Move is_good_name() from trace_probe.h to trace.h) makes > > that function available to other trace subsystems by putting it in > > trace.h. (tracing: Check that the synthetic event and field names > > are > > legal) applies it to the synthetic events, and (selftests/ftrace: > > Change synthetic event name for inter-event-combined test) changes > > a > > testcase that now fails because it uses an illegal name. > > > > > Hi Tom, > > Would you be able to address Masami's concerns on patches 1 and 4? Yes, I'll submit a v2 fixing those soon (today). Thanks, Tom > > -- Steve ^ permalink raw reply [flat|nested] 17+ messages in thread
end of thread, other threads:[~2020-10-12 15:38 UTC | newest] Thread overview: 17+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2020-10-09 15:17 [PATCH 0/5] tracing: Synthetic event dynamic string fixes Tom Zanussi 2020-10-09 15:17 ` [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi 2020-10-10 15:03 ` Masami Hiramatsu 2020-10-12 15:37 ` Tom Zanussi 2020-10-09 15:17 ` [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi 2020-10-10 14:39 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 3/5] tracing: Check that the synthetic event and field names are legal Tom Zanussi 2020-10-10 14:41 ` Masami Hiramatsu 2020-10-09 15:17 ` [PATCH 4/5] tracing: Add synthetic event error logging Tom Zanussi 2020-10-10 14:57 ` Masami Hiramatsu 2020-10-12 15:34 ` Tom Zanussi 2020-10-09 15:17 ` [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi 2020-10-10 14:43 ` Masami Hiramatsu 2020-10-09 20:35 ` [PATCH 0/5] tracing: Synthetic event dynamic string fixes Axel Rasmussen 2020-10-09 21:10 ` Tom Zanussi 2020-10-12 15:13 ` Steven Rostedt 2020-10-12 15:38 ` Tom Zanussi
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).