* [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events @ 2020-10-04 22:14 Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 1/7] tracing: Change STR_VAR_MAX_LEN Tom Zanussi ` (6 more replies) 0 siblings, 7 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Hi, This is v4 of the dynamic string support for synthetic events. This version adds several patches addressing previous comments - a new testcase for the dynamic synth event strings along with a patch adding a blurb about the synthetic_events file, which should have been there in any case, Steve's patch for preventing string printing overruns (tracing: Change synthetic event string format to limit printed length). There's also a new patch (tracing: Save normal string variables) that fixes a bug I found when adding the test case. The problem it fixes is only apparent when using the dynamic strings, although it could also happen with static strings. I wasn't able to produce the problem with static strings, in any case. Other changes include adding the BUILD_BUG_ON() to the (tracing: Change STR_VAR_MAX_LEN) patch, and folding in Steve's __set_synth_event_print_fmt() adding __get_str() calls for trace-cmd. Thanks, Tom Previous versions text: Hi, This is v3 of the dynamic string support for synthetic events. No code changes since v2, just added Fixes: tag for 'tracing: Fix parse_synth_field() error handling' as suggested by Masami along with his Reviewed-by, and Axel's Tested-bys. Thanks, Tom Hi, This is v2 of the dynamic string support for synthetic events. v1 was missing some very important code in the in-kernel API functions that should have reserved room for dynamic strings. This adds it along also some additional test code in the synth_event_gen_test module that tests the dynamic strings for those APIs. I also added Axel's changelog text to the 'tracing: Fix parse_synth_field() error handling' patch and used ssize_t as he also suggested. Thanks, Axel! I also noticed that the original patch didn't use <= as it should have, so changed that as well. Neither my command-line tests or the synth_event_gen_test module are showing any problems at this point for me... Tom Original v1 text: This patchset adds support for dynamic strings for synthetic events, as requested by Axel Rasmussen. Actually, the first two patches should be applied in any case - the first just changes the current max string length and the second fixes a bug I found while testing. It works fine for my simple test cases, but I still need to do a lot more testing, especially of the in-kernel API parts, which don't affect Axel's use case. Anyway, Axel, please try it out and send me your Tested-by: if it works for you, and your broken testcase(s) if it doesn't. ;-) Thanks, Tom The following changes since commit fdb46faeab2f3fa2b43a55059b33b8f98b2e1442: x86: Use tracepoint_enabled() for msr tracepoints instead of open coding it (2020-09-28 10:36:02 -0400) are available in the Git repository at: git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/synth-dynstring-v4 Steven Rostedt (1): tracing: Change synthetic event string format to limit printed length Tom Zanussi (6): tracing: Change STR_VAR_MAX_LEN tracing: Fix parse_synth_field() error handling tracing: Save normal string variables tracing: Add support for dynamic strings to synthetic events tracing: Add README information for synthetic_events file selftests/ftrace: Add test case for synthetic event dynamic strings Documentation/trace/events.rst | 15 +- Documentation/trace/histogram.rst | 18 ++ kernel/trace/synth_event_gen_test.c | 18 +- kernel/trace/trace.c | 7 +- kernel/trace/trace_events_hist.c | 45 ++- kernel/trace/trace_events_synth.c | 256 +++++++++++++++--- kernel/trace/trace_synth.h | 6 +- .../trigger-synthetic-event-dynstring.tc | 31 +++ 8 files changed, 350 insertions(+), 46 deletions(-) create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc -- 2.17.1 ^ permalink raw reply [flat|nested] 16+ messages in thread
* [PATCH v4 1/7] tracing: Change STR_VAR_MAX_LEN 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 2/7] tracing: Fix parse_synth_field() error handling Tom Zanussi ` (5 subsequent siblings) 6 siblings, 0 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel 32 is too small for this value, and anyway it makes more sense to use MAX_FILTER_STR_VAL, as this is also the value used for variable-length __strings. Tested-by: Axel Rasmussen <axelrasmussen@google.com> Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_hist.c | 2 ++ kernel/trace/trace_synth.h | 2 +- 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 1b2ef6490229..3b22e2122d1a 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -1398,6 +1398,8 @@ static int hist_trigger_elt_data_alloc(struct tracing_map_elt *elt) n_str = hist_data->n_field_var_str + hist_data->n_save_var_str; + BUILD_BUG_ON(STR_VAR_LEN_MAX & (sizeof(u64) - 1)); + size = STR_VAR_LEN_MAX; for (i = 0; i < n_str; i++) { diff --git a/kernel/trace/trace_synth.h b/kernel/trace/trace_synth.h index ac35c45207c4..5166705d1556 100644 --- a/kernel/trace/trace_synth.h +++ b/kernel/trace/trace_synth.h @@ -7,7 +7,7 @@ #define SYNTH_SYSTEM "synthetic" #define SYNTH_FIELDS_MAX 32 -#define STR_VAR_LEN_MAX 32 /* must be multiple of sizeof(u64) */ +#define STR_VAR_LEN_MAX MAX_FILTER_STR_VAL /* must be multiple of sizeof(u64) */ struct synth_field { char *type; -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* [PATCH v4 2/7] tracing: Fix parse_synth_field() error handling 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 1/7] tracing: Change STR_VAR_MAX_LEN Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 3/7] tracing: Save normal string variables Tom Zanussi ` (4 subsequent siblings) 6 siblings, 0 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel synth_field_size() returns either a positive size or an error (zero or a negative value). However, the existing code assumes the only error value is 0. It doesn't handle negative error codes, as it assigns directly to field->size (a size_t; unsigned), thereby interpreting the error code as a valid size instead. Do the test before assignment to field->size. [ axelrasmussen@google.com: changelog addition, first paragraph above ] Fixes: 4b147936fa50 (tracing: Add support for 'synthetic' events) Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org> Tested-by: Axel Rasmussen <axelrasmussen@google.com> Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_synth.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index a9cd7793f7ea..fa8a99828f41 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -465,6 +465,7 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, struct synth_field *field; const char *prefix = NULL, *field_type = argv[0], *field_name, *array; int len, ret = 0; + ssize_t size; if (field_type[0] == ';') field_type++; @@ -520,11 +521,12 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, field->type[len - 1] = '\0'; } - field->size = synth_field_size(field->type); - if (!field->size) { + size = synth_field_size(field->type); + if (size <= 0) { ret = -EINVAL; goto free; } + field->size = size; if (synth_field_is_string(field->type)) field->is_string = true; -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* [PATCH v4 3/7] tracing: Save normal string variables 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 1/7] tracing: Change STR_VAR_MAX_LEN Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 2/7] tracing: Fix parse_synth_field() error handling Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events Tom Zanussi ` (3 subsequent siblings) 6 siblings, 0 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel String variables created as field variables and save variables are already handled properly by having their values copied when set. The same isn't done for normal variables, but needs to be - simply saving a pointer to a string contained in an old event isn't sufficient, since that event's data may quickly become overwritten and therefore a string pointer to it could yield garbage. This change uses the same mechanism as field variables and simply appends the new strings to the existing per-element field_var_str[] array allocated for that purpose. Fixes: 02205a6752f2 (tracing: Add support for 'field variables') Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace_events_hist.c | 34 ++++++++++++++++++++++++++++++-- 1 file changed, 32 insertions(+), 2 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 3b22e2122d1a..812bc5f94b5c 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -147,6 +147,8 @@ struct hist_field { */ unsigned int var_ref_idx; bool read_once; + + unsigned int var_str_idx; }; static u64 hist_field_none(struct hist_field *field, @@ -349,6 +351,7 @@ struct hist_trigger_data { unsigned int n_keys; unsigned int n_fields; unsigned int n_vars; + unsigned int n_var_str; unsigned int key_size; struct tracing_map_sort_key sort_keys[TRACING_MAP_SORT_KEYS_MAX]; unsigned int n_sort_keys; @@ -1396,7 +1399,12 @@ static int hist_trigger_elt_data_alloc(struct tracing_map_elt *elt) } } - n_str = hist_data->n_field_var_str + hist_data->n_save_var_str; + n_str = hist_data->n_field_var_str + hist_data->n_save_var_str + + hist_data->n_var_str; + if (n_str > SYNTH_FIELDS_MAX) { + hist_elt_data_free(elt_data); + return -EINVAL; + } BUILD_BUG_ON(STR_VAR_LEN_MAX & (sizeof(u64) - 1)); @@ -3653,6 +3661,7 @@ static int create_var_field(struct hist_trigger_data *hist_data, { struct trace_array *tr = hist_data->event_file->tr; unsigned long flags = 0; + int ret; if (WARN_ON(val_idx >= TRACING_MAP_VALS_MAX + TRACING_MAP_VARS_MAX)) return -EINVAL; @@ -3667,7 +3676,12 @@ static int create_var_field(struct hist_trigger_data *hist_data, if (WARN_ON(hist_data->n_vars > TRACING_MAP_VARS_MAX)) return -EINVAL; - return __create_val_field(hist_data, val_idx, file, var_name, expr_str, flags); + ret = __create_val_field(hist_data, val_idx, file, var_name, expr_str, flags); + + if (hist_data->fields[val_idx]->flags & HIST_FIELD_FL_STRING) + hist_data->fields[val_idx]->var_str_idx = hist_data->n_var_str++; + + return ret; } static int create_val_fields(struct hist_trigger_data *hist_data, @@ -4394,6 +4408,22 @@ static void hist_trigger_elt_update(struct hist_trigger_data *hist_data, hist_val = hist_field->fn(hist_field, elt, rbe, rec); if (hist_field->flags & HIST_FIELD_FL_VAR) { var_idx = hist_field->var.idx; + + if (hist_field->flags & HIST_FIELD_FL_STRING) { + unsigned int str_start, var_str_idx, idx; + char *str, *val_str; + + str_start = hist_data->n_field_var_str + + hist_data->n_save_var_str; + var_str_idx = hist_field->var_str_idx; + idx = str_start + var_str_idx; + + str = elt_data->field_var_str[idx]; + val_str = (char *)(uintptr_t)hist_val; + strscpy(str, val_str, STR_VAR_LEN_MAX); + + hist_val = (u64)(uintptr_t)str; + } tracing_map_set_var(elt, var_idx, hist_val); continue; } -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi ` (2 preceding siblings ...) 2020-10-04 22:14 ` [PATCH v4 3/7] tracing: Save normal string variables Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-08 9:22 ` Masami Hiramatsu 2020-10-04 22:14 ` [PATCH v4 5/7] tracing: Add README information for synthetic_events file Tom Zanussi ` (2 subsequent siblings) 6 siblings, 1 reply; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Currently, sythetic events only support static string fields such as: # echo 'test_latency u64 lat; char somename[32]' > /sys/kernel/debug/tracing/synthetic_events Which is fine, but wastes a lot of space in the event. It also prevents the most commonly-defined strings in the existing trace events e.g. those defined using __string(), from being passed to synthetic events via the trace() action. With this change, synthetic events with dynamic fields can be defined: # echo 'test_latency u64 lat; char somename[]' > /sys/kernel/debug/tracing/synthetic_events And the trace() action can be used to generate events using either dynamic or static strings: # echo 'hist:keys=name:lat=common_timestamp.usecs-$ts0:onmatch(sys.event).test_latency($lat,name)' > /sys/kernel/debug/tracing/events The synthetic event dynamic strings are implemented in the same way as the existing __data_loc strings and appear as such in the format file. [ <rostedt@goodmis.org>: added __set_synth_event_print_fmt() changes: I added the following to make it work with trace-cmd. Dynamic strings must have __get_str() for events in the print_fmt otherwise it can't be parsed correctly. ] Tested-by: Axel Rasmussen <axelrasmussen@google.com> Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- Documentation/trace/events.rst | 15 +- Documentation/trace/histogram.rst | 18 ++ kernel/trace/synth_event_gen_test.c | 18 +- kernel/trace/trace_events_hist.c | 9 + kernel/trace/trace_events_synth.c | 248 ++++++++++++++++++++++++---- kernel/trace/trace_synth.h | 4 + 6 files changed, 272 insertions(+), 40 deletions(-) diff --git a/Documentation/trace/events.rst b/Documentation/trace/events.rst index f792b1959a33..2a5aa48eff6c 100644 --- a/Documentation/trace/events.rst +++ b/Documentation/trace/events.rst @@ -589,8 +589,19 @@ name:: { .type = "int", .name = "my_int_field" }, }; -See synth_field_size() for available types. If field_name contains [n] -the field is considered to be an array. +See synth_field_size() for available types. + +If field_name contains [n], the field is considered to be a static array. + +If field_names contains[] (no subscript), the field is considered to +be a dynamic array, which will only take as much space in the event as +is required to hold the array. + +Because space for an event is reserved before assigning field values +to the event, using dynamic arrays implies that the piecewise +in-kernel API described below can't be used with dynamic arrays. The +other non-piecewise in-kernel APIs can, however, be used with dynamic +arrays. If the event is created from within a module, a pointer to the module must be passed to synth_event_create(). This will ensure that the diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index 8408670d0328..b573604deabd 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1776,6 +1776,24 @@ consisting of the name of the new event along with one or more variables and their types, which can be any valid field type, separated by semicolons, to the tracing/synthetic_events file. +See synth_field_size() for available types. + +If field_name contains [n], the field is considered to be a static array. + +If field_names contains[] (no subscript), the field is considered to +be a dynamic array, which will only take as much space in the event as +is required to hold the array. + +A string field can be specified using either the static notation: + + char name[32]; + +Or the dynamic: + + char name[]; + +The size limit for either is 256. + For instance, the following creates a new event named 'wakeup_latency' with 3 fields: lat, pid, and prio. Each of those fields is simply a variable reference to a variable on another event:: diff --git a/kernel/trace/synth_event_gen_test.c b/kernel/trace/synth_event_gen_test.c index 7d56d621ffea..edd912cd14aa 100644 --- a/kernel/trace/synth_event_gen_test.c +++ b/kernel/trace/synth_event_gen_test.c @@ -242,9 +242,11 @@ static struct synth_field_desc create_synth_test_fields[] = { { .type = "pid_t", .name = "next_pid_field" }, { .type = "char[16]", .name = "next_comm_field" }, { .type = "u64", .name = "ts_ns" }, + { .type = "char[]", .name = "dynstring_field_1" }, { .type = "u64", .name = "ts_ms" }, { .type = "unsigned int", .name = "cpu" }, { .type = "char[64]", .name = "my_string_field" }, + { .type = "char[]", .name = "dynstring_field_2" }, { .type = "int", .name = "my_int_field" }, }; @@ -254,7 +256,7 @@ static struct synth_field_desc create_synth_test_fields[] = { */ static int __init test_create_synth_event(void) { - u64 vals[7]; + u64 vals[9]; int ret; /* Create the create_synth_test event with the fields above */ @@ -292,10 +294,12 @@ static int __init test_create_synth_event(void) vals[0] = 777; /* next_pid_field */ vals[1] = (u64)(long)"tiddlywinks"; /* next_comm_field */ vals[2] = 1000000; /* ts_ns */ - vals[3] = 1000; /* ts_ms */ - vals[4] = raw_smp_processor_id(); /* cpu */ - vals[5] = (u64)(long)"thneed"; /* my_string_field */ - vals[6] = 398; /* my_int_field */ + vals[3] = (u64)(long)"xrayspecs"; /* dynstring_field_1 */ + vals[4] = 1000; /* ts_ms */ + vals[5] = raw_smp_processor_id(); /* cpu */ + vals[6] = (u64)(long)"thneed"; /* my_string_field */ + vals[7] = (u64)(long)"kerplunk"; /* dynstring_field_2 */ + vals[8] = 398; /* my_int_field */ /* Now generate a create_synth_test event */ ret = synth_event_trace_array(create_synth_test, vals, ARRAY_SIZE(vals)); @@ -422,13 +426,15 @@ static int __init test_trace_synth_event(void) int ret; /* Trace some bogus values just for testing */ - ret = synth_event_trace(create_synth_test, 7, /* number of values */ + ret = synth_event_trace(create_synth_test, 9, /* number of values */ (u64)444, /* next_pid_field */ (u64)(long)"clackers", /* next_comm_field */ (u64)1000000, /* ts_ns */ + (u64)(long)"viewmaster",/* dynstring_field_1 */ (u64)1000, /* ts_ms */ (u64)raw_smp_processor_id(), /* cpu */ (u64)(long)"Thneed", /* my_string_field */ + (u64)(long)"yoyos", /* dynstring_field_2 */ (u64)999); /* my_int_field */ return ret; } diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c index 812bc5f94b5c..c74a7d157306 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -3289,6 +3289,15 @@ static int check_synth_field(struct synth_event *event, field = event->fields[field_pos]; + /* + * A dynamic string synth field can accept static or + * dynamic. A static string synth field can only accept a + * same-sized static string, which is checked for later. + */ + if (strstr(hist_field->type, "char[") && field->is_string + && field->is_dynamic) + return 0; + if (strcmp(field->type, hist_field->type) != 0) { if (field->size != hist_field->size || field->is_signed != hist_field->is_signed) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index fa8a99828f41..24bc6d61aa40 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -88,7 +88,7 @@ static int synth_event_define_fields(struct trace_event_call *call) event->fields[i]->offset = n_u64; - if (event->fields[i]->is_string) { + if (event->fields[i]->is_string && !event->fields[i]->is_dynamic) { offset += STR_VAR_LEN_MAX; n_u64 += STR_VAR_LEN_MAX / sizeof(u64); } else { @@ -139,6 +139,9 @@ static int synth_field_string_size(char *type) if (len > 3) return -EINVAL; + if (len == 0) + return 0; /* variable-length string */ + strncpy(buf, start, len); buf[len] = '\0'; @@ -290,10 +293,25 @@ static enum print_line_t print_synth_event(struct trace_iterator *iter, /* parameter values */ if (se->fields[i]->is_string) { - trace_seq_printf(s, print_fmt, se->fields[i]->name, - (char *)&entry->fields[n_u64], - i == se->n_fields - 1 ? "" : " "); - n_u64 += STR_VAR_LEN_MAX / sizeof(u64); + if (se->fields[i]->is_dynamic) { + u32 offset, data_offset; + char *str_field; + + offset = (u32)entry->fields[n_u64]; + data_offset = offset & 0xffff; + + str_field = (char *)entry + data_offset; + + trace_seq_printf(s, print_fmt, se->fields[i]->name, + str_field, + i == se->n_fields - 1 ? "" : " "); + n_u64++; + } else { + trace_seq_printf(s, print_fmt, se->fields[i]->name, + (char *)&entry->fields[n_u64], + i == se->n_fields - 1 ? "" : " "); + n_u64 += STR_VAR_LEN_MAX / sizeof(u64); + } } else { struct trace_print_flags __flags[] = { __def_gfpflag_names, {-1, NULL} }; @@ -325,16 +343,52 @@ static struct trace_event_functions synth_event_funcs = { .trace = print_synth_event }; +static unsigned int trace_string(struct synth_trace_event *entry, + struct synth_event *event, + char *str_val, + bool is_dynamic, + unsigned int data_size, + unsigned int *n_u64) +{ + unsigned int len = 0; + char *str_field; + + if (is_dynamic) { + u32 data_offset; + + data_offset = offsetof(typeof(*entry), fields); + data_offset += event->n_u64 * sizeof(u64); + data_offset += data_size; + + str_field = (char *)entry + data_offset; + + len = strlen(str_val) + 1; + strscpy(str_field, str_val, len); + + data_offset |= len << 16; + *(u32 *)&entry->fields[*n_u64] = data_offset; + + (*n_u64)++; + } else { + str_field = (char *)&entry->fields[*n_u64]; + + strscpy(str_field, str_val, STR_VAR_LEN_MAX); + (*n_u64) += STR_VAR_LEN_MAX / sizeof(u64); + } + + return len; +} + static notrace void trace_event_raw_event_synth(void *__data, u64 *var_ref_vals, unsigned int *var_ref_idx) { + unsigned int i, n_u64, val_idx, len, data_size = 0; struct trace_event_file *trace_file = __data; struct synth_trace_event *entry; struct trace_event_buffer fbuffer; struct trace_buffer *buffer; struct synth_event *event; - unsigned int i, n_u64, val_idx; int fields_size = 0; event = trace_file->event_call->data; @@ -344,6 +398,18 @@ static notrace void trace_event_raw_event_synth(void *__data, fields_size = event->n_u64 * sizeof(u64); + for (i = 0; i < event->n_dynamic_fields; i++) { + unsigned int field_pos = event->dynamic_fields[i]->field_pos; + char *str_val; + + val_idx = var_ref_idx[field_pos]; + str_val = (char *)(long)var_ref_vals[val_idx]; + + len = strlen(str_val) + 1; + + fields_size += len; + } + /* * Avoid ring buffer recursion detection, as this event * is being performed within another event. @@ -360,10 +426,11 @@ static notrace void trace_event_raw_event_synth(void *__data, val_idx = var_ref_idx[i]; if (event->fields[i]->is_string) { char *str_val = (char *)(long)var_ref_vals[val_idx]; - char *str_field = (char *)&entry->fields[n_u64]; - strscpy(str_field, str_val, STR_VAR_LEN_MAX); - n_u64 += STR_VAR_LEN_MAX / sizeof(u64); + len = trace_string(entry, event, str_val, + event->fields[i]->is_dynamic, + data_size, &n_u64); + data_size += len; /* only dynamic string increments */ } else { struct synth_field *field = event->fields[i]; u64 val = var_ref_vals[val_idx]; @@ -422,8 +489,13 @@ static int __set_synth_event_print_fmt(struct synth_event *event, pos += snprintf(buf + pos, LEN_OR_ZERO, "\""); for (i = 0; i < event->n_fields; i++) { - pos += snprintf(buf + pos, LEN_OR_ZERO, - ", REC->%s", event->fields[i]->name); + if (event->fields[i]->is_dynamic && + event->fields[i]->is_dynamic) + pos += snprintf(buf + pos, LEN_OR_ZERO, + ", __get_str(%s)", event->fields[i]->name); + else + pos += snprintf(buf + pos, LEN_OR_ZERO, + ", REC->%s", event->fields[i]->name); } #undef LEN_OR_ZERO @@ -522,9 +594,30 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, } size = synth_field_size(field->type); - if (size <= 0) { + if (size < 0) { ret = -EINVAL; goto free; + } else if (size == 0) { + if (synth_field_is_string(field->type)) { + char *type; + + type = kzalloc(sizeof("__data_loc ") + strlen(field->type) + 1, GFP_KERNEL); + if (!type) { + ret = -ENOMEM; + goto free; + } + + strcat(type, "__data_loc "); + strcat(type, field->type); + kfree(field->type); + field->type = type; + + field->is_dynamic = true; + size = sizeof(u64); + } else { + ret = -EINVAL; + goto free; + } } field->size = size; @@ -532,7 +625,6 @@ static struct synth_field *parse_synth_field(int argc, const char **argv, field->is_string = true; field->is_signed = synth_field_signed(field->type); - out: return field; free: @@ -663,6 +755,7 @@ static void free_synth_event(struct synth_event *event) free_synth_field(event->fields[i]); kfree(event->fields); + kfree(event->dynamic_fields); kfree(event->name); kfree(event->class.system); free_synth_tracepoint(event->tp); @@ -673,8 +766,8 @@ static void free_synth_event(struct synth_event *event) static struct synth_event *alloc_synth_event(const char *name, int n_fields, struct synth_field **fields) { + unsigned int i, j, n_dynamic_fields = 0; struct synth_event *event; - unsigned int i; event = kzalloc(sizeof(*event), GFP_KERNEL); if (!event) { @@ -696,11 +789,33 @@ static struct synth_event *alloc_synth_event(const char *name, int n_fields, goto out; } + for (i = 0; i < n_fields; i++) + if (fields[i]->is_dynamic) + n_dynamic_fields++; + + if (n_dynamic_fields) { + event->dynamic_fields = kcalloc(n_dynamic_fields, + sizeof(*event->dynamic_fields), + GFP_KERNEL); + if (!event->dynamic_fields) { + free_synth_event(event); + event = ERR_PTR(-ENOMEM); + goto out; + } + } + dyn_event_init(&event->devent, &synth_event_ops); - for (i = 0; i < n_fields; i++) + for (i = 0, j = 0; i < n_fields; i++) { event->fields[i] = fields[i]; + if (fields[i]->is_dynamic) { + event->dynamic_fields[j] = fields[i]; + event->dynamic_fields[j]->field_pos = i; + event->dynamic_fields[j++] = fields[i]; + event->n_dynamic_fields++; + } + } event->n_fields = n_fields; out: return event; @@ -712,6 +827,10 @@ static int synth_event_check_arg_fn(void *data) int size; size = synth_field_size((char *)arg_pair->lhs); + if (size == 0) { + if (strstr((char *)arg_pair->lhs, "[")) + return 0; + } return size ? 0 : -EINVAL; } @@ -1200,10 +1319,9 @@ void synth_event_cmd_init(struct dynevent_cmd *cmd, char *buf, int maxlen) EXPORT_SYMBOL_GPL(synth_event_cmd_init); static inline int -__synth_event_trace_start(struct trace_event_file *file, - struct synth_event_trace_state *trace_state) +__synth_event_trace_init(struct trace_event_file *file, + struct synth_event_trace_state *trace_state) { - int entry_size, fields_size = 0; int ret = 0; memset(trace_state, '\0', sizeof(*trace_state)); @@ -1225,8 +1343,20 @@ __synth_event_trace_start(struct trace_event_file *file, } trace_state->event = file->event_call->data; +out: + return ret; +} + +static inline int +__synth_event_trace_start(struct trace_event_file *file, + struct synth_event_trace_state *trace_state, + int dynamic_fields_size) +{ + int entry_size, fields_size = 0; + int ret = 0; fields_size = trace_state->event->n_u64 * sizeof(u64); + fields_size += dynamic_fields_size; /* * Avoid ring buffer recursion detection, as this event @@ -1243,7 +1373,7 @@ __synth_event_trace_start(struct trace_event_file *file, ring_buffer_nest_end(trace_state->buffer); ret = -EINVAL; } -out: + return ret; } @@ -1276,23 +1406,46 @@ __synth_event_trace_end(struct synth_event_trace_state *trace_state) */ int synth_event_trace(struct trace_event_file *file, unsigned int n_vals, ...) { + unsigned int i, n_u64, len, data_size = 0; struct synth_event_trace_state state; - unsigned int i, n_u64; va_list args; int ret; - ret = __synth_event_trace_start(file, &state); + ret = __synth_event_trace_init(file, &state); if (ret) { if (ret == -ENOENT) ret = 0; /* just disabled, not really an error */ return ret; } + if (state.event->n_dynamic_fields) { + va_start(args, n_vals); + + for (i = 0; i < state.event->n_fields; i++) { + u64 val = va_arg(args, u64); + + if (state.event->fields[i]->is_string && + state.event->fields[i]->is_dynamic) { + char *str_val = (char *)(long)val; + + data_size += strlen(str_val) + 1; + } + } + + va_end(args); + } + + ret = __synth_event_trace_start(file, &state, data_size); + if (ret) + return ret; + if (n_vals != state.event->n_fields) { ret = -EINVAL; goto out; } + data_size = 0; + va_start(args, n_vals); for (i = 0, n_u64 = 0; i < state.event->n_fields; i++) { u64 val; @@ -1301,10 +1454,11 @@ int synth_event_trace(struct trace_event_file *file, unsigned int n_vals, ...) if (state.event->fields[i]->is_string) { char *str_val = (char *)(long)val; - char *str_field = (char *)&state.entry->fields[n_u64]; - strscpy(str_field, str_val, STR_VAR_LEN_MAX); - n_u64 += STR_VAR_LEN_MAX / sizeof(u64); + len = trace_string(state.entry, state.event, str_val, + state.event->fields[i]->is_dynamic, + data_size, &n_u64); + data_size += len; /* only dynamic string increments */ } else { struct synth_field *field = state.event->fields[i]; @@ -1357,29 +1511,46 @@ EXPORT_SYMBOL_GPL(synth_event_trace); int synth_event_trace_array(struct trace_event_file *file, u64 *vals, unsigned int n_vals) { + unsigned int i, n_u64, field_pos, len, data_size = 0; struct synth_event_trace_state state; - unsigned int i, n_u64; + char *str_val; int ret; - ret = __synth_event_trace_start(file, &state); + ret = __synth_event_trace_init(file, &state); if (ret) { if (ret == -ENOENT) ret = 0; /* just disabled, not really an error */ return ret; } + if (state.event->n_dynamic_fields) { + for (i = 0; i < state.event->n_dynamic_fields; i++) { + field_pos = state.event->dynamic_fields[i]->field_pos; + str_val = (char *)(long)vals[field_pos]; + len = strlen(str_val) + 1; + data_size += len; + } + } + + ret = __synth_event_trace_start(file, &state, data_size); + if (ret) + return ret; + if (n_vals != state.event->n_fields) { ret = -EINVAL; goto out; } + data_size = 0; + for (i = 0, n_u64 = 0; i < state.event->n_fields; i++) { if (state.event->fields[i]->is_string) { char *str_val = (char *)(long)vals[i]; - char *str_field = (char *)&state.entry->fields[n_u64]; - strscpy(str_field, str_val, STR_VAR_LEN_MAX); - n_u64 += STR_VAR_LEN_MAX / sizeof(u64); + len = trace_string(state.entry, state.event, str_val, + state.event->fields[i]->is_dynamic, + data_size, &n_u64); + data_size += len; /* only dynamic string increments */ } else { struct synth_field *field = state.event->fields[i]; u64 val = vals[i]; @@ -1447,9 +1618,17 @@ int synth_event_trace_start(struct trace_event_file *file, if (!trace_state) return -EINVAL; - ret = __synth_event_trace_start(file, trace_state); - if (ret == -ENOENT) - ret = 0; /* just disabled, not really an error */ + ret = __synth_event_trace_init(file, trace_state); + if (ret) { + if (ret == -ENOENT) + ret = 0; /* just disabled, not really an error */ + return ret; + } + + if (trace_state->event->n_dynamic_fields) + return -ENOTSUPP; + + ret = __synth_event_trace_start(file, trace_state, 0); return ret; } @@ -1510,6 +1689,11 @@ static int __synth_event_add_val(const char *field_name, u64 val, char *str_val = (char *)(long)val; char *str_field; + if (field->is_dynamic) { /* add_val can't do dynamic strings */ + ret = -EINVAL; + goto out; + } + if (!str_val) { ret = -EINVAL; goto out; diff --git a/kernel/trace/trace_synth.h b/kernel/trace/trace_synth.h index 5166705d1556..6e146b959dcd 100644 --- a/kernel/trace/trace_synth.h +++ b/kernel/trace/trace_synth.h @@ -16,6 +16,8 @@ struct synth_field { unsigned int offset; bool is_signed; bool is_string; + bool is_dynamic; + bool field_pos; }; struct synth_event { @@ -24,6 +26,8 @@ struct synth_event { char *name; struct synth_field **fields; unsigned int n_fields; + struct synth_field **dynamic_fields; + unsigned int n_dynamic_fields; unsigned int n_u64; struct trace_event_class class; struct trace_event_call call; -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events 2020-10-04 22:14 ` [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events Tom Zanussi @ 2020-10-08 9:22 ` Masami Hiramatsu 2020-10-08 19:21 ` Steven Rostedt 2020-10-08 20:33 ` Tom Zanussi 0 siblings, 2 replies; 16+ messages in thread From: Masami Hiramatsu @ 2020-10-08 9:22 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel Hi Tom, On Sun, 4 Oct 2020 17:14:06 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > Currently, sythetic events only support static string fields such as: > > # echo 'test_latency u64 lat; char somename[32]' > /sys/kernel/debug/tracing/synthetic_events > > Which is fine, but wastes a lot of space in the event. > > It also prevents the most commonly-defined strings in the existing > trace events e.g. those defined using __string(), from being passed to > synthetic events via the trace() action. > > With this change, synthetic events with dynamic fields can be defined: > > # echo 'test_latency u64 lat; char somename[]' > /sys/kernel/debug/tracing/synthetic_events > > And the trace() action can be used to generate events using either > dynamic or static strings: > > # echo 'hist:keys=name:lat=common_timestamp.usecs-$ts0:onmatch(sys.event).test_latency($lat,name)' > /sys/kernel/debug/tracing/events > > The synthetic event dynamic strings are implemented in the same way as > the existing __data_loc strings and appear as such in the format file. > > [ <rostedt@goodmis.org>: added __set_synth_event_print_fmt() changes: > > I added the following to make it work with trace-cmd. Dynamic strings > must have __get_str() for events in the print_fmt otherwise it can't be > parsed correctly. ] I confirmed this works, but have some questions; - It seems no error message when we failed to define with wrong syntax /sys/kernel/debug/tracing # echo 'myevent char name []' >> synthetic_events sh: write error: Invalid argument /sys/kernel/debug/tracing # cat error_log /sys/kernel/debug/tracing # - what we write and what we see in synthetic_events are different /sys/kernel/debug/tracing # echo 'myevent char name[]' >> synthetic_events /sys/kernel/debug/tracing # cat synthetic_events myevent __data_loc char[] name - And it is not able to re-define with that syntax /sys/kernel/debug/tracing # echo > synthetic_events /sys/kernel/debug/tracing # echo 'myevent __data_loc char[] name' >> synthetic_events sh: write error: Invalid argument /sys/kernel/debug/tracing # - It seems to accept wrong name for variables /sys/kernel/debug/tracing # echo 'myevent char name]' >> synthetic_events /sys/kernel/debug/tracing # echo 'myevent2 char name;[]' >> synthetic_events /sys/kernel/debug/tracing # cat synthetic_events myevent char name] myevent2 __data_loc char[] name; Some of those issues are not introduced from this series. I think we'd better fix those before introducing this series so that we can backport it to stable kernels. Thank you, -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events 2020-10-08 9:22 ` Masami Hiramatsu @ 2020-10-08 19:21 ` Steven Rostedt 2020-10-09 11:15 ` Masami Hiramatsu 2020-10-08 20:33 ` Tom Zanussi 1 sibling, 1 reply; 16+ messages in thread From: Steven Rostedt @ 2020-10-08 19:21 UTC (permalink / raw) To: Masami Hiramatsu; +Cc: Tom Zanussi, axelrasmussen, linux-kernel On Thu, 8 Oct 2020 18:22:07 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > Some of those issues are not introduced from this series. I think > we'd better fix those before introducing this series so that > we can backport it to stable kernels. I agree that these should be fixed, but I'm not sure I want to hold off this series before they are. -- Steve ^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events 2020-10-08 19:21 ` Steven Rostedt @ 2020-10-09 11:15 ` Masami Hiramatsu 0 siblings, 0 replies; 16+ messages in thread From: Masami Hiramatsu @ 2020-10-09 11:15 UTC (permalink / raw) To: Steven Rostedt; +Cc: Tom Zanussi, axelrasmussen, linux-kernel On Thu, 8 Oct 2020 15:21:50 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Thu, 8 Oct 2020 18:22:07 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > Some of those issues are not introduced from this series. I think > > we'd better fix those before introducing this series so that > > we can backport it to stable kernels. > > I agree that these should be fixed, but I'm not sure I want to hold off > this series before they are. OK, I think the last event-name issue will be separated from this patch, but others are directly related this patch. So those need to be fixed in this series. Thank you, -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events 2020-10-08 9:22 ` Masami Hiramatsu 2020-10-08 19:21 ` Steven Rostedt @ 2020-10-08 20:33 ` Tom Zanussi 1 sibling, 0 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-08 20:33 UTC (permalink / raw) To: Masami Hiramatsu; +Cc: rostedt, axelrasmussen, linux-kernel Hi Masami, On Thu, 2020-10-08 at 18:22 +0900, Masami Hiramatsu wrote: > Hi Tom, > > On Sun, 4 Oct 2020 17:14:06 -0500 > Tom Zanussi <zanussi@kernel.org> wrote: > > > Currently, sythetic events only support static string fields such > > as: > > > > # echo 'test_latency u64 lat; char somename[32]' > > > /sys/kernel/debug/tracing/synthetic_events > > > > Which is fine, but wastes a lot of space in the event. > > > > It also prevents the most commonly-defined strings in the existing > > trace events e.g. those defined using __string(), from being passed > > to > > synthetic events via the trace() action. > > > > With this change, synthetic events with dynamic fields can be > > defined: > > > > # echo 'test_latency u64 lat; char somename[]' > > > /sys/kernel/debug/tracing/synthetic_events > > > > And the trace() action can be used to generate events using either > > dynamic or static strings: > > > > # echo 'hist:keys=name:lat=common_timestamp.usecs- > > $ts0:onmatch(sys.event).test_latency($lat,name)' > > > /sys/kernel/debug/tracing/events > > > > The synthetic event dynamic strings are implemented in the same way > > as > > the existing __data_loc strings and appear as such in the format > > file. > > > > [ <rostedt@goodmis.org>: added __set_synth_event_print_fmt() > > changes: > > > > I added the following to make it work with trace-cmd. Dynamic > > strings > > must have __get_str() for events in the print_fmt otherwise it > > can't be > > parsed correctly. ] > > I confirmed this works, but have some questions; > - It seems no error message when we failed to define with wrong > syntax Yes, I need to add an error message for this (as well as others in this file). > > /sys/kernel/debug/tracing # echo 'myevent char name []' >> > synthetic_events > sh: write error: Invalid argument > /sys/kernel/debug/tracing # cat error_log > /sys/kernel/debug/tracing # > > - what we write and what we see in synthetic_events are different > > /sys/kernel/debug/tracing # echo 'myevent char name[]' >> > synthetic_events > /sys/kernel/debug/tracing # cat synthetic_events > myevent __data_loc char[] name > > - And it is not able to re-define with that syntax > > /sys/kernel/debug/tracing # echo > synthetic_events > /sys/kernel/debug/tracing # echo 'myevent __data_loc char[] name' >> > synthetic_events > sh: write error: Invalid argument > /sys/kernel/debug/tracing # > Yes, only the format needs to have the __data_loc, but the event description shouldn't. > - It seems to accept wrong name for variables > > /sys/kernel/debug/tracing # echo 'myevent char name]' >> > synthetic_events > /sys/kernel/debug/tracing # echo 'myevent2 char name;[]' >> > synthetic_events > /sys/kernel/debug/tracing # cat synthetic_events > myevent char name] > myevent2 __data_loc char[] name; > Yes, I think all these other errors boil down to allowing illegal names. Applying your is_good_name() function for probe events to these fields should get rid of them. > Some of those issues are not introduced from this series. I think > we'd better fix those before introducing this series so that > we can backport it to stable kernels. > I should have patches addressing all of these shortly, tomorrow at the latest. Thanks, Tom > Thank you, > > ^ permalink raw reply [flat|nested] 16+ messages in thread
* [PATCH v4 5/7] tracing: Add README information for synthetic_events file 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi ` (3 preceding siblings ...) 2020-10-04 22:14 ` [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-08 0:38 ` Masami Hiramatsu 2020-10-04 22:14 ` [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length Tom Zanussi 6 siblings, 1 reply; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Add an entry with a basic description of events/synthetic_events along with a simple example. Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- kernel/trace/trace.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 3f2533adae72..73fd0e0c0f39 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -5249,7 +5249,12 @@ static const char readme_msg[] = "\t trace(<synthetic_event>,param list) - generate synthetic event\n" "\t save(field,...) - save current event fields\n" #ifdef CONFIG_TRACER_SNAPSHOT - "\t snapshot() - snapshot the trace buffer\n" + "\t snapshot() - snapshot the trace buffer\n\n" +#endif +#ifdef CONFIG_SYNTH_EVENTS + " events/synthetic_events\t- Create/append/remove/show synthetic events\n" + "\t Write into this file to define/undefine new synthetic events.\n" + "\t example: echo 'myevent u64 lat; char name[]' >> synthetic_events\n" #endif #endif ; -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [PATCH v4 5/7] tracing: Add README information for synthetic_events file 2020-10-04 22:14 ` [PATCH v4 5/7] tracing: Add README information for synthetic_events file Tom Zanussi @ 2020-10-08 0:38 ` Masami Hiramatsu 0 siblings, 0 replies; 16+ messages in thread From: Masami Hiramatsu @ 2020-10-08 0:38 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel Hi Tom, On Sun, 4 Oct 2020 17:14:07 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > Add an entry with a basic description of events/synthetic_events along > with a simple example. > > Signed-off-by: Tom Zanussi <zanussi@kernel.org> This looks good to me. Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org> Thank you, > --- > kernel/trace/trace.c | 7 ++++++- > 1 file changed, 6 insertions(+), 1 deletion(-) > > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c > index 3f2533adae72..73fd0e0c0f39 100644 > --- a/kernel/trace/trace.c > +++ b/kernel/trace/trace.c > @@ -5249,7 +5249,12 @@ static const char readme_msg[] = > "\t trace(<synthetic_event>,param list) - generate synthetic event\n" > "\t save(field,...) - save current event fields\n" > #ifdef CONFIG_TRACER_SNAPSHOT > - "\t snapshot() - snapshot the trace buffer\n" > + "\t snapshot() - snapshot the trace buffer\n\n" > +#endif > +#ifdef CONFIG_SYNTH_EVENTS > + " events/synthetic_events\t- Create/append/remove/show synthetic events\n" > + "\t Write into this file to define/undefine new synthetic events.\n" > + "\t example: echo 'myevent u64 lat; char name[]' >> synthetic_events\n" > #endif > #endif > ; > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 16+ messages in thread
* [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi ` (4 preceding siblings ...) 2020-10-04 22:14 ` [PATCH v4 5/7] tracing: Add README information for synthetic_events file Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-08 0:21 ` Masami Hiramatsu 2020-10-04 22:14 ` [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length Tom Zanussi 6 siblings, 1 reply; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel Add a selftest that defines and traces a synthetic event that uses a dynamic string event field. Signed-off-by: Tom Zanussi <zanussi@kernel.org> --- .../trigger-synthetic-event-dynstring.tc | 31 +++++++++++++++++++ 1 file changed, 31 insertions(+) create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc new file mode 100644 index 000000000000..3d65c856eca3 --- /dev/null +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc @@ -0,0 +1,31 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: event trigger - test inter-event histogram trigger trace action with dynamic string param +# requires: set_event synthetic_events events/sched/sched_process_exec/hist "char name[]' >> synthetic_events":README + +fail() { #msg + echo $1 + exit_fail +} + +echo "Test create synthetic event" + +echo 'ping_test_latency u64 lat; char filename[]' > synthetic_events +if [ ! -d events/synthetic/ping_test_latency ]; then + fail "Failed to create ping_test_latency synthetic event" +fi + +echo "Test create histogram for synthetic event using trace action and dynamic strings" +echo "Test histogram dynamic string variables,simple expression support and trace action" + +echo 'hist:key=pid:filenamevar=filename:ts0=common_timestamp.usecs' > events/sched/sched_process_exec/trigger +echo 'hist:key=pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_process_exec).ping_test_latency($lat,$filenamevar) if comm == "ping"' > events/sched/sched_process_exit/trigger +echo 'hist:keys=filename,lat:sort=filename,lat' > events/synthetic/ping_test_latency/trigger + +ping $LOCALHOST -c 5 + +if ! grep -q "ping" events/synthetic/ping_test_latency/hist; then + fail "Failed to create dynamic string trace action inter-event histogram" +fi + +exit 0 -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings 2020-10-04 22:14 ` [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings Tom Zanussi @ 2020-10-08 0:21 ` Masami Hiramatsu 0 siblings, 0 replies; 16+ messages in thread From: Masami Hiramatsu @ 2020-10-08 0:21 UTC (permalink / raw) To: Tom Zanussi; +Cc: rostedt, axelrasmussen, mhiramat, linux-kernel On Sun, 4 Oct 2020 17:14:08 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > Add a selftest that defines and traces a synthetic event that uses a > dynamic string event field. > > Signed-off-by: Tom Zanussi <zanussi@kernel.org> This looks good to me. Acked-by: Masami Hiramatsu <mhiramat@kernel.org> Thank you! > --- > .../trigger-synthetic-event-dynstring.tc | 31 +++++++++++++++++++ > 1 file changed, 31 insertions(+) > create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc > > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc > new file mode 100644 > index 000000000000..3d65c856eca3 > --- /dev/null > +++ b/tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-synthetic-event-dynstring.tc > @@ -0,0 +1,31 @@ > +#!/bin/sh > +# SPDX-License-Identifier: GPL-2.0 > +# description: event trigger - test inter-event histogram trigger trace action with dynamic string param > +# requires: set_event synthetic_events events/sched/sched_process_exec/hist "char name[]' >> synthetic_events":README > + > +fail() { #msg > + echo $1 > + exit_fail > +} > + > +echo "Test create synthetic event" > + > +echo 'ping_test_latency u64 lat; char filename[]' > synthetic_events > +if [ ! -d events/synthetic/ping_test_latency ]; then > + fail "Failed to create ping_test_latency synthetic event" > +fi > + > +echo "Test create histogram for synthetic event using trace action and dynamic strings" > +echo "Test histogram dynamic string variables,simple expression support and trace action" > + > +echo 'hist:key=pid:filenamevar=filename:ts0=common_timestamp.usecs' > events/sched/sched_process_exec/trigger > +echo 'hist:key=pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_process_exec).ping_test_latency($lat,$filenamevar) if comm == "ping"' > events/sched/sched_process_exit/trigger > +echo 'hist:keys=filename,lat:sort=filename,lat' > events/synthetic/ping_test_latency/trigger > + > +ping $LOCALHOST -c 5 > + > +if ! grep -q "ping" events/synthetic/ping_test_latency/hist; then > + fail "Failed to create dynamic string trace action inter-event histogram" > +fi > + > +exit 0 > -- > 2.17.1 > -- Masami Hiramatsu <mhiramat@kernel.org> ^ permalink raw reply [flat|nested] 16+ messages in thread
* [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi ` (5 preceding siblings ...) 2020-10-04 22:14 ` [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings Tom Zanussi @ 2020-10-04 22:14 ` Tom Zanussi 2020-10-05 22:17 ` Steven Rostedt 6 siblings, 1 reply; 16+ messages in thread From: Tom Zanussi @ 2020-10-04 22:14 UTC (permalink / raw) To: rostedt, axelrasmussen; +Cc: mhiramat, linux-kernel From: Steven Rostedt <rostedt@goodmis.org> Change the format for printing synthetic field strings to limit the length of the string printed even if it's not correctly terminated. Description from Steve: I also added this for a bit of paranoid, and probably should be a separate patch, just to make sure if the string isn't nul terminated, this will keep it from bleeding pass the end of the string. --- kernel/trace/trace_events_synth.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c index 24bc6d61aa40..742ce5f62d6d 100644 --- a/kernel/trace/trace_events_synth.c +++ b/kernel/trace/trace_events_synth.c @@ -234,7 +234,7 @@ static const char *synth_field_fmt(char *type) else if (strcmp(type, "gfp_t") == 0) fmt = "%x"; else if (synth_field_is_string(type)) - fmt = "%s"; + fmt = "%.*s"; return fmt; } @@ -303,11 +303,13 @@ static enum print_line_t print_synth_event(struct trace_iterator *iter, str_field = (char *)entry + data_offset; trace_seq_printf(s, print_fmt, se->fields[i]->name, + STR_VAR_LEN_MAX, str_field, i == se->n_fields - 1 ? "" : " "); n_u64++; } else { trace_seq_printf(s, print_fmt, se->fields[i]->name, + STR_VAR_LEN_MAX, (char *)&entry->fields[n_u64], i == se->n_fields - 1 ? "" : " "); n_u64 += STR_VAR_LEN_MAX / sizeof(u64); -- 2.17.1 ^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length 2020-10-04 22:14 ` [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length Tom Zanussi @ 2020-10-05 22:17 ` Steven Rostedt 2020-10-07 14:24 ` Tom Zanussi 0 siblings, 1 reply; 16+ messages in thread From: Steven Rostedt @ 2020-10-05 22:17 UTC (permalink / raw) To: Tom Zanussi; +Cc: axelrasmussen, mhiramat, linux-kernel On Sun, 4 Oct 2020 17:14:09 -0500 Tom Zanussi <zanussi@kernel.org> wrote: > From: Steven Rostedt <rostedt@goodmis.org> > > Change the format for printing synthetic field strings to limit the > length of the string printed even if it's not correctly terminated. > > Description from Steve: > > I also added this for a bit of paranoid, and probably should be a > separate patch, just to make sure if the string isn't nul terminated, > this will keep it from bleeding pass the end of the string. Just FYI. In the future, for something like this, you should still have your own Signed-off-by, as you are sending it (and part of the commit path). You could also add: [ Need signed-off-by from Steven ] Which I would have also added as well. Thanks! -- Steve > --- > kernel/trace/trace_events_synth.c | 4 +++- > 1 file changed, 3 insertions(+), 1 deletion(-) > > diff --git a/kernel/trace/trace_events_synth.c b/kernel/trace/trace_events_synth.c > index 24bc6d61aa40..742ce5f62d6d 100644 > --- a/kernel/trace/trace_events_synth.c > +++ b/kernel/trace/trace_events_synth.c > @@ -234,7 +234,7 @@ static const char *synth_field_fmt(char *type) > else if (strcmp(type, "gfp_t") == 0) > fmt = "%x"; > else if (synth_field_is_string(type)) > - fmt = "%s"; > + fmt = "%.*s"; > > return fmt; > } > @@ -303,11 +303,13 @@ static enum print_line_t print_synth_event(struct trace_iterator *iter, > str_field = (char *)entry + data_offset; > > trace_seq_printf(s, print_fmt, se->fields[i]->name, > + STR_VAR_LEN_MAX, > str_field, > i == se->n_fields - 1 ? "" : " "); > n_u64++; > } else { > trace_seq_printf(s, print_fmt, se->fields[i]->name, > + STR_VAR_LEN_MAX, > (char *)&entry->fields[n_u64], > i == se->n_fields - 1 ? "" : " "); > n_u64 += STR_VAR_LEN_MAX / sizeof(u64); ^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length 2020-10-05 22:17 ` Steven Rostedt @ 2020-10-07 14:24 ` Tom Zanussi 0 siblings, 0 replies; 16+ messages in thread From: Tom Zanussi @ 2020-10-07 14:24 UTC (permalink / raw) To: Steven Rostedt; +Cc: axelrasmussen, mhiramat, linux-kernel Hi Steve, On Mon, 2020-10-05 at 18:17 -0400, Steven Rostedt wrote: > On Sun, 4 Oct 2020 17:14:09 -0500 > Tom Zanussi <zanussi@kernel.org> wrote: > > > From: Steven Rostedt <rostedt@goodmis.org> > > > > Change the format for printing synthetic field strings to limit the > > length of the string printed even if it's not correctly terminated. > > > > Description from Steve: > > > > I also added this for a bit of paranoid, and probably should be a > > separate patch, just to make sure if the string isn't nul > > terminated, > > this will keep it from bleeding pass the end of the string. > > Just FYI. In the future, for something like this, you should still > have > your own Signed-off-by, as you are sending it (and part of the commit > path). You could also add: > > [ Need signed-off-by from Steven ] > > Which I would have also added as well. > Yeah, will do that next time. Thanks for the tip. Tom > Thanks! > > -- Steve > > > > --- > > kernel/trace/trace_events_synth.c | 4 +++- > > 1 file changed, 3 insertions(+), 1 deletion(-) > > > > diff --git a/kernel/trace/trace_events_synth.c > > b/kernel/trace/trace_events_synth.c > > index 24bc6d61aa40..742ce5f62d6d 100644 > > --- a/kernel/trace/trace_events_synth.c > > +++ b/kernel/trace/trace_events_synth.c > > @@ -234,7 +234,7 @@ static const char *synth_field_fmt(char *type) > > else if (strcmp(type, "gfp_t") == 0) > > fmt = "%x"; > > else if (synth_field_is_string(type)) > > - fmt = "%s"; > > + fmt = "%.*s"; > > > > return fmt; > > } > > @@ -303,11 +303,13 @@ static enum print_line_t > > print_synth_event(struct trace_iterator *iter, > > str_field = (char *)entry + > > data_offset; > > > > trace_seq_printf(s, print_fmt, se- > > >fields[i]->name, > > + STR_VAR_LEN_MAX, > > str_field, > > i == se->n_fields - 1 > > ? "" : " "); > > n_u64++; > > } else { > > trace_seq_printf(s, print_fmt, se- > > >fields[i]->name, > > + STR_VAR_LEN_MAX, > > (char *)&entry- > > >fields[n_u64], > > i == se->n_fields - 1 > > ? "" : " "); > > n_u64 += STR_VAR_LEN_MAX / sizeof(u64); > > ^ permalink raw reply [flat|nested] 16+ messages in thread
end of thread, other threads:[~2020-10-09 11:15 UTC | newest] Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2020-10-04 22:14 [PATCH v4 0/7] tracing: Add dynamic strings for synthetic events Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 1/7] tracing: Change STR_VAR_MAX_LEN Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 2/7] tracing: Fix parse_synth_field() error handling Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 3/7] tracing: Save normal string variables Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 4/7] tracing: Add support for dynamic strings to synthetic events Tom Zanussi 2020-10-08 9:22 ` Masami Hiramatsu 2020-10-08 19:21 ` Steven Rostedt 2020-10-09 11:15 ` Masami Hiramatsu 2020-10-08 20:33 ` Tom Zanussi 2020-10-04 22:14 ` [PATCH v4 5/7] tracing: Add README information for synthetic_events file Tom Zanussi 2020-10-08 0:38 ` Masami Hiramatsu 2020-10-04 22:14 ` [PATCH v4 6/7] selftests/ftrace: Add test case for synthetic event dynamic strings Tom Zanussi 2020-10-08 0:21 ` Masami Hiramatsu 2020-10-04 22:14 ` [PATCH v4 7/7] tracing: Change synthetic event string format to limit printed length Tom Zanussi 2020-10-05 22:17 ` Steven Rostedt 2020-10-07 14:24 ` Tom Zanussi
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.