Commit bd82631d authored by Tom Zanussi's avatar Tom Zanussi Committed by Steven Rostedt (VMware)
Browse files

tracing: Add support for dynamic strings to synthetic events 

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

Link: https://lore.kernel.org/r/cover.1601588066.git.zanussi@kernel.org
Link: https://lkml.kernel.org/r/3ed35b6d0e390f5b94cb4a9ba1cc18f5982ab277.1601848695.git.zanussi@kernel.org



Tested-by: default avatarAxel Rasmussen <axelrasmussen@google.com>
Signed-off-by: default avatarTom Zanussi <zanussi@kernel.org>
Signed-off-by: default avatarSteven Rostedt (VMware) <rostedt@goodmis.org>
parent 63a1e5de

Documentation/trace/events.rst

+13 −2
Original line number Diff line number Diff line
@@ -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

Documentation/trace/histogram.rst

+18 −0
Original line number Diff line number Diff line
@@ -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::

kernel/trace/synth_event_gen_test.c

+12 −6
Original line number Diff line number Diff line
@@ -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;

}

kernel/trace/trace_events_hist.c

+9 −0
Original line number Diff line number Diff line
@@ -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)

kernel/trace/trace_events_synth.c

+216 −32
Original line number Diff line number Diff line
@@ -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) {

			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,6 +489,11 @@ 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++) {

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

	}
@@ -522,17 +594,37 @@ 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;



	if (synth_field_is_string(field->type))

		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,

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

	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;

CRA Git | Maintained and supported by SUSTech CRA and CCSE