linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes
@ 2020-10-12 20:18 Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 1/7] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi
                   ` (6 more replies)
  0 siblings, 7 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 UTC (permalink / raw)
  To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel

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.

Thanks,

Tom

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

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             | 140 +++++++++++++++++-
 kernel/trace/trace_probe.h                    |  13 --
 .../trigger-inter-event-combined-hist.tc      |   8 +-
 .../trigger-synthetic_event_syntax_errors.tc  |  19 +++
 5 files changed, 171 insertions(+), 22 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic_event_syntax_errors.tc

-- 
2.17.1


^ permalink raw reply	[flat|nested] 15+ messages in thread

* [PATCH v2 1/7] tracing: Don't show dynamic string internals in synthetic event description
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 2/7] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi
                   ` (5 subsequent siblings)
  6 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 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] 15+ messages in thread

* [PATCH v2 2/7] tracing: Move is_good_name() from trace_probe.h to trace.h
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 1/7] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 3/7] tracing: Check that the synthetic event and field names are legal Tom Zanussi
                   ` (4 subsequent siblings)
  6 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 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.

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


^ permalink raw reply related	[flat|nested] 15+ messages in thread

* [PATCH v2 3/7] tracing: Check that the synthetic event and field names are legal
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 1/7] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 2/7] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 4/7] tracing: Add synthetic event error logging Tom Zanussi
                   ` (3 subsequent siblings)
  6 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 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>
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


^ permalink raw reply related	[flat|nested] 15+ messages in thread

* [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
                   ` (2 preceding siblings ...)
  2020-10-12 20:18 ` [PATCH v2 3/7] tracing: Check that the synthetic event and field names are legal Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 21:42   ` Steven Rostedt
  2020-10-12 22:04   ` Steven Rostedt
  2020-10-12 20:18 ` [PATCH v2 5/7] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi
                   ` (2 subsequent siblings)
  6 siblings, 2 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 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..64c65be62dfe 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_type));
 		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_type));
 			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] 15+ messages in thread

* [PATCH v2 5/7] selftests/ftrace: Change synthetic event name for inter-event-combined test
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
                   ` (3 preceding siblings ...)
  2020-10-12 20:18 ` [PATCH v2 4/7] tracing: Add synthetic event error logging Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly Tom Zanussi
  2020-10-12 20:18 ` [PATCH v2 7/7] selftests/ftrace: Add test case for synthetic event syntax errors Tom Zanussi
  6 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 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)
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


^ permalink raw reply related	[flat|nested] 15+ messages in thread

* [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
                   ` (4 preceding siblings ...)
  2020-10-12 20:18 ` [PATCH v2 5/7] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  2020-10-12 22:14   ` Steven Rostedt
  2020-10-12 20:18 ` [PATCH v2 7/7] selftests/ftrace: Add test case for synthetic event syntax errors Tom Zanussi
  6 siblings, 1 reply; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 UTC (permalink / raw)
  To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel

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

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 | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c
index 64c65be62dfe..5c3f5ae6f0bd 100644
--- a/kernel/trace/trace_events_synth.c
+++ b/kernel/trace/trace_events_synth.c
@@ -179,7 +179,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;
@@ -630,8 +630,11 @@ 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)
+	if (array) {
 		len += strlen(array);
+		if (array[strlen(array) - 1] == ';')
+			len--;
+	}
 	if (prefix)
 		len += strlen(prefix);
 
-- 
2.17.1


^ permalink raw reply related	[flat|nested] 15+ messages in thread

* [PATCH v2 7/7] selftests/ftrace: Add test case for synthetic event syntax errors
  2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
                   ` (5 preceding siblings ...)
  2020-10-12 20:18 ` [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly Tom Zanussi
@ 2020-10-12 20:18 ` Tom Zanussi
  6 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 20:18 UTC (permalink / raw)
  To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel

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..136276b11386
--- /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: Synthetic event parser error log check
+# 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


^ permalink raw reply related	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 20:18 ` [PATCH v2 4/7] tracing: Add synthetic event error logging Tom Zanussi
@ 2020-10-12 21:42   ` Steven Rostedt
  2020-10-12 21:49     ` Steven Rostedt
  2020-10-12 22:04   ` Steven Rostedt
  1 sibling, 1 reply; 15+ messages in thread
From: Steven Rostedt @ 2020-10-12 21:42 UTC (permalink / raw)
  To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel

On Mon, 12 Oct 2020 15:18:06 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> +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);

If I understand strncat() correctly, it will add 'n' + 1 bytes from str
to last_cmd. That is, I think you want:

	strncat(last_cmd, str, MAX_FILTER_STR_VAL - (strlen(last_cmd) + 1));

-- Steve


> +}
> +
> +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';
> +}
> +

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 21:42   ` Steven Rostedt
@ 2020-10-12 21:49     ` Steven Rostedt
  2020-10-12 21:59       ` Tom Zanussi
  0 siblings, 1 reply; 15+ messages in thread
From: Steven Rostedt @ 2020-10-12 21:49 UTC (permalink / raw)
  To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel

On Mon, 12 Oct 2020 17:42:40 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Mon, 12 Oct 2020 15:18:06 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > +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);  
> 
> If I understand strncat() correctly, it will add 'n' + 1 bytes from str
> to last_cmd. That is, I think you want:
> 
> 	strncat(last_cmd, str, MAX_FILTER_STR_VAL - (strlen(last_cmd) + 1));
> 

Looking at the patch more, it only has one caller to last_cmd_set(),
and one caller to synth_err_clear().

Why not just clear on set?

-- Steve



> 
> > +}
> > +
> > +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';
> > +}
> > +  


^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 21:49     ` Steven Rostedt
@ 2020-10-12 21:59       ` Tom Zanussi
  0 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 21:59 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: axelrasmussen, mhiramat, linux-kernel

Hi Steve,

On Mon, 2020-10-12 at 17:49 -0400, Steven Rostedt wrote:
> On Mon, 12 Oct 2020 17:42:40 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > On Mon, 12 Oct 2020 15:18:06 -0500
> > Tom Zanussi <zanussi@kernel.org> wrote:
> > 
> > > +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);  
> > 
> > If I understand strncat() correctly, it will add 'n' + 1 bytes from
> > str
> > to last_cmd. That is, I think you want:
> > 
> > 	strncat(last_cmd, str, MAX_FILTER_STR_VAL - (strlen(last_cmd) +
> > 1));
> > 
> 
> Looking at the patch more, it only has one caller to last_cmd_set(),
> and one caller to synth_err_clear().
> 
> Why not just clear on set?

Yeah, that would make sense, or just remove the clear and use strncpy
in last_cmd_set() instead.

Tom

> 
> -- Steve
> 
> 
> 
> > 
> > > +}
> > > +
> > > +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';
> > > +}
> > > +  
> 
> 


^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 20:18 ` [PATCH v2 4/7] tracing: Add synthetic event error logging Tom Zanussi
  2020-10-12 21:42   ` Steven Rostedt
@ 2020-10-12 22:04   ` Steven Rostedt
  2020-10-12 22:24     ` Tom Zanussi
  1 sibling, 1 reply; 15+ messages in thread
From: Steven Rostedt @ 2020-10-12 22:04 UTC (permalink / raw)
  To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel

On Mon, 12 Oct 2020 15:18:06 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> +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;
> +}
> +

Hmm, the above could easily be replaced with:

	struct seq_buf s;

	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;


-- Steve

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly
  2020-10-12 20:18 ` [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly Tom Zanussi
@ 2020-10-12 22:14   ` Steven Rostedt
  2020-10-12 22:24     ` Tom Zanussi
  0 siblings, 1 reply; 15+ messages in thread
From: Steven Rostedt @ 2020-10-12 22:14 UTC (permalink / raw)
  To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel

On Mon, 12 Oct 2020 15:18:08 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> @@ -630,8 +630,11 @@ 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)
> +	if (array) {
>  		len += strlen(array);
> +		if (array[strlen(array) - 1] == ';')
> +			len--;
> +	}

Why not:

	if (array) {
		int l = strlen(array);

		if (l && array[l - 1] == ';')
			l--;
		len += l;
	}

-- Steve

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 4/7] tracing: Add synthetic event error logging
  2020-10-12 22:04   ` Steven Rostedt
@ 2020-10-12 22:24     ` Tom Zanussi
  0 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 22:24 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: axelrasmussen, mhiramat, linux-kernel

Hi Steve,

On Mon, 2020-10-12 at 18:04 -0400, Steven Rostedt wrote:
> On Mon, 12 Oct 2020 15:18:06 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > +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;
> > +}
> > +
> 
> Hmm, the above could easily be replaced with:
> 
> 	struct seq_buf s;
> 
> 	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;
> 

Yeah, that makes sense, will change it.

Thanks,

Tom

> 
> -- Steve


^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly
  2020-10-12 22:14   ` Steven Rostedt
@ 2020-10-12 22:24     ` Tom Zanussi
  0 siblings, 0 replies; 15+ messages in thread
From: Tom Zanussi @ 2020-10-12 22:24 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: axelrasmussen, mhiramat, linux-kernel

Hi Steve,

On Mon, 2020-10-12 at 18:14 -0400, Steven Rostedt wrote:
> On Mon, 12 Oct 2020 15:18:08 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > @@ -630,8 +630,11 @@ 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)
> > +	if (array) {
> >  		len += strlen(array);
> > +		if (array[strlen(array) - 1] == ';')
> > +			len--;
> > +	}
> 
> Why not:
> 
> 	if (array) {
> 		int l = strlen(array);
> 
> 		if (l && array[l - 1] == ';')
> 			l--;
> 		len += l;
> 	}
> 

Yeah, I think that's better, will change it.

Thanks,

Tom

> -- Steve


^ permalink raw reply	[flat|nested] 15+ messages in thread

end of thread, other threads:[~2020-10-12 22:24 UTC | newest]

Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-10-12 20:18 [PATCH v2 0/7] tracing: Synthetic event dynamic string fixes Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 1/7] tracing: Don't show dynamic string internals in synthetic event description Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 2/7] tracing: Move is_good_name() from trace_probe.h to trace.h Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 3/7] tracing: Check that the synthetic event and field names are legal Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 4/7] tracing: Add synthetic event error logging Tom Zanussi
2020-10-12 21:42   ` Steven Rostedt
2020-10-12 21:49     ` Steven Rostedt
2020-10-12 21:59       ` Tom Zanussi
2020-10-12 22:04   ` Steven Rostedt
2020-10-12 22:24     ` Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 5/7] selftests/ftrace: Change synthetic event name for inter-event-combined test Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 6/7] tracing: Handle synthetic event array field type checking correctly Tom Zanussi
2020-10-12 22:14   ` Steven Rostedt
2020-10-12 22:24     ` Tom Zanussi
2020-10-12 20:18 ` [PATCH v2 7/7] selftests/ftrace: Add test case for synthetic event syntax errors 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).