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

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

[Tom Zanussi]

This updates v2 to replace some of the v2 code with improved code from
Steve (tracing: Add synthetic event error logging) and (tracing:
Handle synthetic event array field type checking correctly) and remove
the synth_error_clear() function and change last_cmd_set() to use
strncpy.

Thanks,

Tom

v2 text:

This updates v1 to fix a couple of additional things that Masami
pointed out:

 - The error logging for the BAD_TYPE error was actually pointing to
   the name - it now points to the type as it should.

 - Added a new test case that verifies most of the synthetic event
   error messages and caret positions.
 
 - Added a new patch that correctly strips off trailing semicolons and
   everything else from array types, which wasn't happening before,
   even before the dynamic array patches.

Original v1 text:

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

Tom Zanussi (7):
  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
  tracing: Handle synthetic event array field type checking correctly
  selftests/ftrace: Add test case for synthetic event syntax errors

 kernel/trace/trace.h                          |  13 ++
 kernel/trace/trace_events_synth.c             | 123 +++++++++++++++++-
 kernel/trace/trace_probe.h                    |  13 --
 .../trigger-inter-event-combined-hist.tc      |   8 +-
 .../trigger-synthetic_event_syntax_errors.tc  |  19 +++
 5 files changed, 153 insertions(+), 23 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc

-- 
2.17.1

[PATCH v3 1/7] 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 v3 2/7] 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.

Acked-by: Masami Hiramatsu <mhiramat@kernel.org>
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 v3 3/7] 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>
Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org>
Tested-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 v3 4/7] 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.

[ <rostedt@goodmis.org>: wrote save_cmdstr() seq_buf implementation. ]
Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 kernel/trace/trace_events_synth.c | 92 ++++++++++++++++++++++++++++++-
 1 file changed, 90 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c
index 8c9d6e464da0..7efe39be6576 100644
--- a/kernel/trace/trace_events_synth.c
+++ b/kernel/trace/trace_events_synth.c
@@ -20,6 +20,48 @@
 
 #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;
+
+	strncpy(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 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 +587,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 +617,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 +646,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_type));
 		ret = -EINVAL;
 		goto free;
 	} else if (size == 0) {
@@ -621,6 +667,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_type));
 			ret = -EINVAL;
 			goto free;
 		}
@@ -1098,12 +1145,47 @@ 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 save_cmdstr(int argc, const char *name, const char **argv)
+{
+        struct seq_buf s;
+	char *buf;
+	int i;
+
+        buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
+        if (!buf)
+                return -ENOMEM;
+
+        seq_buf_init(&s, buf, MAX_DYNEVENT_CMD_LEN);
+
+        seq_buf_puts(&s, name);
+
+        for (i = 0; i < argc; i++) {
+                seq_buf_putc(&s, ' ');
+                seq_buf_puts(&s, argv[i]);
+        }
+
+        if (!seq_buf_buffer_left(&s)) {
+                synth_err(SYNTH_ERR_CMD_TOO_LONG, 0);
+                kfree(buf);
+                return -EINVAL;
+        }
+        buf[s.len] = 0;
+        last_cmd_set(buf);
+
+        kfree(buf);
+        return 0;
+}
+
 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 +1193,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 +1217,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 +1232,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 v3 5/7] 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)
Acked-by: Masami Hiramatsu <mhiramat@kernel.org>
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

[PATCH v3 6/7] tracing: Handle synthetic event array field type checking correctly

[Tom Zanussi]

Since synthetic event array types are derived from the field name,
there may be a semicolon at the end of the type which should be
stripped off.

If there are more characters following that, normal type string
checking will result in an invalid type.

Without this patch, you can end up with an invalid field type string
that gets displayed in both the synthetic event description and the
event format:

Before:

  # echo 'myevent char str[16]; int v' >> synthetic_events
  # cat synthetic_events
    myevent	char[16]; str; int v

  name: myevent
  ID: 1936
  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:char str[16];;	offset:8;	size:16;	signed:1;
  	field:int v;	offset:40;	size:4;	signed:1;

  print fmt: "str=%s, v=%d", REC->str, REC->v

After:

  # echo 'myevent char str[16]; int v' >> synthetic_events
  # cat synthetic_events
    myevent	char[16] str; int v

  # cat events/synthetic/myevent/format
  name: myevent
  ID: 1936
  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:char str[16];	offset:8;	size:16;	signed:1;
	field:int v;	offset:40;	size:4;	signed:1;

  print fmt: "str=%s, v=%d", REC->str, REC->v

[ <rostedt@goodmis.org>: wrote parse_synth_field() snippet. ]
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 | 12 +++++++++---
 1 file changed, 9 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c
index 7efe39be6576..ac3d112268ed 100644
--- a/kernel/trace/trace_events_synth.c
+++ b/kernel/trace/trace_events_synth.c
@@ -174,7 +174,7 @@ static int synth_field_string_size(char *type)
 	start += sizeof("char[") - 1;
 
 	end = strchr(type, ']');
-	if (!end || end < start)
+	if (!end || end < start || type + strlen(type) > end + 1)
 		return -EINVAL;
 
 	len = end - start;
@@ -625,8 +625,14 @@ static struct synth_field *parse_synth_field(int argc, const char **argv,
 	if (field_type[0] == ';')
 		field_type++;
 	len = strlen(field_type) + 1;
-	if (array)
-		len += strlen(array);
+
+        if (array) {
+                int l = strlen(array);
+
+                if (l && array[l - 1] == ';')
+                        l--;
+                len += l;
+        }
 	if (prefix)
 		len += strlen(prefix);
 
-- 
2.17.1

[PATCH v3 7/7] selftests/ftrace: Add test case for synthetic event syntax errors

[Tom Zanussi]

Add a selftest that verifies that the syntax error messages and caret
positions are correct for most of the possible synthetic event syntax
error cases.

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 .../trigger-synthetic_event_syntax_errors.tc  | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc

diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
new file mode 100644
index 000000000000..ada594fe16cb
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
@@ -0,0 +1,19 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: event trigger - test synthetic_events syntax parser errors
+# requires: synthetic_events error_log
+
+check_error() { # command-with-error-pos-by-^
+    ftrace_errlog_check 'synthetic_events' "$1" 'synthetic_events'
+}
+
+check_error 'myevent ^chr arg'			# INVALID_TYPE
+check_error 'myevent ^char str[];; int v'	# INVALID_TYPE
+check_error 'myevent char ^str]; int v'		# INVALID_NAME
+check_error 'myevent char ^str;[]'		# INVALID_NAME
+check_error 'myevent ^char str[; int v'		# INVALID_TYPE
+check_error '^mye;vent char str[]'		# BAD_NAME
+check_error 'myevent char str[]; ^int'		# INVALID_FIELD
+check_error '^myevent'				# INCOMPLETE_CMD
+
+exit 0
-- 
2.17.1

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

[Steven Rostedt]

On Tue, 13 Oct 2020 09:17:55 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> +static int save_cmdstr(int argc, const char *name, const char **argv)
> +{
> +        struct seq_buf s;
> +	char *buf;
> +	int i;
> +
> +        buf = kzalloc(MAX_DYNEVENT_CMD_LEN, GFP_KERNEL);
> +        if (!buf)
> +                return -ENOMEM;
> +
> +        seq_buf_init(&s, buf, MAX_DYNEVENT_CMD_LEN);
> +
> +        seq_buf_puts(&s, name);
> +
> +        for (i = 0; i < argc; i++) {
> +                seq_buf_putc(&s, ' ');
> +                seq_buf_puts(&s, argv[i]);
> +        }
> +
> +        if (!seq_buf_buffer_left(&s)) {
> +                synth_err(SYNTH_ERR_CMD_TOO_LONG, 0);
> +                kfree(buf);
> +                return -EINVAL;
> +        }
> +        buf[s.len] = 0;
> +        last_cmd_set(buf);
> +
> +        kfree(buf);
> +        return 0;
> +}

I see you cut and pasted this ;-)

I fixed up the whitespace.

-- Steve

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

[Masami Hiramatsu]

Hi Tom,

On Tue, 13 Oct 2020 09:17:51 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> This updates v2 to replace some of the v2 code with improved code from
> Steve (tracing: Add synthetic event error logging) and (tracing:
> Handle synthetic event array field type checking correctly) and remove
> the synth_error_clear() function and change last_cmd_set() to use
> strncpy.

Thank you for updating, I tested the series and confirmed all issues 
are fixed now :)

Tested-by: Masami Hiramatsu <mhiramat@kernel.org>

for this series.

/ # cd /sys/kernel/debug/tracing/
/sys/kernel/debug/tracing # echo 'myevent char foo]' >> synthetic_events 
sh: write error: Invalid argument
/sys/kernel/debug/tracing # cat error_log 
[   35.086780] synthetic_events: error: Illegal name
  Command: myevent char foo]
                        ^
/sys/kernel/debug/tracing # echo 'myevent char foo;[]' >> synthetic_events 
sh: write error: Invalid argument
/sys/kernel/debug/tracing # cat error_log 
[   35.086780] synthetic_events: error: Illegal name
  Command: myevent char foo]
                        ^
[   46.857674] synthetic_events: error: Illegal name
  Command: myevent char foo;[]
                        ^
/sys/kernel/debug/tracing # echo 'myevent char foo+[]' >> synthetic_events 
sh: write error: Invalid argument
/sys/kernel/debug/tracing # cat error_log 
[   35.086780] synthetic_events: error: Illegal name
  Command: myevent char foo]
                        ^
[   46.857674] synthetic_events: error: Illegal name
  Command: myevent char foo;[]
                        ^
[   57.220147] synthetic_events: error: Illegal name
  Command: myevent char foo+[]
                        ^
/sys/kernel/debug/tracing # echo 'myevent char foo[]' >> synthetic_events 
/sys/kernel/debug/tracing # cat synthetic_events 
myevent	char[] foo
/sys/kernel/debug/tracing # echo > synthetic_events 
/sys/kernel/debug/tracing # echo 'myevent char[] foo' >> synthetic_events 
/sys/kernel/debug/tracing # cat synthetic_events 
myevent	char[] foo
/sys/kernel/debug/tracing # cat events/synthetic/myevent/format 
name: myevent
ID: 1219
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[] foo;	offset:8;	size:8;	signed:1;

print fmt: "foo=%.*s", __get_str(foo)


> 
> Thanks,
> 
> Tom
> 
> v2 text:
> 
> This updates v1 to fix a couple of additional things that Masami
> pointed out:
> 
>  - The error logging for the BAD_TYPE error was actually pointing to
>    the name - it now points to the type as it should.
> 
>  - Added a new test case that verifies most of the synthetic event
>    error messages and caret positions.
>  
>  - Added a new patch that correctly strips off trailing semicolons and
>    everything else from array types, which wasn't happening before,
>    even before the dynamic array patches.
> 
> Original v1 text:
> 
> 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-v3
> 
> Tom Zanussi (7):
>   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
>   tracing: Handle synthetic event array field type checking correctly
>   selftests/ftrace: Add test case for synthetic event syntax errors
> 
>  kernel/trace/trace.h                          |  13 ++
>  kernel/trace/trace_events_synth.c             | 123 +++++++++++++++++-
>  kernel/trace/trace_probe.h                    |  13 --
>  .../trigger-inter-event-combined-hist.tc      |   8 +-
>  .../trigger-synthetic_event_syntax_errors.tc  |  19 +++
>  5 files changed, 153 insertions(+), 23 deletions(-)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> 
> -- 
> 2.17.1
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v3 7/7] selftests/ftrace: Add test case for synthetic event syntax errors

[Masami Hiramatsu]

Hi Tom,

On Tue, 13 Oct 2020 09:17:58 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> Add a selftest that verifies that the syntax error messages and caret
> positions are correct for most of the possible synthetic event syntax
> error cases.
> 
> Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> ---
>  .../trigger-synthetic_event_syntax_errors.tc  | 19 +++++++++++++++++++
>  1 file changed, 19 insertions(+)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> 
> diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> new file mode 100644
> index 000000000000..ada594fe16cb
> --- /dev/null
> +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> @@ -0,0 +1,19 @@
> +#!/bin/sh
> +# SPDX-License-Identifier: GPL-2.0
> +# description: event trigger - test synthetic_events syntax parser errors
> +# requires: synthetic_events error_log

This also requires dynamic strings support. So, its "requires" line should be

# requires: synthetic_events error_log "char name[]' >> synthetic_events":README

> +
> +check_error() { # command-with-error-pos-by-^
> +    ftrace_errlog_check 'synthetic_events' "$1" 'synthetic_events'
> +}
> +

BTW, some errors looks a bit odd.

> +check_error 'myevent ^chr arg'			# INVALID_TYPE
> +check_error 'myevent ^char str[];; int v'	# INVALID_TYPE

I think there is a wrong "void" argument between ";", instead of invalid type.

> +check_error 'myevent char ^str]; int v'		# INVALID_NAME
> +check_error 'myevent char ^str;[]'		# INVALID_NAME

This is also not an invalid name but '[]' is an invalid type. 

> +check_error 'myevent ^char str[; int v'		# INVALID_TYPE
> +check_error '^mye;vent char str[]'		# BAD_NAME
> +check_error 'myevent char str[]; ^int'		# INVALID_FIELD

Isn't it an incomplete command?

> +check_error '^myevent'				# INCOMPLETE_CMD
> +
> +exit 0

Thank you,

> -- 
> 2.17.1
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v3 7/7] selftests/ftrace: Add test case for synthetic event syntax errors

[Steven Rostedt]

On Wed, 14 Oct 2020 11:06:36 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> Hi Tom,
> 
> On Tue, 13 Oct 2020 09:17:58 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > Add a selftest that verifies that the syntax error messages and caret
> > positions are correct for most of the possible synthetic event syntax
> > error cases.
> > 
> > Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> > ---
> >  .../trigger-synthetic_event_syntax_errors.tc  | 19 +++++++++++++++++++
> >  1 file changed, 19 insertions(+)
> >  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > 
> > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > new file mode 100644
> > index 000000000000..ada594fe16cb
> > --- /dev/null
> > +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > @@ -0,0 +1,19 @@
> > +#!/bin/sh
> > +# SPDX-License-Identifier: GPL-2.0
> > +# description: event trigger - test synthetic_events syntax parser errors
> > +# requires: synthetic_events error_log  
> 
> This also requires dynamic strings support. So, its "requires" line should be
> 
> # requires: synthetic_events error_log "char name[]' >> synthetic_events":README
> 
> > +
> > +check_error() { # command-with-error-pos-by-^
> > +    ftrace_errlog_check 'synthetic_events' "$1" 'synthetic_events'
> > +}
> > +  
> 
> BTW, some errors looks a bit odd.
> 
> > +check_error 'myevent ^chr arg'			# INVALID_TYPE
> > +check_error 'myevent ^char str[];; int v'	# INVALID_TYPE  
> 
> I think there is a wrong "void" argument between ";", instead of invalid type.
> 
> > +check_error 'myevent char ^str]; int v'		# INVALID_NAME
> > +check_error 'myevent char ^str;[]'		# INVALID_NAME  
> 
> This is also not an invalid name but '[]' is an invalid type. 
> 
> > +check_error 'myevent ^char str[; int v'		# INVALID_TYPE
> > +check_error '^mye;vent char str[]'		# BAD_NAME
> > +check_error 'myevent char str[]; ^int'		# INVALID_FIELD  
> 
> Isn't it an incomplete command?
> 
> > +check_error '^myevent'				# INCOMPLETE_CMD
> > +
> > +exit 0  
> 

Hi Masami,

I finished testing this series along with other patches (some from you),
and I'm ready to push this to next, and hopefully soon to Linus. You have a
"tested-by" for the entire series. Are you OK with this patch too? Can we
push this forward and fix up any issues you have later?

-- Steve

Re: [PATCH v3 7/7] selftests/ftrace: Add test case for synthetic event syntax errors

[Masami Hiramatsu]

Hi Steve,

On Wed, 14 Oct 2020 13:32:15 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 14 Oct 2020 11:06:36 +0900
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
> 
> > Hi Tom,
> > 
> > On Tue, 13 Oct 2020 09:17:58 -0500
> > Tom Zanussi <zanussi@kernel.org> wrote:
> > 
> > > Add a selftest that verifies that the syntax error messages and caret
> > > positions are correct for most of the possible synthetic event syntax
> > > error cases.
> > > 
> > > Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> > > ---
> > >  .../trigger-synthetic_event_syntax_errors.tc  | 19 +++++++++++++++++++
> > >  1 file changed, 19 insertions(+)
> > >  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > > 
> > > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > > new file mode 100644
> > > index 000000000000..ada594fe16cb
> > > --- /dev/null
> > > +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc
> > > @@ -0,0 +1,19 @@
> > > +#!/bin/sh
> > > +# SPDX-License-Identifier: GPL-2.0
> > > +# description: event trigger - test synthetic_events syntax parser errors
> > > +# requires: synthetic_events error_log  
> > 
> > This also requires dynamic strings support. So, its "requires" line should be
> > 
> > # requires: synthetic_events error_log "char name[]' >> synthetic_events":README
> > 
> > > +
> > > +check_error() { # command-with-error-pos-by-^
> > > +    ftrace_errlog_check 'synthetic_events' "$1" 'synthetic_events'
> > > +}
> > > +  
> > 
> > BTW, some errors looks a bit odd.
> > 
> > > +check_error 'myevent ^chr arg'			# INVALID_TYPE
> > > +check_error 'myevent ^char str[];; int v'	# INVALID_TYPE  
> > 
> > I think there is a wrong "void" argument between ";", instead of invalid type.
> > 
> > > +check_error 'myevent char ^str]; int v'		# INVALID_NAME
> > > +check_error 'myevent char ^str;[]'		# INVALID_NAME  
> > 
> > This is also not an invalid name but '[]' is an invalid type. 
> > 
> > > +check_error 'myevent ^char str[; int v'		# INVALID_TYPE
> > > +check_error '^mye;vent char str[]'		# BAD_NAME
> > > +check_error 'myevent char str[]; ^int'		# INVALID_FIELD  
> > 
> > Isn't it an incomplete command?
> > 
> > > +check_error '^myevent'				# INCOMPLETE_CMD
> > > +
> > > +exit 0  
> > 
> 
> Hi Masami,
> 
> I finished testing this series along with other patches (some from you),
> and I'm ready to push this to next, and hopefully soon to Linus. You have a
> "tested-by" for the entire series. Are you OK with this patch too? Can we
> push this forward and fix up any issues you have later?

I think this is OK to push at least for the upstream kernel (unless backporting).
The above issues can be fixed in another series :)

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v3 7/7] selftests/ftrace: Add test case for synthetic event syntax errors

[Tom Zanussi]

Hi Masami,

On Wed, 2020-10-14 at 11:06 +0900, Masami Hiramatsu wrote:
> Hi Tom,
> 
> On Tue, 13 Oct 2020 09:17:58 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > Add a selftest that verifies that the syntax error messages and
> > caret
> > positions are correct for most of the possible synthetic event
> > syntax
> > error cases.
> > 
> > Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> > ---
> >  .../trigger-synthetic_event_syntax_errors.tc  | 19
> > +++++++++++++++++++
> >  1 file changed, 19 insertions(+)
> >  create mode 100644
> > tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-
> > synthetic_event_syntax_errors.tc
> > 
> > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-
> > event/trigger-synthetic_event_syntax_errors.tc
> > b/tools/testing/selftests/ftrace/test.d/trigger/inter-
> > event/trigger-synthetic_event_syntax_errors.tc
> > new file mode 100644
> > index 000000000000..ada594fe16cb
> > --- /dev/null
> > +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-
> > event/trigger-synthetic_event_syntax_errors.tc
> > @@ -0,0 +1,19 @@
> > +#!/bin/sh
> > +# SPDX-License-Identifier: GPL-2.0
> > +# description: event trigger - test synthetic_events syntax parser
> > errors
> > +# requires: synthetic_events error_log
> 
> This also requires dynamic strings support. So, its "requires" line
> should be
> 
> # requires: synthetic_events error_log "char name[]' >>
> synthetic_events":README
> 

Yes, thanks for reminding me. ;-)

> > +
> > +check_error() { # command-with-error-pos-by-^
> > +    ftrace_errlog_check 'synthetic_events' "$1" 'synthetic_events'
> > +}
> > +
> 
> BTW, some errors looks a bit odd.
> 
> > +check_error 'myevent ^chr arg'			# INVALID_TYPE
> > +check_error 'myevent ^char str[];; int v'	# INVALID_TYPE
> 
> I think there is a wrong "void" argument between ";", instead of
> invalid type.

Yes, you're right.  I think the solution overall is to just treat
semicolons as whitespace.

> 
> > +check_error 'myevent char ^str]; int v'		# INVALID_NAME
> > +check_error 'myevent char ^str;[]'		# INVALID_NAME
> 
> This is also not an invalid name but '[]' is an invalid type. 
> 
> > +check_error 'myevent ^char str[; int v'		# INVALID_TYPE
> > +check_error '^mye;vent char str[]'		# BAD_NAME
> > +check_error 'myevent char str[]; ^int'		# INVALID_FIELD
> 
> Isn't it an incomplete command?

Yes, but also an invalid field.  I'll try to refine these errors a bit
and make these more consistent.

Tom

> 
> > +check_error '^myevent'				#
> > INCOMPLETE_CMD
> > +
> > +exit 0
> 
> Thank you,
> 
> > -- 
> > 2.17.1
> > 
> 
>