[PATCH 0/5] tracing: Synthetic event dynamic string fixes

[PATCH 0/5] tracing: Synthetic event dynamic string fixes

[Tom Zanussi]

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

[PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description

[Tom Zanussi]

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

[PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h

[Tom Zanussi]

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

[PATCH 3/5] tracing: Check that the synthetic event and field names are legal

[Tom Zanussi]

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

[PATCH 4/5] tracing: Add synthetic event error logging

[Tom Zanussi]

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

[PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test

[Tom Zanussi]

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

Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes

[Axel Rasmussen]

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
>

Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes

[Tom Zanussi]

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
> > 

Re: [PATCH 2/5] tracing: Move is_good_name() from trace_probe.h to trace.h

[Masami Hiramatsu]

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>

Re: [PATCH 3/5] tracing: Check that the synthetic event and field names are legal

[Masami Hiramatsu]

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>

Re: [PATCH 5/5] selftests/ftrace: Change synthetic event name for inter-event-combined test

[Masami Hiramatsu]

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>

Re: [PATCH 4/5] tracing: Add synthetic event error logging

[Masami Hiramatsu]

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>

Re: [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description

[Masami Hiramatsu]

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>

Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes

[Steven Rostedt]

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

Re: [PATCH 4/5] tracing: Add synthetic event error logging

[Tom Zanussi]

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
> > 
> 
> 

Re: [PATCH 1/5] tracing: Don't show dynamic string internals in synthetic event description

[Tom Zanussi]

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
> > 
> 
> 

Re: [PATCH 0/5] tracing: Synthetic event dynamic string fixes

[Tom Zanussi]

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