[PATCH 0/2] trace-cmd list: Include ftrace in event listings

[PATCH 0/2] trace-cmd list: Include ftrace in event listings

[Steven Rostedt]

From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>

I'm constantly needing to look at the event formats of ftrace events
(like the function event or print event), but trace-cmd list does not
include them, as they can not be enabled by trace-cmd record/start.

By default, trace-cmd list -e, wont show ftrace events, but if a regex
is added to the search: trace-cmd list -e print, then it will now list
those events in ftrace. This is useful for:

 # trace-cmd list -e ftrace:function -F
system: ftrace
name: function
ID: 1
format:
        field:unsigned short common_type;       offset:0;       size:2; signed:0;
        field:unsigned char common_flags;       offset:2;       size:1; signed:0;
        field:unsigned char common_preempt_count;       offset:3;       size:1; signed:0;
        field:int common_pid;   offset:4;       size:4; signed:1;

        field:unsigned long ip; offset:8;       size:8; signed:0;
        field:unsigned long parent_ip;  offset:16;      size:8; signed:0;

Steven Rostedt (VMware) (2):
  trace-cmd list: Use tracefs to help find events for -e
  trace-cmd list: Add ftrace events to listing of events

 lib/trace-cmd/trace-input.c |   6 +-
 tracecmd/trace-list.c       | 150 ++++++++++++++++++++++++++++++++++--
 2 files changed, 149 insertions(+), 7 deletions(-)

-- 
2.29.2

[PATCH 1/2] trace-cmd list: Use tracefs to help find events for -e

[Steven Rostedt]

From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>

When the user specifies -e and wants to search for events, use the tracefs
helper functions tracefs_event_systems() and tracefs_system_events() to
find the matching events.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 lib/trace-cmd/trace-input.c |   6 +-
 tracecmd/trace-list.c       | 136 ++++++++++++++++++++++++++++++++++--
 2 files changed, 135 insertions(+), 7 deletions(-)

diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
index 991abd5f..a540ab24 100644
--- a/lib/trace-cmd/trace-input.c
+++ b/lib/trace-cmd/trace-input.c
@@ -1234,9 +1234,11 @@ static unsigned long long timestamp_calc(unsigned long long ts, int cpu,
 			ts -= handle->tsc_calc.offset;
 			ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);
 		} else {
-			tracecmd_warning("Timestamp $llu is before the initial offset %llu, set it to 0",
+			tracecmd_warning("Timestamp %llu is before the initial offset %llu\n"
+					 "\tSetting offset to 0",
 					 ts, handle->tsc_calc.offset);
-			ts = 0;
+			handle->tsc_calc.offset = 0;
+			ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);
 		}
 	}
 
diff --git a/tracecmd/trace-list.c b/tracecmd/trace-list.c
index 63216b43..84ee573b 100644
--- a/tracecmd/trace-list.c
+++ b/tracecmd/trace-list.c
@@ -105,6 +105,122 @@ static void process_file_re(process_file_func func,
 	regfree(&reg);
 }
 
+static void show_event(process_file_func func, const char *system, const char *event)
+{
+	char *buf;
+	int ret;
+
+	ret = asprintf(&buf, "%s:%s", system, event);
+	if (ret < 0)
+		die("Can not allocate event");
+	func(buf, strlen(buf));
+	free(buf);
+}
+
+static void show_system(process_file_func func, const char *system)
+{
+	char **events;
+	int e;
+
+	events = tracefs_system_events(NULL, system);
+	if (!events) /* die? */
+		return;
+
+	for (e = 0; events[e]; e++)
+		show_event(func, system, events[e]);
+}
+
+static void show_event_systems(process_file_func func, char **systems)
+{
+	int s;
+
+	for (s = 0; systems[s]; s++)
+		show_system(func, systems[s]);
+}
+
+
+static void process_events(process_file_func func, const char *re)
+{
+	regex_t system_reg;
+	regex_t event_reg;
+	char *str;
+	size_t l = strlen(re);
+	bool just_systems = true;
+	char **systems;
+	char **events;
+	char *system;
+	char *event;
+	int s, e;
+
+	systems = tracefs_event_systems(NULL);
+	if (!systems)
+		return process_file_re(func, "available_events", re);
+
+	if (!re || l == 0) {
+		show_event_systems(func, systems);
+		return;
+	}
+
+	str = strdup(re);
+	if (!str)
+		die("Can not allocate momory for regex");
+
+	system = strtok(str, ":");
+	event = strtok(NULL, "");
+
+	if (regcomp(&system_reg, system, REG_ICASE|REG_NOSUB))
+		die("invalid regex '%s'", system);
+
+	if (event) {
+		if (regcomp(&event_reg, event, REG_ICASE|REG_NOSUB))
+			die("invalid regex '%s'", event);
+	} else {
+		/*
+		 * If the regex ends with ":", then event would be null,
+		 * but we do not want to match events.
+		 */
+		if (re[l-1] != ':')
+			just_systems = false;
+	}
+	free(str);
+
+	for (s = 0; systems[s]; s++) {
+
+		if (regexec(&system_reg, systems[s], 0, NULL, 0) == 0) {
+			if (!event) {
+				show_system(func, systems[s]);
+				continue;
+			}
+			events = tracefs_system_events(NULL, systems[s]);
+			if (!events) /* die? */
+				continue;
+			for (e = 0; events[e]; e++) {
+				if (regexec(&event_reg, events[e], 0, NULL, 0) == 0)
+					show_event(func, systems[s], events[e]);
+			}
+			tracefs_list_free(events);
+			continue;
+		}
+		if (just_systems)
+			continue;
+
+		events = tracefs_system_events(NULL, systems[s]);
+		if (!events) /* die? */
+			continue;
+
+		for (e = 0; events[e]; e++) {
+			if (regexec(&system_reg, events[e], 0, NULL, 0) == 0)
+				show_event(func, systems[s], events[e]);
+		}
+		tracefs_list_free(events);
+	}
+	tracefs_list_free(systems);
+
+	regfree(&system_reg);
+	if (event)
+		regfree(&event_reg);
+}
+
 static int show_file_write(char *buf, int len)
 {
 	return fwrite(buf, 1, len, stdout);
@@ -210,24 +326,34 @@ static int event_format_write(char *fbuf, int len)
 	return 0;
 }
 
+static int event_name(char *buf, int len)
+{
+	printf("%s\n", buf);
+
+	return 0;
+}
+
 
 static void show_event_filter_re(const char *re)
 {
-	process_file_re(event_filter_write, "available_events", re);
+	process_events(event_filter_write, re);
 }
 
 
 static void show_event_trigger_re(const char *re)
 {
-	process_file_re(event_trigger_write, "available_events", re);
+	process_events(event_trigger_write, re);
 }
 
-
 static void show_event_format_re(const char *re)
 {
-	process_file_re(event_format_write, "available_events", re);
+	process_events(event_format_write, re);
 }
 
+static void show_event_names_re(const char *re)
+{
+	process_events(event_name, re);
+}
 
 static void show_events(const char *eventre, int flags)
 {
@@ -244,7 +370,7 @@ static void show_events(const char *eventre, int flags)
 		else if (flags & SHOW_EVENT_TRIGGER)
 			show_event_trigger_re(eventre);
 		else
-			show_file_re("available_events", eventre);
+			show_event_names_re(eventre);
 	} else
 		show_file("available_events");
 }
-- 
2.29.2

[PATCH 2/2] trace-cmd list: Add ftrace events to listing of events

[Steven Rostedt]

From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>

If a search of events is done with trace-cmd list -e, check if any matches
the ftrace events. This is useful to get the fields and print fmt of the
events under the ftrace system.

Note, just "trace-cmd list -e" will still not list ftrace events by
default.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tracecmd/trace-list.c | 52 +++++++++++++++++++++++++++----------------
 1 file changed, 33 insertions(+), 19 deletions(-)

diff --git a/tracecmd/trace-list.c b/tracecmd/trace-list.c
index 84ee573b..81f157ac 100644
--- a/tracecmd/trace-list.c
+++ b/tracecmd/trace-list.c
@@ -139,18 +139,34 @@ static void show_event_systems(process_file_func func, char **systems)
 }
 
 
+static void match_system_events(process_file_func func, const char *system,
+				regex_t *reg)
+{
+	char **events;
+	int e;
+
+	events = tracefs_system_events(NULL, system);
+	if (!events) /* die? */
+		return;
+	for (e = 0; events[e]; e++) {
+		if (regexec(reg, events[e], 0, NULL, 0) == 0)
+			show_event(func, system, events[e]);
+	}
+	tracefs_list_free(events);
+}
+
 static void process_events(process_file_func func, const char *re)
 {
 	regex_t system_reg;
 	regex_t event_reg;
+	const char *ftrace = "ftrace";
 	char *str;
 	size_t l = strlen(re);
 	bool just_systems = true;
 	char **systems;
-	char **events;
 	char *system;
 	char *event;
-	int s, e;
+	int s;
 
 	systems = tracefs_event_systems(NULL);
 	if (!systems)
@@ -184,6 +200,19 @@ static void process_events(process_file_func func, const char *re)
 	}
 	free(str);
 
+	/*
+	 * See if this matches the special ftrace system, as ftrace is not included
+	 * in the systems list, but can get events from tracefs_system_events().
+	 */
+	if (regexec(&system_reg, ftrace, 0, NULL, 0) == 0) {
+		if (!event)
+			show_system(func, ftrace);
+		else
+			match_system_events(func, ftrace, &event_reg);
+	} else if (!just_systems) {
+		match_system_events(func, ftrace, &system_reg);
+	}
+
 	for (s = 0; systems[s]; s++) {
 
 		if (regexec(&system_reg, systems[s], 0, NULL, 0) == 0) {
@@ -191,28 +220,13 @@ static void process_events(process_file_func func, const char *re)
 				show_system(func, systems[s]);
 				continue;
 			}
-			events = tracefs_system_events(NULL, systems[s]);
-			if (!events) /* die? */
-				continue;
-			for (e = 0; events[e]; e++) {
-				if (regexec(&event_reg, events[e], 0, NULL, 0) == 0)
-					show_event(func, systems[s], events[e]);
-			}
-			tracefs_list_free(events);
+			match_system_events(func, systems[s], &event_reg);
 			continue;
 		}
 		if (just_systems)
 			continue;
 
-		events = tracefs_system_events(NULL, systems[s]);
-		if (!events) /* die? */
-			continue;
-
-		for (e = 0; events[e]; e++) {
-			if (regexec(&system_reg, events[e], 0, NULL, 0) == 0)
-				show_event(func, systems[s], events[e]);
-		}
-		tracefs_list_free(events);
+		match_system_events(func, systems[s], &system_reg);
 	}
 	tracefs_list_free(systems);
 
-- 
2.29.2

Re: [PATCH 1/2] trace-cmd list: Use tracefs to help find events for -e

[Tzvetomir Stoyanov]

On Sat, Apr 17, 2021 at 1:08 AM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>
>
> When the user specifies -e and wants to search for events, use the tracefs
> helper functions tracefs_event_systems() and tracefs_system_events() to
> find the matching events.
>
> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
> ---
>  lib/trace-cmd/trace-input.c |   6 +-
>  tracecmd/trace-list.c       | 136 ++++++++++++++++++++++++++++++++++--
>  2 files changed, 135 insertions(+), 7 deletions(-)
>
> diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
> index 991abd5f..a540ab24 100644
> --- a/lib/trace-cmd/trace-input.c
> +++ b/lib/trace-cmd/trace-input.c
> @@ -1234,9 +1234,11 @@ static unsigned long long timestamp_calc(unsigned long long ts, int cpu,
>                         ts -= handle->tsc_calc.offset;
>                         ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);
>                 } else {
> -                       tracecmd_warning("Timestamp $llu is before the initial offset %llu, set it to 0",
> +                       tracecmd_warning("Timestamp %llu is before the initial offset %llu\n"
> +                                        "\tSetting offset to 0",
>                                          ts, handle->tsc_calc.offset);
> -                       ts = 0;
> +                       handle->tsc_calc.offset = 0;
> +                       ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);

That looks like from a different patch? I'll send v3 from my patch set
with these fixes.

>                 }
>         }
>
> diff --git a/tracecmd/trace-list.c b/tracecmd/trace-list.c
> index 63216b43..84ee573b 100644
> --- a/tracecmd/trace-list.c
> +++ b/tracecmd/trace-list.c
> @@ -105,6 +105,122 @@ static void process_file_re(process_file_func func,
>         regfree(&reg);
>  }
>
> +static void show_event(process_file_func func, const char *system, const char *event)
> +{
> +       char *buf;
> +       int ret;
> +
> +       ret = asprintf(&buf, "%s:%s", system, event);
> +       if (ret < 0)
> +               die("Can not allocate event");
> +       func(buf, strlen(buf));
> +       free(buf);
> +}
> +
> +static void show_system(process_file_func func, const char *system)
> +{
> +       char **events;
> +       int e;
> +
> +       events = tracefs_system_events(NULL, system);
> +       if (!events) /* die? */
> +               return;
> +
> +       for (e = 0; events[e]; e++)
> +               show_event(func, system, events[e]);
> +}
> +
> +static void show_event_systems(process_file_func func, char **systems)
> +{
> +       int s;
> +
> +       for (s = 0; systems[s]; s++)
> +               show_system(func, systems[s]);
> +}
> +
> +
> +static void process_events(process_file_func func, const char *re)
> +{
> +       regex_t system_reg;
> +       regex_t event_reg;
> +       char *str;
> +       size_t l = strlen(re);
> +       bool just_systems = true;
> +       char **systems;
> +       char **events;
> +       char *system;
> +       char *event;
> +       int s, e;
> +
> +       systems = tracefs_event_systems(NULL);
> +       if (!systems)
> +               return process_file_re(func, "available_events", re);
> +
> +       if (!re || l == 0) {
> +               show_event_systems(func, systems);
> +               return;
> +       }
> +
> +       str = strdup(re);
> +       if (!str)
> +               die("Can not allocate momory for regex");
> +
> +       system = strtok(str, ":");
> +       event = strtok(NULL, "");
> +
> +       if (regcomp(&system_reg, system, REG_ICASE|REG_NOSUB))
> +               die("invalid regex '%s'", system);
> +
> +       if (event) {
> +               if (regcomp(&event_reg, event, REG_ICASE|REG_NOSUB))
> +                       die("invalid regex '%s'", event);
> +       } else {
> +               /*
> +                * If the regex ends with ":", then event would be null,
> +                * but we do not want to match events.
> +                */
> +               if (re[l-1] != ':')
> +                       just_systems = false;
> +       }
> +       free(str);
> +
> +       for (s = 0; systems[s]; s++) {
> +
> +               if (regexec(&system_reg, systems[s], 0, NULL, 0) == 0) {
> +                       if (!event) {
> +                               show_system(func, systems[s]);
> +                               continue;
> +                       }
> +                       events = tracefs_system_events(NULL, systems[s]);
> +                       if (!events) /* die? */
> +                               continue;
> +                       for (e = 0; events[e]; e++) {
> +                               if (regexec(&event_reg, events[e], 0, NULL, 0) == 0)
> +                                       show_event(func, systems[s], events[e]);
> +                       }
> +                       tracefs_list_free(events);
> +                       continue;
> +               }
> +               if (just_systems)
> +                       continue;
> +
> +               events = tracefs_system_events(NULL, systems[s]);
> +               if (!events) /* die? */
> +                       continue;
> +
> +               for (e = 0; events[e]; e++) {
> +                       if (regexec(&system_reg, events[e], 0, NULL, 0) == 0)
> +                               show_event(func, systems[s], events[e]);
> +               }
> +               tracefs_list_free(events);
> +       }
> +       tracefs_list_free(systems);
> +
> +       regfree(&system_reg);
> +       if (event)
> +               regfree(&event_reg);
> +}
> +
>  static int show_file_write(char *buf, int len)
>  {
>         return fwrite(buf, 1, len, stdout);
> @@ -210,24 +326,34 @@ static int event_format_write(char *fbuf, int len)
>         return 0;
>  }
>
> +static int event_name(char *buf, int len)
> +{
> +       printf("%s\n", buf);
> +
> +       return 0;
> +}
> +
>
>  static void show_event_filter_re(const char *re)
>  {
> -       process_file_re(event_filter_write, "available_events", re);
> +       process_events(event_filter_write, re);
>  }
>
>
>  static void show_event_trigger_re(const char *re)
>  {
> -       process_file_re(event_trigger_write, "available_events", re);
> +       process_events(event_trigger_write, re);
>  }
>
> -
>  static void show_event_format_re(const char *re)
>  {
> -       process_file_re(event_format_write, "available_events", re);
> +       process_events(event_format_write, re);
>  }
>
> +static void show_event_names_re(const char *re)
> +{
> +       process_events(event_name, re);
> +}
>
>  static void show_events(const char *eventre, int flags)
>  {
> @@ -244,7 +370,7 @@ static void show_events(const char *eventre, int flags)
>                 else if (flags & SHOW_EVENT_TRIGGER)
>                         show_event_trigger_re(eventre);
>                 else
> -                       show_file_re("available_events", eventre);
> +                       show_event_names_re(eventre);
>         } else
>                 show_file("available_events");
>  }
> --
> 2.29.2
>


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

Re: [PATCH 1/2] trace-cmd list: Use tracefs to help find events for -e

[Steven Rostedt]

On Mon, 19 Apr 2021 08:10:57 +0300
Tzvetomir Stoyanov <tz.stoyanov@gmail.com> wrote:

> > --- a/lib/trace-cmd/trace-input.c
> > +++ b/lib/trace-cmd/trace-input.c
> > @@ -1234,9 +1234,11 @@ static unsigned long long timestamp_calc(unsigned long long ts, int cpu,
> >                         ts -= handle->tsc_calc.offset;
> >                         ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);
> >                 } else {
> > -                       tracecmd_warning("Timestamp $llu is before the initial offset %llu, set it to 0",
> > +                       tracecmd_warning("Timestamp %llu is before the initial offset %llu\n"
> > +                                        "\tSetting offset to 0",
> >                                          ts, handle->tsc_calc.offset);
> > -                       ts = 0;
> > +                       handle->tsc_calc.offset = 0;
> > +                       ts = mul_u64_u32_shr(ts, handle->tsc_calc.mult, handle->tsc_calc.shift);  
> 
> That looks like from a different patch? I'll send v3 from my patch set
> with these fixes.
> 
> >                 }
> >         }

Yes, that was leftover from another change that accidentally got committed
into this one. Thanks for noticing. I'll be sending out a v2.

-- Steve