[PATCH v2 0/3] Changes in few libtraceevent APIs

[PATCH v2 0/3] Changes in few libtraceevent APIs

[Tzvetomir Stoyanov (VMware)]

Before releasing libtraceevent as a standalone library, few
APIs must be changed:
 - Event printing interface is redesigned, to be more simple
   and user friendly. Now the tep_print_event() API can be used 
   to print various event information. All other event print APIs
   are removed.
 - Changed the user's plugin directory to 
   ~/.local/lib/traceevent/plugins/ to be XDG compliant.

[
 v2 canges:
  - the user's plugin directory changed from 
 ~/.config/traceevent/plugins/ to ~/.local/lib/traceevent/plugins/, 
 as suggested by Patrick McLean.
]

Tzvetomir Stoyanov (3):
  tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs
  tools/lib/traceevent: Remove tep_register_trace_clock()
  tools/lib/traceevent: Change user's plugin directory

 tools/lib/traceevent/Makefile            |   6 +-
 tools/lib/traceevent/event-parse-api.c   |  40 ---
 tools/lib/traceevent/event-parse-local.h |   6 -
 tools/lib/traceevent/event-parse.c       | 308 +++++++++++++----------
 tools/lib/traceevent/event-parse.h       |  29 +--
 tools/lib/traceevent/event-plugin.c      |   2 +-
 tools/perf/builtin-kmem.c                |   3 +-
 tools/perf/util/sort.c                   |   3 +-
 tools/perf/util/trace-event-parse.c      |   2 +-
 9 files changed, 197 insertions(+), 202 deletions(-)

-- 
2.21.0

[PATCH v2 1/3] tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs

[Tzvetomir Stoyanov (VMware)]

From: Tzvetomir Stoyanov <tstoyanov@vmware.com>

Libtraceevent APIs for printing various trace events information are
complicated, there are complex extra parameters. To control the way
event information is printed, the user should call a set of functions
in a specific sequence.
These APIs are reimplemented to provide a more simple interface for
printing event information.
Removed APIs:
 	tep_print_event_task()
	tep_print_event_time()
	tep_print_event_data()
	tep_event_info()
	tep_is_latency_format()
	tep_set_latency_format()
	tep_data_latency_format()
	tep_set_print_raw()

A new API for printing event information is introduced:
   void tep_print_event(struct tep_handle *tep, struct trace_seq *s,
		        struct tep_record *record, const char *fmt, ...);
where "fmt" is a printf-like format string, followed by the event
fields to be printed. Supported fields:
 TEP_PRINT_PID, "%d" - event PID
 TEP_PRINT_CPU, "%d" - event CPU
 TEP_PRINT_COMM, "%s" - event command string
 TEP_PRINT_NAME, "%s" - event name
 TEP_PRINT_LATENCY, "%s" - event latency
 TEP_PRINT_TIME, %d - event time stamp. A divisor and precision
   can be specified as part of this format string:
   "%precision.divisord". Example:
   "%3.1000d" - divide the time by 1000 and print the first 3 digits
   before the dot. Thus, the time stamp "123456000" will be printed as
   "123.456"
 TEP_PRINT_INFO, "%s" - event information. If any width is specified in
   the format string, the event information will be printed in raw format.

Example:
  tep_print_event(tep, s, record, "%16s-%-5d [%03d] %s %6.1000d %s %s",
		  TEP_PRINT_COMM, TEP_PRINT_PID, TEP_PRINT_CPU,
		  TEP_PRINT_LATENCY, TEP_PRINT_TIME, TEP_PRINT_NAME, TEP_PRINT_INFO);
Output:
	ls-11314 [005] d.h. 185207.366383 function __wake_up

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 tools/lib/traceevent/event-parse-api.c   |  40 ---
 tools/lib/traceevent/event-parse-local.h |   4 -
 tools/lib/traceevent/event-parse.c       | 297 ++++++++++++++---------
 tools/lib/traceevent/event-parse.h       |  28 +--
 tools/perf/builtin-kmem.c                |   3 +-
 tools/perf/util/sort.c                   |   3 +-
 tools/perf/util/trace-event-parse.c      |   2 +-
 7 files changed, 193 insertions(+), 184 deletions(-)

diff --git a/tools/lib/traceevent/event-parse-api.c b/tools/lib/traceevent/event-parse-api.c
index 988587840c80..4faf52a65791 100644
--- a/tools/lib/traceevent/event-parse-api.c
+++ b/tools/lib/traceevent/event-parse-api.c
@@ -302,33 +302,6 @@ void tep_set_local_bigendian(struct tep_handle *tep, enum tep_endian endian)
 		tep->host_bigendian = endian;
 }
 
-/**
- * tep_is_latency_format - get if the latency output format is configured
- * @tep: a handle to the tep_handle
- *
- * This returns true if the latency output format is configured
- * If @tep is NULL, false is returned.
- */
-bool tep_is_latency_format(struct tep_handle *tep)
-{
-	if (tep)
-		return (tep->latency_format);
-	return false;
-}
-
-/**
- * tep_set_latency_format - set the latency output format
- * @tep: a handle to the tep_handle
- * @lat: non zero for latency output format
- *
- * This sets the latency output format
-  */
-void tep_set_latency_format(struct tep_handle *tep, int lat)
-{
-	if (tep)
-		tep->latency_format = lat;
-}
-
 /**
  * tep_is_old_format - get if an old kernel is used
  * @tep: a handle to the tep_handle
@@ -344,19 +317,6 @@ bool tep_is_old_format(struct tep_handle *tep)
 	return false;
 }
 
-/**
- * tep_set_print_raw - set a flag to force print in raw format
- * @tep: a handle to the tep_handle
- * @print_raw: the new value of the print_raw flag
- *
- * This sets a flag to force print in raw format
- */
-void tep_set_print_raw(struct tep_handle *tep, int print_raw)
-{
-	if (tep)
-		tep->print_raw = print_raw;
-}
-
 /**
  * tep_set_test_filters - set a flag to test a filter string
  * @tep: a handle to the tep_handle
diff --git a/tools/lib/traceevent/event-parse-local.h b/tools/lib/traceevent/event-parse-local.h
index 09aa142f7fdd..6e58ee1fe7c8 100644
--- a/tools/lib/traceevent/event-parse-local.h
+++ b/tools/lib/traceevent/event-parse-local.h
@@ -28,8 +28,6 @@ struct tep_handle {
 	enum tep_endian file_bigendian;
 	enum tep_endian host_bigendian;
 
-	int latency_format;
-
 	int old_format;
 
 	int cpus;
@@ -70,8 +68,6 @@ struct tep_handle {
 	int ld_offset;
 	int ld_size;
 
-	int print_raw;
-
 	int test_filters;
 
 	int flags;
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index b36b536a9fcb..b3dfcc39f606 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -5174,14 +5174,15 @@ static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_e
  * tep_data_latency_format - parse the data for the latency format
  * @tep: a handle to the trace event parser context
  * @s: the trace_seq to write to
+ * @format: a printf format string
  * @record: the record to read from
  *
  * This parses out the Latency format (interrupts disabled,
  * need rescheduling, in hard/soft interrupt, preempt count
  * and lock depth) and places it into the trace_seq.
  */
-void tep_data_latency_format(struct tep_handle *tep,
-			     struct trace_seq *s, struct tep_record *record)
+static void tep_data_latency_format(struct tep_handle *tep, struct trace_seq *s,
+				    char *format, struct tep_record *record)
 {
 	static int check_lock_depth = 1;
 	static int check_migrate_disable = 1;
@@ -5193,6 +5194,8 @@ void tep_data_latency_format(struct tep_handle *tep,
 	int migrate_disable = 0;
 	int hardirq;
 	int softirq;
+	char lat_str[32];
+	char str[8];
 	void *data = record->data;
 
 	lat_flags = parse_common_flags(tep, data);
@@ -5222,7 +5225,7 @@ void tep_data_latency_format(struct tep_handle *tep,
 	hardirq = lat_flags & TRACE_FLAG_HARDIRQ;
 	softirq = lat_flags & TRACE_FLAG_SOFTIRQ;
 
-	trace_seq_printf(s, "%c%c%c",
+	snprintf(lat_str, 32, "%c%c%c",
 	       (lat_flags & TRACE_FLAG_IRQS_OFF) ? 'd' :
 	       (lat_flags & TRACE_FLAG_IRQS_NOSUPPORT) ?
 	       'X' : '.',
@@ -5232,24 +5235,27 @@ void tep_data_latency_format(struct tep_handle *tep,
 	       hardirq ? 'h' : softirq ? 's' : '.');
 
 	if (pc)
-		trace_seq_printf(s, "%x", pc);
+		snprintf(str, 8, "%x", pc);
 	else
-		trace_seq_putc(s, '.');
+		snprintf(str, 8, ".");
+	strcat(lat_str, str);
 
 	if (migrate_disable_exists) {
 		if (migrate_disable < 0)
-			trace_seq_putc(s, '.');
+			snprintf(str, 8, ".");
 		else
-			trace_seq_printf(s, "%d", migrate_disable);
+			snprintf(str, 8, "%d", migrate_disable);
+		strcat(lat_str, str);
 	}
 
 	if (lock_depth_exists) {
 		if (lock_depth < 0)
-			trace_seq_putc(s, '.');
+			snprintf(str, 8, ".");
 		else
-			trace_seq_printf(s, "%d", lock_depth);
+			snprintf(str, 8, "%d", lock_depth);
+		strcat(lat_str, str);
 	}
-
+	trace_seq_printf(s, format, lat_str);
 	trace_seq_terminate(s);
 }
 
@@ -5413,18 +5419,20 @@ int tep_cmdline_pid(struct tep_handle *tep, struct tep_cmdline *cmdline)
 /**
  * tep_event_info - parse the data into the print format
  * @s: the trace_seq to write to
+ * @format: printf format string. If any precision is specified in the string,
+ *	    print in raw data format
  * @event: the handle to the event
  * @record: the record to read from
  *
  * This parses the raw @data using the given @event information and
  * writes the print format into the trace_seq.
  */
-void tep_event_info(struct trace_seq *s, struct tep_event *event,
-		    struct tep_record *record)
+static void tep_event_info(struct trace_seq *s, char *format,
+			   struct tep_event *event, struct tep_record *record)
 {
 	int print_pretty = 1;
 
-	if (event->tep->print_raw || (event->flags & TEP_EVENT_FL_PRINTRAW))
+	if (isdigit(*(format+1)) || (event->flags & TEP_EVENT_FL_PRINTRAW))
 		tep_print_fields(s, record->data, record->size, event);
 	else {
 
@@ -5439,20 +5447,6 @@ void tep_event_info(struct trace_seq *s, struct tep_event *event,
 	trace_seq_terminate(s);
 }
 
-static bool is_timestamp_in_us(char *trace_clock, bool use_trace_clock)
-{
-	if (!trace_clock || !use_trace_clock)
-		return true;
-
-	if (!strcmp(trace_clock, "local") || !strcmp(trace_clock, "global")
-	    || !strcmp(trace_clock, "uptime") || !strcmp(trace_clock, "perf")
-	    || !strncmp(trace_clock, "mono", 4))
-		return true;
-
-	/* trace_clock is setting in tsc or counter mode */
-	return false;
-}
-
 /**
  * tep_find_event_by_record - return the event from a given record
  * @tep: a handle to the trace event parser context
@@ -5477,128 +5471,193 @@ tep_find_event_by_record(struct tep_handle *tep, struct tep_record *record)
 }
 
 /**
- * tep_print_event_task - Write the event task comm, pid and CPU
+ * tep_print_event_time - Write the event timestamp
  * @tep: a handle to the trace event parser context
  * @s: the trace_seq to write to
+ * @format: a printf format string.
+ *	    Time divisor and precision can be specified as part of this format
+ *	    string: "%precision.divisord". Example:
+ *	    "%3.1000d" - divide the time by 1000 and print the first 3 digits
+ *	     before the dot. Thus, the timestamp "123456000" will be printed as
+ *	     "123.456"
  * @event: the handle to the record's event
  * @record: The record to get the event from
  *
- * Writes the tasks comm, pid and CPU to @s.
+ * Writes the timestamp of the record into @s.
  */
-void tep_print_event_task(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record)
+static void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
+				 char *format, struct tep_event *event,
+				 struct tep_record *record)
+{
+	unsigned long long time;
+	char *divstr;
+	int prec = 0, pr;
+	int div = 0;
+	int p10 = 1;
+
+	if (isdigit(*(format + 1)))
+		prec = atoi(format + 1);
+	divstr = strchr(format, '.');
+	if (divstr && isdigit(*(divstr + 1)))
+		div = atoi(divstr + 1);
+	time = record->ts;
+	if (div)
+		time /= div;
+	pr = prec;
+	while (pr--)
+		p10 *= 10;
+
+	if (p10 > 1 && p10 < time)
+		trace_seq_printf(s, "%5llu.%0*llu", time / p10, prec, time % p10);
+	else
+		printf("%12llu\n", time);
+}
+
+struct print_event_type {
+	enum {
+		EVENT_TYPE_INT = 1,
+		EVENT_TYPE_STRING,
+		EVENT_TYPE_UNKNOWN,
+	} type;
+	char format[32];
+};
+
+static void tep_print_string(struct tep_handle *tep, struct trace_seq *s,
+			     struct tep_record *record, struct tep_event *event,
+			     const char *arg, struct print_event_type *type)
 {
-	void *data = record->data;
 	const char *comm;
 	int pid;
 
-	pid = parse_common_pid(tep, data);
-	comm = find_cmdline(tep, pid);
-
-	if (tep->latency_format)
-		trace_seq_printf(s, "%8.8s-%-5d %3d", comm, pid, record->cpu);
-	else
-		trace_seq_printf(s, "%16s-%-5d [%03d]", comm, pid, record->cpu);
+	if (strncmp(arg, TEP_PRINT_LATENCY, strlen(TEP_PRINT_LATENCY)) == 0) {
+		tep_data_latency_format(tep, s, type->format, record);
+	} else if (strncmp(arg, TEP_PRINT_COMM, strlen(TEP_PRINT_COMM)) == 0) {
+		pid = parse_common_pid(tep, record->data);
+		comm = find_cmdline(tep, pid);
+		trace_seq_printf(s, type->format, comm);
+	} else if (strncmp(arg, TEP_PRINT_INFO, strlen(TEP_PRINT_INFO)) == 0) {
+		tep_event_info(s, type->format, event, record);
+	} else if  (strncmp(arg, TEP_PRINT_NAME, strlen(TEP_PRINT_NAME)) == 0) {
+		trace_seq_printf(s, type->format, event->name);
+	}
 }
 
-/**
- * tep_print_event_time - Write the event timestamp
- * @tep: a handle to the trace event parser context
- * @s: the trace_seq to write to
- * @event: the handle to the record's event
- * @record: The record to get the event from
- * @use_trace_clock: Set to parse according to the @tep->trace_clock
- *
- * Writes the timestamp of the record into @s.
- */
-void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record,
-			  bool use_trace_clock)
+static void tep_print_int(struct tep_handle *tep, struct trace_seq *s,
+			  struct tep_record *record, struct tep_event *event,
+			  int arg, struct print_event_type *type)
 {
-	unsigned long secs;
-	unsigned long usecs;
-	unsigned long nsecs;
-	int p;
-	bool use_usec_format;
+	int param;
 
-	use_usec_format = is_timestamp_in_us(tep->trace_clock, use_trace_clock);
-	if (use_usec_format) {
-		secs = record->ts / NSEC_PER_SEC;
-		nsecs = record->ts - secs * NSEC_PER_SEC;
+	switch (arg) {
+	case TEP_PRINT_CPU:
+		param = record->cpu;
+		break;
+	case TEP_PRINT_PID:
+		param = parse_common_pid(tep, record->data);
+		break;
+	case TEP_PRINT_TIME:
+		return tep_print_event_time(tep, s, type->format, event, record);
+	default:
+		return;
 	}
+	trace_seq_printf(s, type->format, param);
+}
 
-	if (tep->latency_format) {
-		tep_data_latency_format(tep, s, record);
-	}
+static int tep_print_event_param_type(char *format,
+				      struct print_event_type *type)
+{
+	char *str = format + 1;
+	int i = 1;
 
-	if (use_usec_format) {
-		if (tep->flags & TEP_NSEC_OUTPUT) {
-			usecs = nsecs;
-			p = 9;
-		} else {
-			usecs = (nsecs + 500) / NSEC_PER_USEC;
-			/* To avoid usecs larger than 1 sec */
-			if (usecs >= USEC_PER_SEC) {
-				usecs -= USEC_PER_SEC;
-				secs++;
-			}
-			p = 6;
+	type->type = EVENT_TYPE_UNKNOWN;
+	while (*str) {
+		switch (*str) {
+		case 'd':
+		case 'u':
+		case 'i':
+		case 'x':
+		case 'X':
+		case 'o':
+			type->type = EVENT_TYPE_INT;
+			break;
+		case 's':
+			type->type = EVENT_TYPE_STRING;
+			break;
 		}
-
-		trace_seq_printf(s, " %5lu.%0*lu:", secs, p, usecs);
-	} else
-		trace_seq_printf(s, " %12llu:", record->ts);
+		str++;
+		i++;
+		if (type->type != EVENT_TYPE_UNKNOWN)
+			break;
+	}
+	memset(type->format, 0, 32);
+	memcpy(type->format, format, i < 32 ? i : 31);
+	return i;
 }
 
 /**
- * tep_print_event_data - Write the event data section
+ * tep_print_event - Write various event information
  * @tep: a handle to the trace event parser context
  * @s: the trace_seq to write to
- * @event: the handle to the record's event
  * @record: The record to get the event from
- *
- * Writes the parsing of the record's data to @s.
+ * @format: a printf format string. Supported event fileds:
+ *	TEP_PRINT_PID, "%d" - event PID
+ *	TEP_PRINT_CPU, "%d" - event CPU
+ *	TEP_PRINT_COMM, "%s" - event command string
+ *	TEP_PRINT_NAME, "%s" - event name
+ *	TEP_PRINT_LATENCY, "%s" - event latency
+ *	TEP_PRINT_TIME, %d - event time stamp. A divisor and precision
+ *			can be specified as part of this format string:
+ *			"%precision.divisord". Example:
+ *			"%3.1000d" - divide the time by 1000 and print the first
+ *			3 digits before the dot. Thus, the time stamp
+ *			"123456000" will be printed as "123.456"
+ *	TEP_PRINT_INFO, "%s" - event information. If any width is specified in
+ *			the format string, the event information will be printed
+ *			in raw format.
+ * Writes the specified event information into @s.
  */
-void tep_print_event_data(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record)
-{
-	static const char *spaces = "                    "; /* 20 spaces */
-	int len;
-
-	trace_seq_printf(s, " %s: ", event->name);
-
-	/* Space out the event names evenly. */
-	len = strlen(event->name);
-	if (len < 20)
-		trace_seq_printf(s, "%.*s", 20 - len, spaces);
-
-	tep_event_info(s, event, record);
-}
-
 void tep_print_event(struct tep_handle *tep, struct trace_seq *s,
-		     struct tep_record *record, bool use_trace_clock)
-{
+		     struct tep_record *record, const char *fmt, ...)
+{
+	struct print_event_type type;
+	char *format = strdup(fmt);
+	char *current = format;
+	char *str = format;
+	int offset;
+	va_list args;
 	struct tep_event *event;
 
 	event = tep_find_event_by_record(tep, record);
-	if (!event) {
-		int i;
-		int type = trace_parse_common_type(tep, record->data);
-
-		do_warning("ug! no event found for type %d", type);
-		trace_seq_printf(s, "[UNKNOWN TYPE %d]", type);
-		for (i = 0; i < record->size; i++)
-			trace_seq_printf(s, " %02x",
-					 ((unsigned char *)record->data)[i]);
-		return;
-	}
+	va_start(args, fmt);
+	while (*current) {
+		current = strchr(str, '%');
+		if (!current) {
+			trace_seq_puts(s, str);
+			break;
+		}
+		memset(&type, 0, sizeof(type));
+		offset = tep_print_event_param_type(current, &type);
+		*current = '\0';
+		trace_seq_puts(s, str);
+		current += offset;
+		switch (type.type) {
+		case EVENT_TYPE_STRING:
+			tep_print_string(tep, s, record, event,
+					 va_arg(args, char*), &type);
+			break;
+		case EVENT_TYPE_INT:
+			tep_print_int(tep, s, record, event,
+				      va_arg(args, int), &type);
+			break;
+		case EVENT_TYPE_UNKNOWN:
+		default:
+			break;
+		}
+		str = current;
 
-	tep_print_event_task(tep, s, event, record);
-	tep_print_event_time(tep, s, event, record, use_trace_clock);
-	tep_print_event_data(tep, s, event, record);
+	}
+	va_end(args);
+	free(format);
 }
 
 static int events_id_cmp(const void *a, const void *b)
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 642f68ab5fb2..5ed5107a4ec4 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -442,18 +442,17 @@ int tep_register_print_string(struct tep_handle *tep, const char *fmt,
 			      unsigned long long addr);
 bool tep_is_pid_registered(struct tep_handle *tep, int pid);
 
-void tep_print_event_task(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record);
-void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record,
-			  bool use_trace_clock);
-void tep_print_event_data(struct tep_handle *tep, struct trace_seq *s,
-			  struct tep_event *event,
-			  struct tep_record *record);
+#define TEP_PRINT_INFO		"INFO"
+#define TEP_PRINT_COMM		"COMM"
+#define TEP_PRINT_LATENCY	"LATENCY"
+#define TEP_PRINT_NAME		"NAME"
+#define TEP_PRINT_PID		1U
+#define TEP_PRINT_TIME		2U
+#define TEP_PRINT_CPU		3U
+
 void tep_print_event(struct tep_handle *tep, struct trace_seq *s,
-		     struct tep_record *record, bool use_trace_clock);
+		     struct tep_record *record, const char *fmt, ...)
+	__attribute__ ((format (printf, 4, 5)));
 
 int tep_parse_header_page(struct tep_handle *tep, char *buf, unsigned long size,
 			  int long_size);
@@ -525,8 +524,6 @@ tep_find_event_by_name(struct tep_handle *tep, const char *sys, const char *name
 struct tep_event *
 tep_find_event_by_record(struct tep_handle *tep, struct tep_record *record);
 
-void tep_data_latency_format(struct tep_handle *tep,
-			     struct trace_seq *s, struct tep_record *record);
 int tep_data_type(struct tep_handle *tep, struct tep_record *rec);
 int tep_data_pid(struct tep_handle *tep, struct tep_record *rec);
 int tep_data_preempt_count(struct tep_handle *tep, struct tep_record *rec);
@@ -541,8 +538,6 @@ void tep_print_field(struct trace_seq *s, void *data,
 		     struct tep_format_field *field);
 void tep_print_fields(struct trace_seq *s, void *data,
 		      int size __maybe_unused, struct tep_event *event);
-void tep_event_info(struct trace_seq *s, struct tep_event *event,
-		    struct tep_record *record);
 int tep_strerror(struct tep_handle *tep, enum tep_errno errnum,
 		 char *buf, size_t buflen);
 
@@ -566,12 +561,9 @@ bool tep_is_file_bigendian(struct tep_handle *tep);
 void tep_set_file_bigendian(struct tep_handle *tep, enum tep_endian endian);
 bool tep_is_local_bigendian(struct tep_handle *tep);
 void tep_set_local_bigendian(struct tep_handle *tep, enum tep_endian endian);
-bool tep_is_latency_format(struct tep_handle *tep);
-void tep_set_latency_format(struct tep_handle *tep, int lat);
 int tep_get_header_page_size(struct tep_handle *tep);
 int tep_get_header_timestamp_size(struct tep_handle *tep);
 bool tep_is_old_format(struct tep_handle *tep);
-void tep_set_print_raw(struct tep_handle *tep, int print_raw);
 void tep_set_test_filters(struct tep_handle *tep, int test_filters);
 
 struct tep_handle *tep_alloc(void);
diff --git a/tools/perf/builtin-kmem.c b/tools/perf/builtin-kmem.c
index 9e5e60898083..6f9b15ee252e 100644
--- a/tools/perf/builtin-kmem.c
+++ b/tools/perf/builtin-kmem.c
@@ -749,7 +749,8 @@ static int parse_gfp_flags(struct perf_evsel *evsel, struct perf_sample *sample,
 	}
 
 	trace_seq_init(&seq);
-	tep_event_info(&seq, evsel->tp_format, &record);
+	tep_print_event(evsel->tp_format->tep,
+			&seq, &record, "%s", TEP_PRINT_INFO);
 
 	str = strtok_r(seq.buffer, " ", &pos);
 	while (str) {
diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
index 5d2518e89fc4..55a20bbbe236 100644
--- a/tools/perf/util/sort.c
+++ b/tools/perf/util/sort.c
@@ -711,7 +711,8 @@ static char *get_trace_output(struct hist_entry *he)
 		tep_print_fields(&seq, he->raw_data, he->raw_size,
 				 evsel->tp_format);
 	} else {
-		tep_event_info(&seq, evsel->tp_format, &rec);
+		tep_print_event(evsel->tp_format->tep,
+				&seq, &rec, "%s", TEP_PRINT_INFO);
 	}
 	/*
 	 * Trim the buffer, it starts at 4KB and we're not going to
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index b3982e1bb4c5..3c5fef614d89 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -110,7 +110,7 @@ void event_format__fprintf(struct tep_event *event,
 	record.data = data;
 
 	trace_seq_init(&s);
-	tep_event_info(&s, event, &record);
+	tep_print_event(event->tep, &s, &record, "%s", TEP_PRINT_INFO);
 	trace_seq_do_fprintf(&s, fp);
 	trace_seq_destroy(&s);
 }
-- 
2.21.0

Re: [PATCH v2 1/3] tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs

[Steven Rostedt]

On Tue, 30 Jul 2019 15:50:26 +0300
"Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:


> diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
> index b36b536a9fcb..b3dfcc39f606 100644
> --- a/tools/lib/traceevent/event-parse.c
> +++ b/tools/lib/traceevent/event-parse.c
> @@ -5174,14 +5174,15 @@ static void pretty_print(struct trace_seq *s, void *data, int size, struct tep_e
>   * tep_data_latency_format - parse the data for the latency format
>   * @tep: a handle to the trace event parser context
>   * @s: the trace_seq to write to
> + * @format: a printf format string
>   * @record: the record to read from
>   *
>   * This parses out the Latency format (interrupts disabled,
>   * need rescheduling, in hard/soft interrupt, preempt count
>   * and lock depth) and places it into the trace_seq.
>   */
> -void tep_data_latency_format(struct tep_handle *tep,
> -			     struct trace_seq *s, struct tep_record *record)

Converting this to a static means that we don't need to start with
"tep_", as those should be reserved for external functions. We can also
modify the above kerndoc to be more of a simple comment, as we don't
need to have static functions turn into documentation.

> +static void tep_data_latency_format(struct tep_handle *tep, struct trace_seq *s,
> +				    char *format, struct tep_record *record)
>  {
>  	static int check_lock_depth = 1;
>  	static int check_migrate_disable = 1;
> @@ -5193,6 +5194,8 @@ void tep_data_latency_format(struct tep_handle *tep,
>  	int migrate_disable = 0;
>  	int hardirq;
>  	int softirq;
> +	char lat_str[32];
> +	char str[8];

This may be a bit of overkill, but we could just add temporary struct
trace_seq here.

	struct trace_seq sq;

>  	void *data = record->data;
>  

	trace_seq_init(&sq);

>  	lat_flags = parse_common_flags(tep, data);
> @@ -5222,7 +5225,7 @@ void tep_data_latency_format(struct tep_handle *tep,
>  	hardirq = lat_flags & TRACE_FLAG_HARDIRQ;
>  	softirq = lat_flags & TRACE_FLAG_SOFTIRQ;
>  
> -	trace_seq_printf(s, "%c%c%c",
> +	snprintf(lat_str, 32, "%c%c%c",

Then we can keep all the trace_seq_printf() and friends, but just use
&sq instead.

>  	       (lat_flags & TRACE_FLAG_IRQS_OFF) ? 'd' :
>  	       (lat_flags & TRACE_FLAG_IRQS_NOSUPPORT) ?
>  	       'X' : '.',
> @@ -5232,24 +5235,27 @@ void tep_data_latency_format(struct tep_handle *tep,
>  	       hardirq ? 'h' : softirq ? 's' : '.');
>  
>  	if (pc)
> -		trace_seq_printf(s, "%x", pc);
> +		snprintf(str, 8, "%x", pc);
>  	else
> -		trace_seq_putc(s, '.');
> +		snprintf(str, 8, ".");
> +	strcat(lat_str, str);
>  
>  	if (migrate_disable_exists) {
>  		if (migrate_disable < 0)
> -			trace_seq_putc(s, '.');
> +			snprintf(str, 8, ".");
>  		else
> -			trace_seq_printf(s, "%d", migrate_disable);
> +			snprintf(str, 8, "%d", migrate_disable);
> +		strcat(lat_str, str);
>  	}
>  
>  	if (lock_depth_exists) {
>  		if (lock_depth < 0)
> -			trace_seq_putc(s, '.');
> +			snprintf(str, 8, ".");
>  		else
> -			trace_seq_printf(s, "%d", lock_depth);
> +			snprintf(str, 8, "%d", lock_depth);
> +		strcat(lat_str, str);
>  	}
> -
> +	trace_seq_printf(s, format, lat_str);

Then here we would do:

	if (sq.state == TRACE_SEQ__MEM_ALLOC_FAILED) {
		s->state = TRACE_SEQ__MEM_ALLOC_FAILED;
		return;
	}	

	trace_seq_terminate(&sq);
	trace_seq_printf(s, format, sq.buffer);
>  	trace_seq_terminate(s);

Just a thought. But using the strcat also works. I figured this just
makes it more consistent.

>  }
>  
> @@ -5413,18 +5419,20 @@ int tep_cmdline_pid(struct tep_handle *tep, struct tep_cmdline *cmdline)
>  /**
>   * tep_event_info - parse the data into the print format
>   * @s: the trace_seq to write to
> + * @format: printf format string. If any precision is specified in the string,
> + *	    print in raw data format

I'm curious to why this is needed?

We can use a temp trace_seq like I mentioned above, and then apply the
format to it at the end.


>   * @event: the handle to the event
>   * @record: the record to read from
>   *
>   * This parses the raw @data using the given @event information and
>   * writes the print format into the trace_seq.
>   */
> -void tep_event_info(struct trace_seq *s, struct tep_event *event,
> -		    struct tep_record *record)
> +static void tep_event_info(struct trace_seq *s, char *format,
> +			   struct tep_event *event, struct tep_record *record)

Same thing. The comments for this static function can also be
simplified.


>  {
>  	int print_pretty = 1;
>  
> -	if (event->tep->print_raw || (event->flags & TEP_EVENT_FL_PRINTRAW))
> +	if (isdigit(*(format+1)) || (event->flags & TEP_EVENT_FL_PRINTRAW))
>  		tep_print_fields(s, record->data, record->size, event);
>  	else {
>  
> @@ -5439,20 +5447,6 @@ void tep_event_info(struct trace_seq *s, struct tep_event *event,
>  	trace_seq_terminate(s);
>  }
>  
> -static bool is_timestamp_in_us(char *trace_clock, bool use_trace_clock)
> -{
> -	if (!trace_clock || !use_trace_clock)
> -		return true;
> -
> -	if (!strcmp(trace_clock, "local") || !strcmp(trace_clock, "global")
> -	    || !strcmp(trace_clock, "uptime") || !strcmp(trace_clock, "perf")
> -	    || !strncmp(trace_clock, "mono", 4))
> -		return true;
> -
> -	/* trace_clock is setting in tsc or counter mode */
> -	return false;
> -}
> -
>  /**
>   * tep_find_event_by_record - return the event from a given record
>   * @tep: a handle to the trace event parser context
> @@ -5477,128 +5471,193 @@ tep_find_event_by_record(struct tep_handle *tep, struct tep_record *record)
>  }
>  
>  /**
> - * tep_print_event_task - Write the event task comm, pid and CPU
> + * tep_print_event_time - Write the event timestamp
>   * @tep: a handle to the trace event parser context
>   * @s: the trace_seq to write to
> + * @format: a printf format string.
> + *	    Time divisor and precision can be specified as part of this format
> + *	    string: "%precision.divisord". Example:
> + *	    "%3.1000d" - divide the time by 1000 and print the first 3 digits
> + *	     before the dot. Thus, the timestamp "123456000" will be printed as
> + *	     "123.456"
>   * @event: the handle to the record's event
>   * @record: The record to get the event from
>   *
> - * Writes the tasks comm, pid and CPU to @s.
> + * Writes the timestamp of the record into @s.
>   */
> -void tep_print_event_task(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record)

Again, we can simplify the comments for this function. Not make it less
informative, but remove the /** and make it just less official.

> +static void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
> +				 char *format, struct tep_event *event,
> +				 struct tep_record *record)
> +{
> +	unsigned long long time;
> +	char *divstr;
> +	int prec = 0, pr;
> +	int div = 0;
> +	int p10 = 1;
> +
> +	if (isdigit(*(format + 1)))
> +		prec = atoi(format + 1);
> +	divstr = strchr(format, '.');
> +	if (divstr && isdigit(*(divstr + 1)))
> +		div = atoi(divstr + 1);
> +	time = record->ts;
> +	if (div)
> +		time /= div;
> +	pr = prec;
> +	while (pr--)
> +		p10 *= 10;
> +
> +	if (p10 > 1 && p10 < time)
> +		trace_seq_printf(s, "%5llu.%0*llu", time / p10, prec, time % p10);
> +	else
> +		printf("%12llu\n", time);

Hmm, this should not print. I think you meant this to be
trace_seq_printf() not printf().

> +}
> +
> +struct print_event_type {
> +	enum {
> +		EVENT_TYPE_INT = 1,
> +		EVENT_TYPE_STRING,
> +		EVENT_TYPE_UNKNOWN,
> +	} type;
> +	char format[32];
> +};
> +
> +static void tep_print_string(struct tep_handle *tep, struct trace_seq *s,

Oh, and we should also remove the "tep_" from the names of the static
functions.

> +			     struct tep_record *record, struct tep_event *event,
> +			     const char *arg, struct print_event_type *type)
>  {
> -	void *data = record->data;
>  	const char *comm;
>  	int pid;
>  
> -	pid = parse_common_pid(tep, data);
> -	comm = find_cmdline(tep, pid);
> -
> -	if (tep->latency_format)
> -		trace_seq_printf(s, "%8.8s-%-5d %3d", comm, pid, record->cpu);
> -	else
> -		trace_seq_printf(s, "%16s-%-5d [%03d]", comm, pid, record->cpu);
> +	if (strncmp(arg, TEP_PRINT_LATENCY, strlen(TEP_PRINT_LATENCY)) == 0) {
> +		tep_data_latency_format(tep, s, type->format, record);
> +	} else if (strncmp(arg, TEP_PRINT_COMM, strlen(TEP_PRINT_COMM)) == 0) {
> +		pid = parse_common_pid(tep, record->data);
> +		comm = find_cmdline(tep, pid);
> +		trace_seq_printf(s, type->format, comm);
> +	} else if (strncmp(arg, TEP_PRINT_INFO, strlen(TEP_PRINT_INFO)) == 0) {
> +		tep_event_info(s, type->format, event, record);
> +	} else if  (strncmp(arg, TEP_PRINT_NAME, strlen(TEP_PRINT_NAME)) == 0) {
> +		trace_seq_printf(s, type->format, event->name);
> +	}

Hmm, I wonder if we should add an else here.
	} else {
		trace_seq_printf(s, "[UNKNOWN TEP TYPE %s]", arg);
	}
?

>  }
>  
> -/**
> - * tep_print_event_time - Write the event timestamp
> - * @tep: a handle to the trace event parser context
> - * @s: the trace_seq to write to
> - * @event: the handle to the record's event
> - * @record: The record to get the event from
> - * @use_trace_clock: Set to parse according to the @tep->trace_clock
> - *
> - * Writes the timestamp of the record into @s.
> - */
> -void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record,
> -			  bool use_trace_clock)

Same thing about static functions here.

> +static void tep_print_int(struct tep_handle *tep, struct trace_seq *s,
> +			  struct tep_record *record, struct tep_event *event,
> +			  int arg, struct print_event_type *type)
>  {
> -	unsigned long secs;
> -	unsigned long usecs;
> -	unsigned long nsecs;
> -	int p;
> -	bool use_usec_format;
> +	int param;
>  
> -	use_usec_format = is_timestamp_in_us(tep->trace_clock, use_trace_clock);
> -	if (use_usec_format) {
> -		secs = record->ts / NSEC_PER_SEC;
> -		nsecs = record->ts - secs * NSEC_PER_SEC;
> +	switch (arg) {
> +	case TEP_PRINT_CPU:
> +		param = record->cpu;
> +		break;
> +	case TEP_PRINT_PID:
> +		param = parse_common_pid(tep, record->data);
> +		break;
> +	case TEP_PRINT_TIME:
> +		return tep_print_event_time(tep, s, type->format, event, record);
> +	default:
> +		return;
>  	}
> +	trace_seq_printf(s, type->format, param);
> +}
>  
> -	if (tep->latency_format) {
> -		tep_data_latency_format(tep, s, record);
> -	}
> +static int tep_print_event_param_type(char *format,
> +				      struct print_event_type *type)
> +{
> +	char *str = format + 1;
> +	int i = 1;
>  
> -	if (use_usec_format) {
> -		if (tep->flags & TEP_NSEC_OUTPUT) {
> -			usecs = nsecs;
> -			p = 9;
> -		} else {
> -			usecs = (nsecs + 500) / NSEC_PER_USEC;
> -			/* To avoid usecs larger than 1 sec */
> -			if (usecs >= USEC_PER_SEC) {
> -				usecs -= USEC_PER_SEC;
> -				secs++;
> -			}
> -			p = 6;
> +	type->type = EVENT_TYPE_UNKNOWN;
> +	while (*str) {
> +		switch (*str) {
> +		case 'd':
> +		case 'u':
> +		case 'i':
> +		case 'x':
> +		case 'X':
> +		case 'o':
> +			type->type = EVENT_TYPE_INT;
> +			break;
> +		case 's':
> +			type->type = EVENT_TYPE_STRING;
> +			break;

Should this cover all printf types?

>  		}
> -
> -		trace_seq_printf(s, " %5lu.%0*lu:", secs, p, usecs);
> -	} else
> -		trace_seq_printf(s, " %12llu:", record->ts);
> +		str++;
> +		i++;
> +		if (type->type != EVENT_TYPE_UNKNOWN)
> +			break;
> +	}
> +	memset(type->format, 0, 32);
> +	memcpy(type->format, format, i < 32 ? i : 31);
> +	return i;
>  }
>  
>  /**
> - * tep_print_event_data - Write the event data section
> + * tep_print_event - Write various event information
>   * @tep: a handle to the trace event parser context
>   * @s: the trace_seq to write to
> - * @event: the handle to the record's event
>   * @record: The record to get the event from
> - *
> - * Writes the parsing of the record's data to @s.
> + * @format: a printf format string. Supported event fileds:
> + *	TEP_PRINT_PID, "%d" - event PID
> + *	TEP_PRINT_CPU, "%d" - event CPU
> + *	TEP_PRINT_COMM, "%s" - event command string
> + *	TEP_PRINT_NAME, "%s" - event name
> + *	TEP_PRINT_LATENCY, "%s" - event latency
> + *	TEP_PRINT_TIME, %d - event time stamp. A divisor and precision
> + *			can be specified as part of this format string:
> + *			"%precision.divisord". Example:
> + *			"%3.1000d" - divide the time by 1000 and print the first
> + *			3 digits before the dot. Thus, the time stamp
> + *			"123456000" will be printed as "123.456"
> + *	TEP_PRINT_INFO, "%s" - event information. If any width is specified in
> + *			the format string, the event information will be printed
> + *			in raw format.
> + * Writes the specified event information into @s.
>   */
> -void tep_print_event_data(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record)
> -{
> -	static const char *spaces = "                    "; /* 20 spaces */
> -	int len;
> -
> -	trace_seq_printf(s, " %s: ", event->name);
> -
> -	/* Space out the event names evenly. */
> -	len = strlen(event->name);
> -	if (len < 20)
> -		trace_seq_printf(s, "%.*s", 20 - len, spaces);
> -
> -	tep_event_info(s, event, record);
> -}
> -
>  void tep_print_event(struct tep_handle *tep, struct trace_seq *s,
> -		     struct tep_record *record, bool use_trace_clock)
> -{
> +		     struct tep_record *record, const char *fmt, ...)
> +{
> +	struct print_event_type type;
> +	char *format = strdup(fmt);

Need to test if strdup succeeded.

> +	char *current = format;
> +	char *str = format;
> +	int offset;
> +	va_list args;
>  	struct tep_event *event;
>  
>  	event = tep_find_event_by_record(tep, record);
> -	if (!event) {
> -		int i;
> -		int type = trace_parse_common_type(tep, record->data);
> -
> -		do_warning("ug! no event found for type %d", type);
> -		trace_seq_printf(s, "[UNKNOWN TYPE %d]", type);
> -		for (i = 0; i < record->size; i++)
> -			trace_seq_printf(s, " %02x",
> -					 ((unsigned char *)record->data)[i]);
> -		return;
> -	}
> +	va_start(args, fmt);
> +	while (*current) {
> +		current = strchr(str, '%');
> +		if (!current) {
> +			trace_seq_puts(s, str);
> +			break;
> +		}
> +		memset(&type, 0, sizeof(type));
> +		offset = tep_print_event_param_type(current, &type);
> +		*current = '\0';
> +		trace_seq_puts(s, str);
> +		current += offset;
> +		switch (type.type) {
> +		case EVENT_TYPE_STRING:
> +			tep_print_string(tep, s, record, event,
> +					 va_arg(args, char*), &type);
> +			break;
> +		case EVENT_TYPE_INT:
> +			tep_print_int(tep, s, record, event,
> +				      va_arg(args, int), &type);
> +			break;
> +		case EVENT_TYPE_UNKNOWN:
> +		default:

Should we add a trace_seq_printf("[UNKNOWN TYPE]") or something here?

-- Steve


> +			break;
> +		}
> +		str = current;
>  
> -	tep_print_event_task(tep, s, event, record);
> -	tep_print_event_time(tep, s, event, record, use_trace_clock);
> -	tep_print_event_data(tep, s, event, record);
> +	}
> +	va_end(args);
> +	free(format);
>  }
>  
>  static int events_id_cmp(const void *a, const void *b)
> diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
> index 642f68ab5fb2..5ed5107a4ec4 100644
> --- a/tools/lib/traceevent/event-parse.h
> +++ b/tools/lib/traceevent/event-parse.h
> @@ -442,18 +442,17 @@ int tep_register_print_string(struct tep_handle *tep, const char *fmt,
>  			      unsigned long long addr);
>  bool tep_is_pid_registered(struct tep_handle *tep, int pid);
>  
> -void tep_print_event_task(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record);
> -void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record,
> -			  bool use_trace_clock);
> -void tep_print_event_data(struct tep_handle *tep, struct trace_seq *s,
> -			  struct tep_event *event,
> -			  struct tep_record *record);
> +#define TEP_PRINT_INFO		"INFO"
> +#define TEP_PRINT_COMM		"COMM"
> +#define TEP_PRINT_LATENCY	"LATENCY"
> +#define TEP_PRINT_NAME		"NAME"
> +#define TEP_PRINT_PID		1U
> +#define TEP_PRINT_TIME		2U
> +#define TEP_PRINT_CPU		3U
> +
>  void tep_print_event(struct tep_handle *tep, struct trace_seq *s,
> -		     struct tep_record *record, bool use_trace_clock);
> +		     struct tep_record *record, const char *fmt, ...)
> +	__attribute__ ((format (printf, 4, 5)));
>  
>  int tep_parse_header_page(struct tep_handle *tep, char *buf, unsigned long size,
>  			  int long_size);
> @@ -525,8 +524,6 @@ tep_find_event_by_name(struct tep_handle *tep, const char *sys, const char *name
>  struct tep_event *
>  tep_find_event_by_record(struct tep_handle *tep, struct tep_record *record);
>  
> -void tep_data_latency_format(struct tep_handle *tep,
> -			     struct trace_seq *s, struct tep_record *record);
>  int tep_data_type(struct tep_handle *tep, struct tep_record *rec);
>  int tep_data_pid(struct tep_handle *tep, struct tep_record *rec);
>  int tep_data_preempt_count(struct tep_handle *tep, struct tep_record *rec);
> @@ -541,8 +538,6 @@ void tep_print_field(struct trace_seq *s, void *data,
>  		     struct tep_format_field *field);
>  void tep_print_fields(struct trace_seq *s, void *data,
>  		      int size __maybe_unused, struct tep_event *event);
> -void tep_event_info(struct trace_seq *s, struct tep_event *event,
> -		    struct tep_record *record);
>  int tep_strerror(struct tep_handle *tep, enum tep_errno errnum,
>  		 char *buf, size_t buflen);
>  
> @@ -566,12 +561,9 @@ bool tep_is_file_bigendian(struct tep_handle *tep);
>  void tep_set_file_bigendian(struct tep_handle *tep, enum tep_endian endian);
>  bool tep_is_local_bigendian(struct tep_handle *tep);
>  void tep_set_local_bigendian(struct tep_handle *tep, enum tep_endian endian);
> -bool tep_is_latency_format(struct tep_handle *tep);
> -void tep_set_latency_format(struct tep_handle *tep, int lat);
>  int tep_get_header_page_size(struct tep_handle *tep);
>  int tep_get_header_timestamp_size(struct tep_handle *tep);
>  bool tep_is_old_format(struct tep_handle *tep);
> -void tep_set_print_raw(struct tep_handle *tep, int print_raw);
>  void tep_set_test_filters(struct tep_handle *tep, int test_filters);
>  
>  struct tep_handle *tep_alloc(void);
> diff --git a/tools/perf/builtin-kmem.c b/tools/perf/builtin-kmem.c
> index 9e5e60898083..6f9b15ee252e 100644
> --- a/tools/perf/builtin-kmem.c
> +++ b/tools/perf/builtin-kmem.c
> @@ -749,7 +749,8 @@ static int parse_gfp_flags(struct perf_evsel *evsel, struct perf_sample *sample,
>  	}
>  
>  	trace_seq_init(&seq);
> -	tep_event_info(&seq, evsel->tp_format, &record);
> +	tep_print_event(evsel->tp_format->tep,
> +			&seq, &record, "%s", TEP_PRINT_INFO);
>  
>  	str = strtok_r(seq.buffer, " ", &pos);
>  	while (str) {
> diff --git a/tools/perf/util/sort.c b/tools/perf/util/sort.c
> index 5d2518e89fc4..55a20bbbe236 100644
> --- a/tools/perf/util/sort.c
> +++ b/tools/perf/util/sort.c
> @@ -711,7 +711,8 @@ static char *get_trace_output(struct hist_entry *he)
>  		tep_print_fields(&seq, he->raw_data, he->raw_size,
>  				 evsel->tp_format);
>  	} else {
> -		tep_event_info(&seq, evsel->tp_format, &rec);
> +		tep_print_event(evsel->tp_format->tep,
> +				&seq, &rec, "%s", TEP_PRINT_INFO);
>  	}
>  	/*
>  	 * Trim the buffer, it starts at 4KB and we're not going to
> diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> index b3982e1bb4c5..3c5fef614d89 100644
> --- a/tools/perf/util/trace-event-parse.c
> +++ b/tools/perf/util/trace-event-parse.c
> @@ -110,7 +110,7 @@ void event_format__fprintf(struct tep_event *event,
>  	record.data = data;
>  
>  	trace_seq_init(&s);
> -	tep_event_info(&s, event, &record);
> +	tep_print_event(event->tep, &s, &record, "%s", TEP_PRINT_INFO);
>  	trace_seq_do_fprintf(&s, fp);
>  	trace_seq_destroy(&s);
>  }

Re: [PATCH v2 1/3] tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs

[Tzvetomir Stoyanov]

On Tue, Jul 30, 2019 at 7:12 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Tue, 30 Jul 2019 15:50:26 +0300
> "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:
>
...
> >  }
> >
> > @@ -5413,18 +5419,20 @@ int tep_cmdline_pid(struct tep_handle *tep, struct tep_cmdline *cmdline)
> >  /**
> >   * tep_event_info - parse the data into the print format
> >   * @s: the trace_seq to write to
> > + * @format: printf format string. If any precision is specified in the string,
> > + *       print in raw data format
>
> I'm curious to why this is needed?
>
> We can use a temp trace_seq like I mentioned above, and then apply the
> format to it at the end.
>
We need a way to keep the tep_set_print_raw() functionality with the
new tep_print_event() API.
The user should have an option to print TEP_PRINT_INFO in raw format.
The only way to pass some
extra parameters to tep_print_event() is to use the printf format
string, "%s" in this case.
I choose to use "%s" width specifier to force TEP_PRINT_INFO in raw format.
The other possible solution could be to define a new
TEP_PRINT_INFO_RAW type for this use case.
...

-- 
Tzvetomir (Ceco) Stoyanov
VMware Open Source Technology Center

Re: [PATCH v2 1/3] tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs

[Steven Rostedt]

On Wed, 31 Jul 2019 15:16:13 +0300
Tzvetomir Stoyanov <tz.stoyanov@gmail.com> wrote:

> > > @@ -5413,18 +5419,20 @@ int tep_cmdline_pid(struct tep_handle *tep, struct tep_cmdline *cmdline)
> > >  /**
> > >   * tep_event_info - parse the data into the print format
> > >   * @s: the trace_seq to write to
> > > + * @format: printf format string. If any precision is specified in the string,
> > > + *       print in raw data format  
> >
> > I'm curious to why this is needed?
> >
> > We can use a temp trace_seq like I mentioned above, and then apply the
> > format to it at the end.
> >  
> We need a way to keep the tep_set_print_raw() functionality with the
> new tep_print_event() API.
> The user should have an option to print TEP_PRINT_INFO in raw format.
> The only way to pass some
> extra parameters to tep_print_event() is to use the printf format
> string, "%s" in this case.
> I choose to use "%s" width specifier to force TEP_PRINT_INFO in raw format.
> The other possible solution could be to define a new
> TEP_PRINT_INFO_RAW type for this use case.

I like the idea of adding a new TEP_PRINT_INFO_RAW, as the other seems
more of a "hack" to get that. It also removes the ability to pass in a
string precision for a normal TEP_PRINT_INFO.

Thanks!

-- Steve

[PATCH v2 2/3] tools/lib/traceevent: Remove tep_register_trace_clock()

[Tzvetomir Stoyanov (VMware)]

From: Tzvetomir Stoyanov <tstoyanov@vmware.com>

The tep_register_trace_clock() API is used to instruct the
traceevent library how to print the event time stamps. As event
print interface if redesigned, this API is not needed any more.
The new event print API is flexible and the user can specify how
the time stamps are printed.

Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 tools/lib/traceevent/event-parse-local.h |  2 --
 tools/lib/traceevent/event-parse.c       | 11 -----------
 tools/lib/traceevent/event-parse.h       |  1 -
 3 files changed, 14 deletions(-)

diff --git a/tools/lib/traceevent/event-parse-local.h b/tools/lib/traceevent/event-parse-local.h
index 6e58ee1fe7c8..cee469803a34 100644
--- a/tools/lib/traceevent/event-parse-local.h
+++ b/tools/lib/traceevent/event-parse-local.h
@@ -81,8 +81,6 @@ struct tep_handle {
 
 	/* cache */
 	struct tep_event *last_event;
-
-	char *trace_clock;
 };
 
 void tep_free_event(struct tep_event *event);
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index b3dfcc39f606..b97dbf1d63f7 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -351,16 +351,6 @@ int tep_override_comm(struct tep_handle *tep, const char *comm, int pid)
 	return _tep_register_comm(tep, comm, pid, true);
 }
 
-int tep_register_trace_clock(struct tep_handle *tep, const char *trace_clock)
-{
-	tep->trace_clock = strdup(trace_clock);
-	if (!tep->trace_clock) {
-		errno = ENOMEM;
-		return -1;
-	}
-	return 0;
-}
-
 struct func_map {
 	unsigned long long		addr;
 	char				*func;
@@ -7022,7 +7012,6 @@ void tep_free(struct tep_handle *tep)
 		free_handler(handle);
 	}
 
-	free(tep->trace_clock);
 	free(tep->events);
 	free(tep->sort_events);
 	free(tep->func_resolver);
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 5ed5107a4ec4..aef43f53560e 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -435,7 +435,6 @@ int tep_set_function_resolver(struct tep_handle *tep,
 void tep_reset_function_resolver(struct tep_handle *tep);
 int tep_register_comm(struct tep_handle *tep, const char *comm, int pid);
 int tep_override_comm(struct tep_handle *tep, const char *comm, int pid);
-int tep_register_trace_clock(struct tep_handle *tep, const char *trace_clock);
 int tep_register_function(struct tep_handle *tep, char *name,
 			  unsigned long long addr, char *mod);
 int tep_register_print_string(struct tep_handle *tep, const char *fmt,
-- 
2.21.0

[PATCH v2 3/3] tools/lib/traceevent: Change user's plugin directory

[Tzvetomir Stoyanov (VMware)]

From: Tzvetomir Stoyanov <tstoyanov@vmware.com>

To be compliant with XDG user directory layout,
the user's plugin directory is changed from
~/.traceevent/plugins to ~/.local/lib/traceevent/plugins/
Thanks to Patrick McLean:
https://lore.kernel.org/linux-trace-devel/20190313144206.41e75cf8@patrickm/

Suggested-by: Patrick McLean <chutzpah@gentoo.org>
Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com>
---
 tools/lib/traceevent/Makefile       | 6 +++---
 tools/lib/traceevent/event-plugin.c | 2 +-
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/tools/lib/traceevent/Makefile b/tools/lib/traceevent/Makefile
index 3292c290654f..86ce17a1f7fb 100644
--- a/tools/lib/traceevent/Makefile
+++ b/tools/lib/traceevent/Makefile
@@ -62,15 +62,15 @@ set_plugin_dir := 1
 
 # Set plugin_dir to preffered global plugin location
 # If we install under $HOME directory we go under
-# $(HOME)/.traceevent/plugins
+# $(HOME)/.local/lib/traceevent/plugins
 #
 # We dont set PLUGIN_DIR in case we install under $HOME
 # directory, because by default the code looks under:
-# $(HOME)/.traceevent/plugins by default.
+# $(HOME)/.local/lib/traceevent/plugins by default.
 #
 ifeq ($(plugin_dir),)
 ifeq ($(prefix),$(HOME))
-override plugin_dir = $(HOME)/.traceevent/plugins
+override plugin_dir = $(HOME)/.local/lib/traceevent/plugins
 set_plugin_dir := 0
 else
 override plugin_dir = $(libdir)/traceevent/plugins
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 8ca28de9337a..e1f7ddd5a6cf 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -18,7 +18,7 @@
 #include "event-utils.h"
 #include "trace-seq.h"
 
-#define LOCAL_PLUGIN_DIR ".traceevent/plugins"
+#define LOCAL_PLUGIN_DIR ".local/lib/traceevent/plugins/"
 
 static struct registered_plugin_options {
 	struct registered_plugin_options	*next;
-- 
2.21.0

Re: [PATCH v2 0/3] Changes in few libtraceevent APIs

[Steven Rostedt]

On Tue, 30 Jul 2019 15:50:25 +0300
"Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:

> Before releasing libtraceevent as a standalone library, few
> APIs must be changed:
>  - Event printing interface is redesigned, to be more simple
>    and user friendly. Now the tep_print_event() API can be used 
>    to print various event information. All other event print APIs
>    are removed.
>  - Changed the user's plugin directory to 
>    ~/.local/lib/traceevent/plugins/ to be XDG compliant.

BTW, the other two patches look good. Let's send a v2 of all the
patches with the comments in the first patch addressed.

Thanks Ceco!

-- Steve


> 
> [
>  v2 canges:
>   - the user's plugin directory changed from 
>  ~/.config/traceevent/plugins/ to ~/.local/lib/traceevent/plugins/, 
>  as suggested by Patrick McLean.
> ]
> 
> Tzvetomir Stoyanov (3):
>   tools/lib/traceevent, tools/perf: Changes in tep_print_event_* APIs
>   tools/lib/traceevent: Remove tep_register_trace_clock()
>   tools/lib/traceevent: Change user's plugin directory
> 
>  tools/lib/traceevent/Makefile            |   6 +-
>  tools/lib/traceevent/event-parse-api.c   |  40 ---
>  tools/lib/traceevent/event-parse-local.h |   6 -
>  tools/lib/traceevent/event-parse.c       | 308 +++++++++++++----------
>  tools/lib/traceevent/event-parse.h       |  29 +--
>  tools/lib/traceevent/event-plugin.c      |   2 +-
>  tools/perf/builtin-kmem.c                |   3 +-
>  tools/perf/util/sort.c                   |   3 +-
>  tools/perf/util/trace-event-parse.c      |   2 +-
>  9 files changed, 197 insertions(+), 202 deletions(-)
>