[PATCH v2 0/4] tools lib traceevent: bitmask handling and plugin updates

[PATCH v2 0/4] tools lib traceevent: bitmask handling and plugin updates

[Steven Rostedt]

This is v2 of the patch series that added __get_bitmask() as well as
added some plugin code. This version addresses what Namhyung suggested.
The diff from v1 is posted below.

Steven Rostedt (Red Hat) (4):
      tools lib traceevent: Add flag to not load event plugins
      tools lib traceevent: Add options to plugins
      tools lib traceevent: Add options to function plugin
      tools lib traceevent: Added support for __get_bitmask() macro

----
 tools/lib/traceevent/event-parse.c                 | 113 ++++++++++++
 tools/lib/traceevent/event-parse.h                 |  25 ++-
 tools/lib/traceevent/event-plugin.c                | 204 ++++++++++++++++++++-
 tools/lib/traceevent/plugin_function.c             |  43 ++++-
 .../perf/util/scripting-engines/trace-event-perl.c |   1 +
 .../util/scripting-engines/trace-event-python.c    |   1 +
 6 files changed, 377 insertions(+), 10 deletions(-)


diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index 2d6aa92..93825a1 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -3794,7 +3794,7 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 			f = pevent_find_any_field(event, arg->bitmask.bitmask);
 			arg->bitmask.offset = f->offset;
 		}
-		bitmask_offset = data2host4(pevent, data + arg->string.offset);
+		bitmask_offset = data2host4(pevent, data + arg->bitmask.offset);
 		bitmask_size = bitmask_offset >> 16;
 		bitmask_offset &= 0xffff;
 		print_bitmask_to_seq(pevent, s, format, len_arg,
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 025627f..7a3873f 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -362,7 +362,7 @@ enum pevent_func_arg_type {
 enum pevent_flag {
 	PEVENT_NSEC_OUTPUT		= 1,	/* output in NSECS */
 	PEVENT_DISABLE_SYS_PLUGINS	= 1 << 1,
-	PEVENT_DISABLE_PLUGINS		= 1 << 2
+	PEVENT_DISABLE_PLUGINS		= 1 << 2,
 };
 
 #define PEVENT_ERRORS 							      \
@@ -419,6 +419,8 @@ enum pevent_errno {
 
 struct plugin_list;
 
+#define INVALID_PLUGIN_LIST_OPTION	((char **)((unsigned long)-1))
+
 struct plugin_list *traceevent_load_plugins(struct pevent *pevent);
 void traceevent_unload_plugins(struct plugin_list *plugin_list,
 			       struct pevent *pevent);
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index a244794..648ef84 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -57,7 +57,7 @@ struct plugin_list {
  * used by toggling the option.
  *
  * Returns NULL if there's no options registered. On error it returns
- * an (char **)-1 (must check for that)
+ * INVALID_PLUGIN_LIST_OPTION
  *
  * Must be freed with traceevent_plugin_free_options_list().
  */
@@ -72,6 +72,7 @@ char **traceevent_plugin_list_options(void)
 	for (reg = registered_options; reg; reg = reg->next) {
 		for (op = reg->options; op->name; op++) {
 			char *alias = op->plugin_alias ? op->plugin_alias : op->file;
+			char **temp = list;
 
 			name = malloc(strlen(op->name) + strlen(alias) + 2);
 			if (!name)
@@ -80,6 +81,7 @@ char **traceevent_plugin_list_options(void)
 			sprintf(name, "%s:%s", alias, op->name);
 			list = realloc(list, count + 2);
 			if (!list) {
+				list = temp;
 				free(name);
 				goto err;
 			}
@@ -87,16 +89,14 @@ char **traceevent_plugin_list_options(void)
 			list[count] = NULL;
 		}
 	}
-	if (!count)
-		return NULL;
 	return list;
 
  err:
-	while (--count > 0)
+	while (--count >= 0)
 		free(list[count]);
 	free(list);
 
-	return (char **)((unsigned long)-1);
+	return INVALID_PLUGIN_LIST_OPTION;
 }
 
 void traceevent_plugin_free_options_list(char **list)

[PATCH v2 1/4] tools lib traceevent: Add flag to not load event plugins

[Steven Rostedt]

[-- Attachment #1: 0001-tools-lib-traceevent-Add-flag-to-not-load-event-plug.patch --]
[-- Type: text/plain, Size: 1657 bytes --]

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

Add a flag to pevent that will let the callers be able to set it and
keep the system, and perhaps even normal plugins from being loaded.

This is useful when plugins might hide certain information and seeing
the raw events shows what may be going on.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/lib/traceevent/event-parse.h  | 2 ++
 tools/lib/traceevent/event-plugin.c | 7 ++++++-
 2 files changed, 8 insertions(+), 1 deletion(-)

diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index feab94281634..a68ec3d8289f 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -354,6 +354,8 @@ enum pevent_func_arg_type {
 
 enum pevent_flag {
 	PEVENT_NSEC_OUTPUT		= 1,	/* output in NSECS */
+	PEVENT_DISABLE_SYS_PLUGINS	= 1 << 1,
+	PEVENT_DISABLE_PLUGINS		= 1 << 2,
 };
 
 #define PEVENT_ERRORS 							      \
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 0c8bf6780e4d..317466bd1a37 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -148,12 +148,17 @@ load_plugins(struct pevent *pevent, const char *suffix,
 	char *path;
 	char *envdir;
 
+	if (pevent->flags & PEVENT_DISABLE_PLUGINS)
+		return;
+
 	/*
 	 * If a system plugin directory was defined,
 	 * check that first.
 	 */
 #ifdef PLUGIN_DIR
-	load_plugins_dir(pevent, suffix, PLUGIN_DIR, load_plugin, data);
+	if (!(pevent->flags & PEVENT_DISABLE_SYS_PLUGINS))
+		load_plugins_dir(pevent, suffix, PLUGIN_DIR,
+				 load_plugin, data);
 #endif
 
 	/*
-- 
2.0.0.rc2

[tip:perf/core] tools lib traceevent: Add flag to not load event plugins

[tip-bot for Steven Rostedt (Red Hat)]

Commit-ID:  a7c3196c79051f9e1a498f5be8fe6870bde5e55d
Gitweb:     http://git.kernel.org/tip/a7c3196c79051f9e1a498f5be8fe6870bde5e55d
Author:     Steven Rostedt (Red Hat) <rostedt@goodmis.org>
AuthorDate: Mon, 2 Jun 2014 23:20:13 -0400
Committer:  Jiri Olsa <jolsa@kernel.org>
CommitDate: Sat, 7 Jun 2014 23:33:36 +0200

tools lib traceevent: Add flag to not load event plugins

Add a flag to pevent that will let the callers be able to set it and
keep the system, and perhaps even normal plugins from being loaded.

This is useful when plugins might hide certain information and seeing
the raw events shows what may be going on.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20140603032223.678098063@goodmis.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
 tools/lib/traceevent/event-parse.h  | 2 ++
 tools/lib/traceevent/event-plugin.c | 7 ++++++-
 2 files changed, 8 insertions(+), 1 deletion(-)

diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index feab942..a68ec3d 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -354,6 +354,8 @@ enum pevent_func_arg_type {
 
 enum pevent_flag {
 	PEVENT_NSEC_OUTPUT		= 1,	/* output in NSECS */
+	PEVENT_DISABLE_SYS_PLUGINS	= 1 << 1,
+	PEVENT_DISABLE_PLUGINS		= 1 << 2,
 };
 
 #define PEVENT_ERRORS 							      \
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 0c8bf67..317466b 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -148,12 +148,17 @@ load_plugins(struct pevent *pevent, const char *suffix,
 	char *path;
 	char *envdir;
 
+	if (pevent->flags & PEVENT_DISABLE_PLUGINS)
+		return;
+
 	/*
 	 * If a system plugin directory was defined,
 	 * check that first.
 	 */
 #ifdef PLUGIN_DIR
-	load_plugins_dir(pevent, suffix, PLUGIN_DIR, load_plugin, data);
+	if (!(pevent->flags & PEVENT_DISABLE_SYS_PLUGINS))
+		load_plugins_dir(pevent, suffix, PLUGIN_DIR,
+				 load_plugin, data);
 #endif
 
 	/*

[PATCH v2 2/4] tools lib traceevent: Add options to plugins

[Steven Rostedt]

[-- Attachment #1: 0002-tools-lib-traceevent-Add-options-to-plugins.patch --]
[-- Type: text/plain, Size: 8227 bytes --]

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

The traceevent plugins allows developers to have their events print out
information that is more advanced than what can be achieved by the
trace event format files.

As these plugins are used on the userspace side of the tracing tools, it
is only logical that the tools should be able to produce different types
of output for the events. The types of events still need to be defined by
the plugins thus we need a way to pass information from the tool to the
plugin to specify what type of information to be shown.

Not only does the information need to be passed by the tool to plugin, but
the plugin also requires a way to notify the tool of what options it can
provide.

This builds the plugin option infrastructure that is taken from trace-cmd
that is used to allow plugins to produce different output based on the
options specified by the tool.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/lib/traceevent/event-parse.h  |  16 ++-
 tools/lib/traceevent/event-plugin.c | 197 ++++++++++++++++++++++++++++++++++++
 2 files changed, 210 insertions(+), 3 deletions(-)

diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index a68ec3d8289f..56e0e6c12411 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -107,8 +107,8 @@ typedef int (*pevent_event_handler_func)(struct trace_seq *s,
 typedef int (*pevent_plugin_load_func)(struct pevent *pevent);
 typedef int (*pevent_plugin_unload_func)(struct pevent *pevent);
 
-struct plugin_option {
-	struct plugin_option		*next;
+struct pevent_plugin_option {
+	struct pevent_plugin_option	*next;
 	void				*handle;
 	char				*file;
 	char				*name;
@@ -135,7 +135,7 @@ struct plugin_option {
  * PEVENT_PLUGIN_OPTIONS:  (optional)
  *   Plugin options that can be set before loading
  *
- *   struct plugin_option PEVENT_PLUGIN_OPTIONS[] = {
+ *   struct pevent_plugin_option PEVENT_PLUGIN_OPTIONS[] = {
  *	{
  *		.name = "option-name",
  *		.plugin_alias = "overide-file-name", (optional)
@@ -412,9 +412,19 @@ enum pevent_errno {
 
 struct plugin_list;
 
+#define INVALID_PLUGIN_LIST_OPTION	((char **)((unsigned long)-1))
+
 struct plugin_list *traceevent_load_plugins(struct pevent *pevent);
 void traceevent_unload_plugins(struct plugin_list *plugin_list,
 			       struct pevent *pevent);
+char **traceevent_plugin_list_options(void);
+void traceevent_plugin_free_options_list(char **list);
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options);
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options);
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list);
 
 struct cmdline;
 struct cmdline_list;
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 317466bd1a37..648ef84dc37e 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -18,6 +18,7 @@
  * ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  */
 
+#include <stdio.h>
 #include <string.h>
 #include <dlfcn.h>
 #include <stdlib.h>
@@ -30,12 +31,208 @@
 
 #define LOCAL_PLUGIN_DIR ".traceevent/plugins"
 
+static struct registered_plugin_options {
+	struct registered_plugin_options	*next;
+	struct pevent_plugin_option		*options;
+} *registered_options;
+
+static struct trace_plugin_options {
+	struct trace_plugin_options	*next;
+	char				*plugin;
+	char				*option;
+	char				*value;
+} *trace_plugin_options;
+
 struct plugin_list {
 	struct plugin_list	*next;
 	char			*name;
 	void			*handle;
 };
 
+/**
+ * traceevent_plugin_list_options - get list of plugin options
+ *
+ * Returns an array of char strings that list the currently registered
+ * plugin options in the format of <plugin>:<option>. This list can be
+ * used by toggling the option.
+ *
+ * Returns NULL if there's no options registered. On error it returns
+ * INVALID_PLUGIN_LIST_OPTION
+ *
+ * Must be freed with traceevent_plugin_free_options_list().
+ */
+char **traceevent_plugin_list_options(void)
+{
+	struct registered_plugin_options *reg;
+	struct pevent_plugin_option *op;
+	char **list = NULL;
+	char *name;
+	int count = 0;
+
+	for (reg = registered_options; reg; reg = reg->next) {
+		for (op = reg->options; op->name; op++) {
+			char *alias = op->plugin_alias ? op->plugin_alias : op->file;
+			char **temp = list;
+
+			name = malloc(strlen(op->name) + strlen(alias) + 2);
+			if (!name)
+				goto err;
+
+			sprintf(name, "%s:%s", alias, op->name);
+			list = realloc(list, count + 2);
+			if (!list) {
+				list = temp;
+				free(name);
+				goto err;
+			}
+			list[count++] = name;
+			list[count] = NULL;
+		}
+	}
+	return list;
+
+ err:
+	while (--count >= 0)
+		free(list[count]);
+	free(list);
+
+	return INVALID_PLUGIN_LIST_OPTION;
+}
+
+void traceevent_plugin_free_options_list(char **list)
+{
+	int i;
+
+	if (!list)
+		return;
+
+	if (list == (char **)((unsigned long)-1))
+		return;
+
+	for (i = 0; list[i]; i++)
+		free(list[i]);
+
+	free(list);
+}
+
+static int
+update_option(const char *file, struct pevent_plugin_option *option)
+{
+	struct trace_plugin_options *op;
+	char *plugin;
+
+	if (option->plugin_alias) {
+		plugin = strdup(option->plugin_alias);
+		if (!plugin)
+			return -1;
+	} else {
+		char *p;
+		plugin = strdup(file);
+		if (!plugin)
+			return -1;
+		p = strstr(plugin, ".");
+		if (p)
+			*p = '\0';
+	}
+
+	/* first look for named options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (!op->plugin)
+			continue;
+		if (strcmp(op->plugin, plugin) != 0)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		goto out;
+	}
+
+	/* first look for unnamed options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (op->plugin)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		break;
+	}
+
+ out:
+	free(plugin);
+	return 0;
+}
+
+/**
+ * traceevent_plugin_add_options - Add a set of options by a plugin
+ * @name: The name of the plugin adding the options
+ * @options: The set of options being loaded
+ *
+ * Sets the options with the values that have been added by user.
+ */
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options *reg;
+
+	reg = malloc(sizeof(*reg));
+	if (!reg)
+		return -1;
+	reg->next = registered_options;
+	reg->options = options;
+	registered_options = reg;
+
+	while (options->name) {
+		update_option(name, options);
+		options++;
+	}
+	return 0;
+}
+
+/**
+ * traceevent_plugin_remove_options - remove plugin options that were registered
+ * @options: Options to removed that were registered with traceevent_plugin_add_options
+ */
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options **last;
+	struct registered_plugin_options *reg;
+
+	for (last = &registered_options; *last; last = &(*last)->next) {
+		if ((*last)->options == options) {
+			reg = *last;
+			*last = reg->next;
+			free(reg);
+			return;
+		}
+	}
+			
+}
+
+/**
+ * traceevent_print_plugins - print out the list of plugins loaded
+ * @s: the trace_seq descripter to write to
+ * @prefix: The prefix string to add before listing the option name
+ * @suffix: The suffix string ot append after the option name
+ * @list: The list of plugins (usually returned by traceevent_load_plugins()
+ *
+ * Writes to the trace_seq @s the list of plugins (files) that is
+ * returned by traceevent_load_plugins(). Use @prefix and @suffix for formating:
+ * @prefix = "  ", @suffix = "\n".
+ */
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list)
+{
+	while (list) {
+		trace_seq_printf(s, "%s%s%s", prefix, list->name, suffix);
+		list = list->next;
+	}
+}
+
 static void
 load_plugin(struct pevent *pevent, const char *path,
 	    const char *file, void *data)
-- 
2.0.0.rc2

Re: [PATCH v2 2/4] tools lib traceevent: Add options to plugins

[Namhyung Kim]

On Mon, 02 Jun 2014 23:20:14 -0400, Steven Rostedt wrote:
> +void traceevent_plugin_free_options_list(char **list)
> +{
> +	int i;
> +
> +	if (!list)
> +		return;
> +
> +	if (list == (char **)((unsigned long)-1))

It also should be:

	if (list == INVALID_PLUGIN_LIST_OPTION)


Other than that, the series looks good to me now!

Thanks,
Namhyung


> +		return;
> +
> +	for (i = 0; list[i]; i++)
> +		free(list[i]);
> +
> +	free(list);
> +}

[PATCH v3 2/4] tools lib traceevent: Add options to plugins

[Steven Rostedt]

The traceevent plugins allows developers to have their events print out
information that is more advanced than what can be achieved by the
trace event format files.

As these plugins are used on the userspace side of the tracing tools, it
is only logical that the tools should be able to produce different types
of output for the events. The types of events still need to be defined by
the plugins thus we need a way to pass information from the tool to the
plugin to specify what type of information to be shown.

Not only does the information need to be passed by the tool to plugin, but
the plugin also requires a way to notify the tool of what options it can
provide.

This builds the plugin option infrastructure that is taken from trace-cmd
that is used to allow plugins to produce different output based on the
options specified by the tool.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/lib/traceevent/event-parse.h  |  16 ++-
 tools/lib/traceevent/event-plugin.c | 197 ++++++++++++++++++++++++++++++++++++
 2 files changed, 210 insertions(+), 3 deletions(-)

diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index a68ec3d8289f..56e0e6c12411 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -107,8 +107,8 @@ typedef int (*pevent_event_handler_func)(struct trace_seq *s,
 typedef int (*pevent_plugin_load_func)(struct pevent *pevent);
 typedef int (*pevent_plugin_unload_func)(struct pevent *pevent);
 
-struct plugin_option {
-	struct plugin_option		*next;
+struct pevent_plugin_option {
+	struct pevent_plugin_option	*next;
 	void				*handle;
 	char				*file;
 	char				*name;
@@ -135,7 +135,7 @@ struct plugin_option {
  * PEVENT_PLUGIN_OPTIONS:  (optional)
  *   Plugin options that can be set before loading
  *
- *   struct plugin_option PEVENT_PLUGIN_OPTIONS[] = {
+ *   struct pevent_plugin_option PEVENT_PLUGIN_OPTIONS[] = {
  *	{
  *		.name = "option-name",
  *		.plugin_alias = "overide-file-name", (optional)
@@ -412,9 +412,19 @@ enum pevent_errno {
 
 struct plugin_list;
 
+#define INVALID_PLUGIN_LIST_OPTION	((char **)((unsigned long)-1))
+
 struct plugin_list *traceevent_load_plugins(struct pevent *pevent);
 void traceevent_unload_plugins(struct plugin_list *plugin_list,
 			       struct pevent *pevent);
+char **traceevent_plugin_list_options(void);
+void traceevent_plugin_free_options_list(char **list);
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options);
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options);
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list);
 
 struct cmdline;
 struct cmdline_list;
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 317466bd1a37..db7765be1bb6 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -18,6 +18,7 @@
  * ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  */
 
+#include <stdio.h>
 #include <string.h>
 #include <dlfcn.h>
 #include <stdlib.h>
@@ -30,12 +31,208 @@
 
 #define LOCAL_PLUGIN_DIR ".traceevent/plugins"
 
+static struct registered_plugin_options {
+	struct registered_plugin_options	*next;
+	struct pevent_plugin_option		*options;
+} *registered_options;
+
+static struct trace_plugin_options {
+	struct trace_plugin_options	*next;
+	char				*plugin;
+	char				*option;
+	char				*value;
+} *trace_plugin_options;
+
 struct plugin_list {
 	struct plugin_list	*next;
 	char			*name;
 	void			*handle;
 };
 
+/**
+ * traceevent_plugin_list_options - get list of plugin options
+ *
+ * Returns an array of char strings that list the currently registered
+ * plugin options in the format of <plugin>:<option>. This list can be
+ * used by toggling the option.
+ *
+ * Returns NULL if there's no options registered. On error it returns
+ * INVALID_PLUGIN_LIST_OPTION
+ *
+ * Must be freed with traceevent_plugin_free_options_list().
+ */
+char **traceevent_plugin_list_options(void)
+{
+	struct registered_plugin_options *reg;
+	struct pevent_plugin_option *op;
+	char **list = NULL;
+	char *name;
+	int count = 0;
+
+	for (reg = registered_options; reg; reg = reg->next) {
+		for (op = reg->options; op->name; op++) {
+			char *alias = op->plugin_alias ? op->plugin_alias : op->file;
+			char **temp = list;
+
+			name = malloc(strlen(op->name) + strlen(alias) + 2);
+			if (!name)
+				goto err;
+
+			sprintf(name, "%s:%s", alias, op->name);
+			list = realloc(list, count + 2);
+			if (!list) {
+				list = temp;
+				free(name);
+				goto err;
+			}
+			list[count++] = name;
+			list[count] = NULL;
+		}
+	}
+	return list;
+
+ err:
+	while (--count >= 0)
+		free(list[count]);
+	free(list);
+
+	return INVALID_PLUGIN_LIST_OPTION;
+}
+
+void traceevent_plugin_free_options_list(char **list)
+{
+	int i;
+
+	if (!list)
+		return;
+
+	if (list == INVALID_PLUGIN_LIST_OPTION)
+		return;
+
+	for (i = 0; list[i]; i++)
+		free(list[i]);
+
+	free(list);
+}
+
+static int
+update_option(const char *file, struct pevent_plugin_option *option)
+{
+	struct trace_plugin_options *op;
+	char *plugin;
+
+	if (option->plugin_alias) {
+		plugin = strdup(option->plugin_alias);
+		if (!plugin)
+			return -1;
+	} else {
+		char *p;
+		plugin = strdup(file);
+		if (!plugin)
+			return -1;
+		p = strstr(plugin, ".");
+		if (p)
+			*p = '\0';
+	}
+
+	/* first look for named options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (!op->plugin)
+			continue;
+		if (strcmp(op->plugin, plugin) != 0)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		goto out;
+	}
+
+	/* first look for unnamed options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (op->plugin)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		break;
+	}
+
+ out:
+	free(plugin);
+	return 0;
+}
+
+/**
+ * traceevent_plugin_add_options - Add a set of options by a plugin
+ * @name: The name of the plugin adding the options
+ * @options: The set of options being loaded
+ *
+ * Sets the options with the values that have been added by user.
+ */
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options *reg;
+
+	reg = malloc(sizeof(*reg));
+	if (!reg)
+		return -1;
+	reg->next = registered_options;
+	reg->options = options;
+	registered_options = reg;
+
+	while (options->name) {
+		update_option(name, options);
+		options++;
+	}
+	return 0;
+}
+
+/**
+ * traceevent_plugin_remove_options - remove plugin options that were registered
+ * @options: Options to removed that were registered with traceevent_plugin_add_options
+ */
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options **last;
+	struct registered_plugin_options *reg;
+
+	for (last = &registered_options; *last; last = &(*last)->next) {
+		if ((*last)->options == options) {
+			reg = *last;
+			*last = reg->next;
+			free(reg);
+			return;
+		}
+	}
+			
+}
+
+/**
+ * traceevent_print_plugins - print out the list of plugins loaded
+ * @s: the trace_seq descripter to write to
+ * @prefix: The prefix string to add before listing the option name
+ * @suffix: The suffix string ot append after the option name
+ * @list: The list of plugins (usually returned by traceevent_load_plugins()
+ *
+ * Writes to the trace_seq @s the list of plugins (files) that is
+ * returned by traceevent_load_plugins(). Use @prefix and @suffix for formating:
+ * @prefix = "  ", @suffix = "\n".
+ */
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list)
+{
+	while (list) {
+		trace_seq_printf(s, "%s%s%s", prefix, list->name, suffix);
+		list = list->next;
+	}
+}
+
 static void
 load_plugin(struct pevent *pevent, const char *path,
 	    const char *file, void *data)
-- 
2.0.0.rc2

Re: [PATCH v3 2/4] tools lib traceevent: Add options to plugins

[Steven Rostedt]

On Tue, 3 Jun 2014 18:41:54 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> 
> The traceevent plugins allows developers to have their events print out
> information that is more advanced than what can be achieved by the
> trace event format files.
> 
> As these plugins are used on the userspace side of the tracing tools, it
> is only logical that the tools should be able to produce different types
> of output for the events. The types of events still need to be defined by
> the plugins thus we need a way to pass information from the tool to the
> plugin to specify what type of information to be shown.
> 
> Not only does the information need to be passed by the tool to plugin, but
> the plugin also requires a way to notify the tool of what options it can
> provide.
> 
> This builds the plugin option infrastructure that is taken from trace-cmd
> that is used to allow plugins to produce different output based on the
> options specified by the tool.
> 
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

Jiri,

I only sent this patch for v3, as the 1,3,4 are fine. Do you want me to
send a full series? Or can you just pull in v2 of patches 1,3 and 4 and
then v3 of this one?

-- Steve

Re: [PATCH v3 2/4] tools lib traceevent: Add options to plugins

[Jiri Olsa]

On Tue, Jun 03, 2014 at 06:43:10PM -0400, Steven Rostedt wrote:
> On Tue, 3 Jun 2014 18:41:54 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > 
> > The traceevent plugins allows developers to have their events print out
> > information that is more advanced than what can be achieved by the
> > trace event format files.
> > 
> > As these plugins are used on the userspace side of the tracing tools, it
> > is only logical that the tools should be able to produce different types
> > of output for the events. The types of events still need to be defined by
> > the plugins thus we need a way to pass information from the tool to the
> > plugin to specify what type of information to be shown.
> > 
> > Not only does the information need to be passed by the tool to plugin, but
> > the plugin also requires a way to notify the tool of what options it can
> > provide.
> > 
> > This builds the plugin option infrastructure that is taken from trace-cmd
> > that is used to allow plugins to produce different output based on the
> > options specified by the tool.
> > 
> > Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> 
> Jiri,
> 
> I only sent this patch for v3, as the 1,3,4 are fine. Do you want me to
> send a full series? Or can you just pull in v2 of patches 1,3 and 4 and
> then v3 of this one?

no need to resend, I'll take it from here

jirka

[tip:perf/core] tools lib traceevent: Add options to plugins

[tip-bot for Steven Rostedt]

Commit-ID:  5827f2faabe40cc285cc67b697277547a19b6c9a
Gitweb:     http://git.kernel.org/tip/5827f2faabe40cc285cc67b697277547a19b6c9a
Author:     Steven Rostedt <rostedt@goodmis.org>
AuthorDate: Tue, 3 Jun 2014 18:41:54 -0400
Committer:  Jiri Olsa <jolsa@kernel.org>
CommitDate: Sat, 7 Jun 2014 23:33:36 +0200

tools lib traceevent: Add options to plugins

The traceevent plugins allows developers to have their events print out
information that is more advanced than what can be achieved by the
trace event format files.

As these plugins are used on the userspace side of the tracing tools, it
is only logical that the tools should be able to produce different types
of output for the events. The types of events still need to be defined by
the plugins thus we need a way to pass information from the tool to the
plugin to specify what type of information to be shown.

Not only does the information need to be passed by the tool to plugin, but
the plugin also requires a way to notify the tool of what options it can
provide.

This builds the plugin option infrastructure that is taken from trace-cmd
that is used to allow plugins to produce different output based on the
options specified by the tool.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20140603184154.0a4c031c@gandalf.local.home
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
 tools/lib/traceevent/event-parse.h  |  16 ++-
 tools/lib/traceevent/event-plugin.c | 196 ++++++++++++++++++++++++++++++++++++
 2 files changed, 209 insertions(+), 3 deletions(-)

diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index a68ec3d..56e0e6c 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -107,8 +107,8 @@ typedef int (*pevent_event_handler_func)(struct trace_seq *s,
 typedef int (*pevent_plugin_load_func)(struct pevent *pevent);
 typedef int (*pevent_plugin_unload_func)(struct pevent *pevent);
 
-struct plugin_option {
-	struct plugin_option		*next;
+struct pevent_plugin_option {
+	struct pevent_plugin_option	*next;
 	void				*handle;
 	char				*file;
 	char				*name;
@@ -135,7 +135,7 @@ struct plugin_option {
  * PEVENT_PLUGIN_OPTIONS:  (optional)
  *   Plugin options that can be set before loading
  *
- *   struct plugin_option PEVENT_PLUGIN_OPTIONS[] = {
+ *   struct pevent_plugin_option PEVENT_PLUGIN_OPTIONS[] = {
  *	{
  *		.name = "option-name",
  *		.plugin_alias = "overide-file-name", (optional)
@@ -412,9 +412,19 @@ enum pevent_errno {
 
 struct plugin_list;
 
+#define INVALID_PLUGIN_LIST_OPTION	((char **)((unsigned long)-1))
+
 struct plugin_list *traceevent_load_plugins(struct pevent *pevent);
 void traceevent_unload_plugins(struct plugin_list *plugin_list,
 			       struct pevent *pevent);
+char **traceevent_plugin_list_options(void);
+void traceevent_plugin_free_options_list(char **list);
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options);
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options);
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list);
 
 struct cmdline;
 struct cmdline_list;
diff --git a/tools/lib/traceevent/event-plugin.c b/tools/lib/traceevent/event-plugin.c
index 317466b..136162c 100644
--- a/tools/lib/traceevent/event-plugin.c
+++ b/tools/lib/traceevent/event-plugin.c
@@ -18,6 +18,7 @@
  * ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  */
 
+#include <stdio.h>
 #include <string.h>
 #include <dlfcn.h>
 #include <stdlib.h>
@@ -30,12 +31,207 @@
 
 #define LOCAL_PLUGIN_DIR ".traceevent/plugins"
 
+static struct registered_plugin_options {
+	struct registered_plugin_options	*next;
+	struct pevent_plugin_option		*options;
+} *registered_options;
+
+static struct trace_plugin_options {
+	struct trace_plugin_options	*next;
+	char				*plugin;
+	char				*option;
+	char				*value;
+} *trace_plugin_options;
+
 struct plugin_list {
 	struct plugin_list	*next;
 	char			*name;
 	void			*handle;
 };
 
+/**
+ * traceevent_plugin_list_options - get list of plugin options
+ *
+ * Returns an array of char strings that list the currently registered
+ * plugin options in the format of <plugin>:<option>. This list can be
+ * used by toggling the option.
+ *
+ * Returns NULL if there's no options registered. On error it returns
+ * INVALID_PLUGIN_LIST_OPTION
+ *
+ * Must be freed with traceevent_plugin_free_options_list().
+ */
+char **traceevent_plugin_list_options(void)
+{
+	struct registered_plugin_options *reg;
+	struct pevent_plugin_option *op;
+	char **list = NULL;
+	char *name;
+	int count = 0;
+
+	for (reg = registered_options; reg; reg = reg->next) {
+		for (op = reg->options; op->name; op++) {
+			char *alias = op->plugin_alias ? op->plugin_alias : op->file;
+			char **temp = list;
+
+			name = malloc(strlen(op->name) + strlen(alias) + 2);
+			if (!name)
+				goto err;
+
+			sprintf(name, "%s:%s", alias, op->name);
+			list = realloc(list, count + 2);
+			if (!list) {
+				list = temp;
+				free(name);
+				goto err;
+			}
+			list[count++] = name;
+			list[count] = NULL;
+		}
+	}
+	return list;
+
+ err:
+	while (--count >= 0)
+		free(list[count]);
+	free(list);
+
+	return INVALID_PLUGIN_LIST_OPTION;
+}
+
+void traceevent_plugin_free_options_list(char **list)
+{
+	int i;
+
+	if (!list)
+		return;
+
+	if (list == INVALID_PLUGIN_LIST_OPTION)
+		return;
+
+	for (i = 0; list[i]; i++)
+		free(list[i]);
+
+	free(list);
+}
+
+static int
+update_option(const char *file, struct pevent_plugin_option *option)
+{
+	struct trace_plugin_options *op;
+	char *plugin;
+
+	if (option->plugin_alias) {
+		plugin = strdup(option->plugin_alias);
+		if (!plugin)
+			return -1;
+	} else {
+		char *p;
+		plugin = strdup(file);
+		if (!plugin)
+			return -1;
+		p = strstr(plugin, ".");
+		if (p)
+			*p = '\0';
+	}
+
+	/* first look for named options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (!op->plugin)
+			continue;
+		if (strcmp(op->plugin, plugin) != 0)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		goto out;
+	}
+
+	/* first look for unnamed options */
+	for (op = trace_plugin_options; op; op = op->next) {
+		if (op->plugin)
+			continue;
+		if (strcmp(op->option, option->name) != 0)
+			continue;
+
+		option->value = op->value;
+		option->set ^= 1;
+		break;
+	}
+
+ out:
+	free(plugin);
+	return 0;
+}
+
+/**
+ * traceevent_plugin_add_options - Add a set of options by a plugin
+ * @name: The name of the plugin adding the options
+ * @options: The set of options being loaded
+ *
+ * Sets the options with the values that have been added by user.
+ */
+int traceevent_plugin_add_options(const char *name,
+				  struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options *reg;
+
+	reg = malloc(sizeof(*reg));
+	if (!reg)
+		return -1;
+	reg->next = registered_options;
+	reg->options = options;
+	registered_options = reg;
+
+	while (options->name) {
+		update_option(name, options);
+		options++;
+	}
+	return 0;
+}
+
+/**
+ * traceevent_plugin_remove_options - remove plugin options that were registered
+ * @options: Options to removed that were registered with traceevent_plugin_add_options
+ */
+void traceevent_plugin_remove_options(struct pevent_plugin_option *options)
+{
+	struct registered_plugin_options **last;
+	struct registered_plugin_options *reg;
+
+	for (last = &registered_options; *last; last = &(*last)->next) {
+		if ((*last)->options == options) {
+			reg = *last;
+			*last = reg->next;
+			free(reg);
+			return;
+		}
+	}
+}
+
+/**
+ * traceevent_print_plugins - print out the list of plugins loaded
+ * @s: the trace_seq descripter to write to
+ * @prefix: The prefix string to add before listing the option name
+ * @suffix: The suffix string ot append after the option name
+ * @list: The list of plugins (usually returned by traceevent_load_plugins()
+ *
+ * Writes to the trace_seq @s the list of plugins (files) that is
+ * returned by traceevent_load_plugins(). Use @prefix and @suffix for formating:
+ * @prefix = "  ", @suffix = "\n".
+ */
+void traceevent_print_plugins(struct trace_seq *s,
+			      const char *prefix, const char *suffix,
+			      const struct plugin_list *list)
+{
+	while (list) {
+		trace_seq_printf(s, "%s%s%s", prefix, list->name, suffix);
+		list = list->next;
+	}
+}
+
 static void
 load_plugin(struct pevent *pevent, const char *path,
 	    const char *file, void *data)

Re: [PATCH v2 2/4] tools lib traceevent: Add options to plugins

[Jiri Olsa]

On Tue, Jun 03, 2014 at 03:51:22PM +0900, Namhyung Kim wrote:
> On Mon, 02 Jun 2014 23:20:14 -0400, Steven Rostedt wrote:
> > +void traceevent_plugin_free_options_list(char **list)
> > +{
> > +	int i;
> > +
> > +	if (!list)
> > +		return;
> > +
> > +	if (list == (char **)((unsigned long)-1))
> 
> It also should be:
> 
> 	if (list == INVALID_PLUGIN_LIST_OPTION)
> 
> 
> Other than that, the series looks good to me now!

can I use your Acked-by?

thanks,
jirka

Re: [PATCH v2 2/4] tools lib traceevent: Add options to plugins

[Namhyung Kim]

Hi Jiri,

2014-06-04 (수), 13:42 +0200, Jiri Olsa:
> On Tue, Jun 03, 2014 at 03:51:22PM +0900, Namhyung Kim wrote:
> > On Mon, 02 Jun 2014 23:20:14 -0400, Steven Rostedt wrote:
> > > +void traceevent_plugin_free_options_list(char **list)
> > > +{
> > > +	int i;
> > > +
> > > +	if (!list)
> > > +		return;
> > > +
> > > +	if (list == (char **)((unsigned long)-1))
> > 
> > It also should be:
> > 
> > 	if (list == INVALID_PLUGIN_LIST_OPTION)
> > 
> > 
> > Other than that, the series looks good to me now!
> 
> can I use your Acked-by?

Sure thing!

Acked-by: Namhyung Kim <namhyung@kernel.org>

Thanks,
Namhyung

[PATCH v2 3/4] tools lib traceevent: Add options to function plugin

[Steven Rostedt]

[-- Attachment #1: 0003-tools-lib-traceevent-Add-options-to-function-plugin.patch --]
[-- Type: text/plain, Size: 4194 bytes --]

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

Add the options "parent" and "indent" to the function plugin.

When parent is set, the output looks like this:

function:             fsnotify_modify <-- vfs_write
function:             zone_statistics <-- get_page_from_freelist
function:                __inc_zone_state <-- zone_statistics
function:                inotify_inode_queue_event <-- fsnotify_modify
function:                fsnotify_parent <-- fsnotify_modify
function:                __inc_zone_state <-- zone_statistics
function:                   __fsnotify_parent <-- fsnotify_parent
function:                   inotify_dentry_parent_queue_event <-- fsnotify_parent
function:             add_to_page_cache_lru <-- do_read_cache_page

When it's not set, it looks like:

function:             fsnotify_modify
function:             zone_statistics
function:                __inc_zone_state
function:                inotify_inode_queue_event
function:                fsnotify_parent
function:                __inc_zone_state
function:                   __fsnotify_parent
function:                   inotify_dentry_parent_queue_event
function:             add_to_page_cache_lru

When the otpion "indent" is not set, it looks like this:

function:             fsnotify_modify <-- vfs_write
function:             zone_statistics <-- get_page_from_freelist
function:             __inc_zone_state <-- zone_statistics
function:             inotify_inode_queue_event <-- fsnotify_modify
function:             fsnotify_parent <-- fsnotify_modify
function:             __inc_zone_state <-- zone_statistics
function:             __fsnotify_parent <-- fsnotify_parent
function:             inotify_dentry_parent_queue_event <-- fsnotify_parent
function:             add_to_page_cache_lru <-- do_read_cache_page

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/lib/traceevent/plugin_function.c | 43 +++++++++++++++++++++++++++++-----
 1 file changed, 37 insertions(+), 6 deletions(-)

diff --git a/tools/lib/traceevent/plugin_function.c b/tools/lib/traceevent/plugin_function.c
index 80ba4ff1fe84..a00ec190821a 100644
--- a/tools/lib/traceevent/plugin_function.c
+++ b/tools/lib/traceevent/plugin_function.c
@@ -33,6 +33,29 @@ static int cpus = -1;
 
 #define STK_BLK 10
 
+struct pevent_plugin_option plugin_options[] =
+{
+	{
+		.name = "parent",
+		.plugin_alias = "ftrace",
+		.description =
+		"Print parent of functions for function events",
+	},
+	{
+		.name = "indent",
+		.plugin_alias = "ftrace",
+		.description =
+		"Try to show function call indents, based on parents",
+		.set = 1,
+	},
+	{
+		.name = NULL,
+	}
+};
+
+static struct pevent_plugin_option *ftrace_parent = &plugin_options[0];
+static struct pevent_plugin_option *ftrace_indent = &plugin_options[1];
+
 static void add_child(struct func_stack *stack, const char *child, int pos)
 {
 	int i;
@@ -119,7 +142,8 @@ static int function_handler(struct trace_seq *s, struct pevent_record *record,
 
 	parent = pevent_find_function(pevent, pfunction);
 
-	index = add_and_get_index(parent, func, record->cpu);
+	if (parent && ftrace_indent->set)
+		index = add_and_get_index(parent, func, record->cpu);
 
 	trace_seq_printf(s, "%*s", index*3, "");
 
@@ -128,11 +152,13 @@ static int function_handler(struct trace_seq *s, struct pevent_record *record,
 	else
 		trace_seq_printf(s, "0x%llx", function);
 
-	trace_seq_printf(s, " <-- ");
-	if (parent)
-		trace_seq_printf(s, "%s", parent);
-	else
-		trace_seq_printf(s, "0x%llx", pfunction);
+	if (ftrace_parent->set) {
+		trace_seq_printf(s, " <-- ");
+		if (parent)
+			trace_seq_printf(s, "%s", parent);
+		else
+			trace_seq_printf(s, "0x%llx", pfunction);
+	}
 
 	return 0;
 }
@@ -141,6 +167,9 @@ int PEVENT_PLUGIN_LOADER(struct pevent *pevent)
 {
 	pevent_register_event_handler(pevent, -1, "ftrace", "function",
 				      function_handler, NULL);
+
+	traceevent_plugin_add_options("ftrace", plugin_options);
+
 	return 0;
 }
 
@@ -157,6 +186,8 @@ void PEVENT_PLUGIN_UNLOADER(struct pevent *pevent)
 		free(fstack[i].stack);
 	}
 
+	traceevent_plugin_remove_options(plugin_options);
+
 	free(fstack);
 	fstack = NULL;
 	cpus = -1;
-- 
2.0.0.rc2

[tip:perf/core] tools lib traceevent: Add options to function plugin

[tip-bot for Steven Rostedt (Red Hat)]

Commit-ID:  49440828ad7b809e9d31f6108875e3b1e974690c
Gitweb:     http://git.kernel.org/tip/49440828ad7b809e9d31f6108875e3b1e974690c
Author:     Steven Rostedt (Red Hat) <rostedt@goodmis.org>
AuthorDate: Mon, 2 Jun 2014 23:20:15 -0400
Committer:  Jiri Olsa <jolsa@kernel.org>
CommitDate: Sat, 7 Jun 2014 23:33:37 +0200

tools lib traceevent: Add options to function plugin

Add the options "parent" and "indent" to the function plugin.

When parent is set, the output looks like this:

function:             fsnotify_modify <-- vfs_write
function:             zone_statistics <-- get_page_from_freelist
function:                __inc_zone_state <-- zone_statistics
function:                inotify_inode_queue_event <-- fsnotify_modify
function:                fsnotify_parent <-- fsnotify_modify
function:                __inc_zone_state <-- zone_statistics
function:                   __fsnotify_parent <-- fsnotify_parent
function:                   inotify_dentry_parent_queue_event <-- fsnotify_parent
function:             add_to_page_cache_lru <-- do_read_cache_page

When it's not set, it looks like:

function:             fsnotify_modify
function:             zone_statistics
function:                __inc_zone_state
function:                inotify_inode_queue_event
function:                fsnotify_parent
function:                __inc_zone_state
function:                   __fsnotify_parent
function:                   inotify_dentry_parent_queue_event
function:             add_to_page_cache_lru

When the otpion "indent" is not set, it looks like this:

function:             fsnotify_modify <-- vfs_write
function:             zone_statistics <-- get_page_from_freelist
function:             __inc_zone_state <-- zone_statistics
function:             inotify_inode_queue_event <-- fsnotify_modify
function:             fsnotify_parent <-- fsnotify_modify
function:             __inc_zone_state <-- zone_statistics
function:             __fsnotify_parent <-- fsnotify_parent
function:             inotify_dentry_parent_queue_event <-- fsnotify_parent
function:             add_to_page_cache_lru <-- do_read_cache_page

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20140603032224.056940410@goodmis.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
 tools/lib/traceevent/plugin_function.c | 43 +++++++++++++++++++++++++++++-----
 1 file changed, 37 insertions(+), 6 deletions(-)

diff --git a/tools/lib/traceevent/plugin_function.c b/tools/lib/traceevent/plugin_function.c
index 80ba4ff..a00ec19 100644
--- a/tools/lib/traceevent/plugin_function.c
+++ b/tools/lib/traceevent/plugin_function.c
@@ -33,6 +33,29 @@ static int cpus = -1;
 
 #define STK_BLK 10
 
+struct pevent_plugin_option plugin_options[] =
+{
+	{
+		.name = "parent",
+		.plugin_alias = "ftrace",
+		.description =
+		"Print parent of functions for function events",
+	},
+	{
+		.name = "indent",
+		.plugin_alias = "ftrace",
+		.description =
+		"Try to show function call indents, based on parents",
+		.set = 1,
+	},
+	{
+		.name = NULL,
+	}
+};
+
+static struct pevent_plugin_option *ftrace_parent = &plugin_options[0];
+static struct pevent_plugin_option *ftrace_indent = &plugin_options[1];
+
 static void add_child(struct func_stack *stack, const char *child, int pos)
 {
 	int i;
@@ -119,7 +142,8 @@ static int function_handler(struct trace_seq *s, struct pevent_record *record,
 
 	parent = pevent_find_function(pevent, pfunction);
 
-	index = add_and_get_index(parent, func, record->cpu);
+	if (parent && ftrace_indent->set)
+		index = add_and_get_index(parent, func, record->cpu);
 
 	trace_seq_printf(s, "%*s", index*3, "");
 
@@ -128,11 +152,13 @@ static int function_handler(struct trace_seq *s, struct pevent_record *record,
 	else
 		trace_seq_printf(s, "0x%llx", function);
 
-	trace_seq_printf(s, " <-- ");
-	if (parent)
-		trace_seq_printf(s, "%s", parent);
-	else
-		trace_seq_printf(s, "0x%llx", pfunction);
+	if (ftrace_parent->set) {
+		trace_seq_printf(s, " <-- ");
+		if (parent)
+			trace_seq_printf(s, "%s", parent);
+		else
+			trace_seq_printf(s, "0x%llx", pfunction);
+	}
 
 	return 0;
 }
@@ -141,6 +167,9 @@ int PEVENT_PLUGIN_LOADER(struct pevent *pevent)
 {
 	pevent_register_event_handler(pevent, -1, "ftrace", "function",
 				      function_handler, NULL);
+
+	traceevent_plugin_add_options("ftrace", plugin_options);
+
 	return 0;
 }
 
@@ -157,6 +186,8 @@ void PEVENT_PLUGIN_UNLOADER(struct pevent *pevent)
 		free(fstack[i].stack);
 	}
 
+	traceevent_plugin_remove_options(plugin_options);
+
 	free(fstack);
 	fstack = NULL;
 	cpus = -1;

[PATCH v2 4/4] tools lib traceevent: Added support for __get_bitmask() macro

[Steven Rostedt]

[-- Attachment #1: 0004-tools-lib-traceevent-Added-support-for-__get_bitmask.patch --]
[-- Type: text/plain, Size: 8035 bytes --]

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

Coming in v3.16, trace events will be able to save bitmasks in raw
format in the ring buffer and output it with the __get_bitmask() macro.

In order for userspace tools to parse this, it must be able to handle
the __get_bitmask() call and be able to convert the data that's in
the ring buffer into a nice bitmask format. The output is similar to
what the kernel uses to print bitmasks, with a comma separator every
4 bytes (8 characters).

This allows for cpumasks to also be saved efficiently.

The first user is the thermal:thermal_power_limit event which has the
following output:

 thermal_power_limit:  cpus=0000000f freq=1900000 cdev_state=0 power=5252

Link: http://lkml.kernel.org/r/20140506132238.22e136d1@gandalf.local.home

Suggested-by: Javi Merino <javi.merino@arm.com>
Tested-by: Javi Merino <javi.merino@arm.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/lib/traceevent/event-parse.c                 | 113 +++++++++++++++++++++
 tools/lib/traceevent/event-parse.h                 |   7 ++
 .../perf/util/scripting-engines/trace-event-perl.c |   1 +
 .../util/scripting-engines/trace-event-python.c    |   1 +
 4 files changed, 122 insertions(+)

diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index b83184f2d484..93825a17dcce 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -765,6 +765,9 @@ static void free_arg(struct print_arg *arg)
 	case PRINT_BSTRING:
 		free(arg->string.string);
 		break;
+	case PRINT_BITMASK:
+		free(arg->bitmask.bitmask);
+		break;
 	case PRINT_DYNAMIC_ARRAY:
 		free(arg->dynarray.index);
 		break;
@@ -2268,6 +2271,7 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		ret = 0;
@@ -2296,6 +2300,7 @@ static char *arg_eval (struct print_arg *arg)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		break;
@@ -2683,6 +2688,35 @@ process_str(struct event_format *event __maybe_unused, struct print_arg *arg,
 	return EVENT_ERROR;
 }
 
+static enum event_type
+process_bitmask(struct event_format *event __maybe_unused, struct print_arg *arg,
+	    char **tok)
+{
+	enum event_type type;
+	char *token;
+
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto out_free;
+
+	arg->type = PRINT_BITMASK;
+	arg->bitmask.bitmask = token;
+	arg->bitmask.offset = -1;
+
+	if (read_expected(EVENT_DELIM, ")") < 0)
+		goto out_err;
+
+	type = read_token(&token);
+	*tok = token;
+
+	return type;
+
+ out_free:
+	free_token(token);
+ out_err:
+	*tok = NULL;
+	return EVENT_ERROR;
+}
+
 static struct pevent_function_handler *
 find_func_handler(struct pevent *pevent, char *func_name)
 {
@@ -2797,6 +2831,10 @@ process_function(struct event_format *event, struct print_arg *arg,
 		free_token(token);
 		return process_str(event, arg, tok);
 	}
+	if (strcmp(token, "__get_bitmask") == 0) {
+		free_token(token);
+		return process_bitmask(event, arg, tok);
+	}
 	if (strcmp(token, "__get_dynamic_array") == 0) {
 		free_token(token);
 		return process_dynamic_array(event, arg, tok);
@@ -3324,6 +3362,7 @@ eval_num_arg(void *data, int size, struct event_format *event, struct print_arg
 		return eval_type(val, arg, 0);
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 		return 0;
 	case PRINT_FUNC: {
 		struct trace_seq s;
@@ -3556,6 +3595,60 @@ static void print_str_to_seq(struct trace_seq *s, const char *format,
 		trace_seq_printf(s, format, str);
 }
 
+static void print_bitmask_to_seq(struct pevent *pevent,
+				 struct trace_seq *s, const char *format,
+				 int len_arg, const void *data, int size)
+{
+	int nr_bits = size * 8;
+	int str_size = (nr_bits + 3) / 4;
+	int len = 0;
+	char buf[3];
+	char *str;
+	int index;
+	int i;
+
+	/*
+	 * The kernel likes to put in commas every 32 bits, we
+	 * can do the same.
+	 */
+	str_size += (nr_bits - 1) / 32;
+
+	str = malloc(str_size + 1);
+	if (!str) {
+		do_warning("%s: not enough memory!", __func__);
+		return;
+	}
+	str[str_size] = 0;
+
+	/* Start out with -2 for the two chars per byte */
+	for (i = str_size - 2; i >= 0; i -= 2) {
+		/*
+		 * data points to a bit mask of size bytes.
+		 * In the kernel, this is an array of long words, thus
+		 * endianess is very important.
+		 */
+		if (pevent->file_bigendian)
+			index = size - (len + 1);
+		else
+			index = len;
+
+		snprintf(buf, 3, "%02x", *((unsigned char *)data + index));
+		memcpy(str + i, buf, 2);
+		len++;
+		if (!(len & 3) && i > 0) {
+			i--;
+			str[i] = ',';
+		}
+	}
+
+	if (len_arg >= 0)
+		trace_seq_printf(s, format, len_arg, str);
+	else
+		trace_seq_printf(s, format, str);
+
+	free(str);
+}
+
 static void print_str_arg(struct trace_seq *s, void *data, int size,
 			  struct event_format *event, const char *format,
 			  int len_arg, struct print_arg *arg)
@@ -3691,6 +3784,23 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 	case PRINT_BSTRING:
 		print_str_to_seq(s, format, len_arg, arg->string.string);
 		break;
+	case PRINT_BITMASK: {
+		int bitmask_offset;
+		int bitmask_size;
+
+		if (arg->bitmask.offset == -1) {
+			struct format_field *f;
+
+			f = pevent_find_any_field(event, arg->bitmask.bitmask);
+			arg->bitmask.offset = f->offset;
+		}
+		bitmask_offset = data2host4(pevent, data + arg->bitmask.offset);
+		bitmask_size = bitmask_offset >> 16;
+		bitmask_offset &= 0xffff;
+		print_bitmask_to_seq(pevent, s, format, len_arg,
+				     data + bitmask_offset, bitmask_size);
+		break;
+	}
 	case PRINT_OP:
 		/*
 		 * The only op for string should be ? :
@@ -4822,6 +4932,9 @@ static void print_args(struct print_arg *args)
 	case PRINT_BSTRING:
 		printf("__get_str(%s)", args->string.string);
 		break;
+	case PRINT_BITMASK:
+		printf("__get_bitmask(%s)", args->bitmask.bitmask);
+		break;
 	case PRINT_TYPE:
 		printf("(%s)", args->typecast.type);
 		print_args(args->typecast.item);
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 56e0e6c12411..7a3873ff9a4f 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -208,6 +208,11 @@ struct print_arg_string {
 	int			offset;
 };
 
+struct print_arg_bitmask {
+	char			*bitmask;
+	int			offset;
+};
+
 struct print_arg_field {
 	char			*name;
 	struct format_field	*field;
@@ -274,6 +279,7 @@ enum print_arg_type {
 	PRINT_DYNAMIC_ARRAY,
 	PRINT_OP,
 	PRINT_FUNC,
+	PRINT_BITMASK,
 };
 
 struct print_arg {
@@ -288,6 +294,7 @@ struct print_arg {
 		struct print_arg_hex		hex;
 		struct print_arg_func		func;
 		struct print_arg_string		string;
+		struct print_arg_bitmask	bitmask;
 		struct print_arg_op		op;
 		struct print_arg_dynarray	dynarray;
 	};
diff --git a/tools/perf/util/scripting-engines/trace-event-perl.c b/tools/perf/util/scripting-engines/trace-event-perl.c
index e108207c5de0..af7da565a750 100644
--- a/tools/perf/util/scripting-engines/trace-event-perl.c
+++ b/tools/perf/util/scripting-engines/trace-event-perl.c
@@ -215,6 +215,7 @@ static void define_event_symbols(struct event_format *event,
 	case PRINT_BSTRING:
 	case PRINT_DYNAMIC_ARRAY:
 	case PRINT_STRING:
+	case PRINT_BITMASK:
 		break;
 	case PRINT_TYPE:
 		define_event_symbols(event, ev_name, args->typecast.item);
diff --git a/tools/perf/util/scripting-engines/trace-event-python.c b/tools/perf/util/scripting-engines/trace-event-python.c
index cd9774df3750..c3de0971bfdd 100644
--- a/tools/perf/util/scripting-engines/trace-event-python.c
+++ b/tools/perf/util/scripting-engines/trace-event-python.c
@@ -197,6 +197,7 @@ static void define_event_symbols(struct event_format *event,
 	case PRINT_BSTRING:
 	case PRINT_DYNAMIC_ARRAY:
 	case PRINT_FUNC:
+	case PRINT_BITMASK:
 		/* we should warn... */
 		return;
 	}
-- 
2.0.0.rc2

[tip:perf/core] tools lib traceevent: Added support for __get_bitmask() macro

[tip-bot for Steven Rostedt (Red Hat)]

Commit-ID:  473a778a2f2949972b52ad7fc61577f381f2d05e
Gitweb:     http://git.kernel.org/tip/473a778a2f2949972b52ad7fc61577f381f2d05e
Author:     Steven Rostedt (Red Hat) <rostedt@goodmis.org>
AuthorDate: Mon, 2 Jun 2014 23:20:16 -0400
Committer:  Jiri Olsa <jolsa@kernel.org>
CommitDate: Sat, 7 Jun 2014 23:33:37 +0200

tools lib traceevent: Added support for __get_bitmask() macro

Coming in v3.16, trace events will be able to save bitmasks in raw
format in the ring buffer and output it with the __get_bitmask() macro.

In order for userspace tools to parse this, it must be able to handle
the __get_bitmask() call and be able to convert the data that's in
the ring buffer into a nice bitmask format. The output is similar to
what the kernel uses to print bitmasks, with a comma separator every
4 bytes (8 characters).

This allows for cpumasks to also be saved efficiently.

The first user is the thermal:thermal_power_limit event which has the
following output:

 thermal_power_limit:  cpus=0000000f freq=1900000 cdev_state=0 power=5252

Link: http://lkml.kernel.org/r/20140506132238.22e136d1@gandalf.local.home

Suggested-by: Javi Merino <javi.merino@arm.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Javi Merino <javi.merino@arm.com>
Link: http://lkml.kernel.org/r/20140603032224.229186537@goodmis.org
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
 tools/lib/traceevent/event-parse.c                 | 113 +++++++++++++++++++++
 tools/lib/traceevent/event-parse.h                 |   7 ++
 .../perf/util/scripting-engines/trace-event-perl.c |   1 +
 .../util/scripting-engines/trace-event-python.c    |   1 +
 4 files changed, 122 insertions(+)

diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index b83184f..93825a1 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -765,6 +765,9 @@ static void free_arg(struct print_arg *arg)
 	case PRINT_BSTRING:
 		free(arg->string.string);
 		break;
+	case PRINT_BITMASK:
+		free(arg->bitmask.bitmask);
+		break;
 	case PRINT_DYNAMIC_ARRAY:
 		free(arg->dynarray.index);
 		break;
@@ -2268,6 +2271,7 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		ret = 0;
@@ -2296,6 +2300,7 @@ static char *arg_eval (struct print_arg *arg)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		break;
@@ -2683,6 +2688,35 @@ process_str(struct event_format *event __maybe_unused, struct print_arg *arg,
 	return EVENT_ERROR;
 }
 
+static enum event_type
+process_bitmask(struct event_format *event __maybe_unused, struct print_arg *arg,
+	    char **tok)
+{
+	enum event_type type;
+	char *token;
+
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto out_free;
+
+	arg->type = PRINT_BITMASK;
+	arg->bitmask.bitmask = token;
+	arg->bitmask.offset = -1;
+
+	if (read_expected(EVENT_DELIM, ")") < 0)
+		goto out_err;
+
+	type = read_token(&token);
+	*tok = token;
+
+	return type;
+
+ out_free:
+	free_token(token);
+ out_err:
+	*tok = NULL;
+	return EVENT_ERROR;
+}
+
 static struct pevent_function_handler *
 find_func_handler(struct pevent *pevent, char *func_name)
 {
@@ -2797,6 +2831,10 @@ process_function(struct event_format *event, struct print_arg *arg,
 		free_token(token);
 		return process_str(event, arg, tok);
 	}
+	if (strcmp(token, "__get_bitmask") == 0) {
+		free_token(token);
+		return process_bitmask(event, arg, tok);
+	}
 	if (strcmp(token, "__get_dynamic_array") == 0) {
 		free_token(token);
 		return process_dynamic_array(event, arg, tok);
@@ -3324,6 +3362,7 @@ eval_num_arg(void *data, int size, struct event_format *event, struct print_arg
 		return eval_type(val, arg, 0);
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 		return 0;
 	case PRINT_FUNC: {
 		struct trace_seq s;
@@ -3556,6 +3595,60 @@ static void print_str_to_seq(struct trace_seq *s, const char *format,
 		trace_seq_printf(s, format, str);
 }
 
+static void print_bitmask_to_seq(struct pevent *pevent,
+				 struct trace_seq *s, const char *format,
+				 int len_arg, const void *data, int size)
+{
+	int nr_bits = size * 8;
+	int str_size = (nr_bits + 3) / 4;
+	int len = 0;
+	char buf[3];
+	char *str;
+	int index;
+	int i;
+
+	/*
+	 * The kernel likes to put in commas every 32 bits, we
+	 * can do the same.
+	 */
+	str_size += (nr_bits - 1) / 32;
+
+	str = malloc(str_size + 1);
+	if (!str) {
+		do_warning("%s: not enough memory!", __func__);
+		return;
+	}
+	str[str_size] = 0;
+
+	/* Start out with -2 for the two chars per byte */
+	for (i = str_size - 2; i >= 0; i -= 2) {
+		/*
+		 * data points to a bit mask of size bytes.
+		 * In the kernel, this is an array of long words, thus
+		 * endianess is very important.
+		 */
+		if (pevent->file_bigendian)
+			index = size - (len + 1);
+		else
+			index = len;
+
+		snprintf(buf, 3, "%02x", *((unsigned char *)data + index));
+		memcpy(str + i, buf, 2);
+		len++;
+		if (!(len & 3) && i > 0) {
+			i--;
+			str[i] = ',';
+		}
+	}
+
+	if (len_arg >= 0)
+		trace_seq_printf(s, format, len_arg, str);
+	else
+		trace_seq_printf(s, format, str);
+
+	free(str);
+}
+
 static void print_str_arg(struct trace_seq *s, void *data, int size,
 			  struct event_format *event, const char *format,
 			  int len_arg, struct print_arg *arg)
@@ -3691,6 +3784,23 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 	case PRINT_BSTRING:
 		print_str_to_seq(s, format, len_arg, arg->string.string);
 		break;
+	case PRINT_BITMASK: {
+		int bitmask_offset;
+		int bitmask_size;
+
+		if (arg->bitmask.offset == -1) {
+			struct format_field *f;
+
+			f = pevent_find_any_field(event, arg->bitmask.bitmask);
+			arg->bitmask.offset = f->offset;
+		}
+		bitmask_offset = data2host4(pevent, data + arg->bitmask.offset);
+		bitmask_size = bitmask_offset >> 16;
+		bitmask_offset &= 0xffff;
+		print_bitmask_to_seq(pevent, s, format, len_arg,
+				     data + bitmask_offset, bitmask_size);
+		break;
+	}
 	case PRINT_OP:
 		/*
 		 * The only op for string should be ? :
@@ -4822,6 +4932,9 @@ static void print_args(struct print_arg *args)
 	case PRINT_BSTRING:
 		printf("__get_str(%s)", args->string.string);
 		break;
+	case PRINT_BITMASK:
+		printf("__get_bitmask(%s)", args->bitmask.bitmask);
+		break;
 	case PRINT_TYPE:
 		printf("(%s)", args->typecast.type);
 		print_args(args->typecast.item);
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index 56e0e6c..7a3873f 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -208,6 +208,11 @@ struct print_arg_string {
 	int			offset;
 };
 
+struct print_arg_bitmask {
+	char			*bitmask;
+	int			offset;
+};
+
 struct print_arg_field {
 	char			*name;
 	struct format_field	*field;
@@ -274,6 +279,7 @@ enum print_arg_type {
 	PRINT_DYNAMIC_ARRAY,
 	PRINT_OP,
 	PRINT_FUNC,
+	PRINT_BITMASK,
 };
 
 struct print_arg {
@@ -288,6 +294,7 @@ struct print_arg {
 		struct print_arg_hex		hex;
 		struct print_arg_func		func;
 		struct print_arg_string		string;
+		struct print_arg_bitmask	bitmask;
 		struct print_arg_op		op;
 		struct print_arg_dynarray	dynarray;
 	};
diff --git a/tools/perf/util/scripting-engines/trace-event-perl.c b/tools/perf/util/scripting-engines/trace-event-perl.c
index e108207..af7da56 100644
--- a/tools/perf/util/scripting-engines/trace-event-perl.c
+++ b/tools/perf/util/scripting-engines/trace-event-perl.c
@@ -215,6 +215,7 @@ static void define_event_symbols(struct event_format *event,
 	case PRINT_BSTRING:
 	case PRINT_DYNAMIC_ARRAY:
 	case PRINT_STRING:
+	case PRINT_BITMASK:
 		break;
 	case PRINT_TYPE:
 		define_event_symbols(event, ev_name, args->typecast.item);
diff --git a/tools/perf/util/scripting-engines/trace-event-python.c b/tools/perf/util/scripting-engines/trace-event-python.c
index cd9774d..c3de097 100644
--- a/tools/perf/util/scripting-engines/trace-event-python.c
+++ b/tools/perf/util/scripting-engines/trace-event-python.c
@@ -197,6 +197,7 @@ static void define_event_symbols(struct event_format *event,
 	case PRINT_BSTRING:
 	case PRINT_DYNAMIC_ARRAY:
 	case PRINT_FUNC:
+	case PRINT_BITMASK:
 		/* we should warn... */
 		return;
 	}

[RFC][PATCH] tracing: Add __cpumask() macro to trace events to record cpumasks

[Steven Rostedt]

Being able to show a cpumask of events can be useful as some events
may affect only some CPUs. There is no standard way to record the
cpumask and converting it to a string is rather expensive during
the trace as traces happen in hotpaths. It would be better to record
the raw event mask and be able to parse it at print time.

The following macros were added for use with the TRACE_EVENT() macro:

  __cpumask()
  __assign_cpumask()
  __get_cpumask()

To test this, I added this to the sched_migrate_task event, which
looked like this:

TRACE_EVENT(sched_migrate_task,

	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),

	TP_ARGS(p, dest_cpu, cpus),

	TP_STRUCT__entry(
		__array(	char,	comm,	TASK_COMM_LEN	)
		__field(	pid_t,	pid			)
		__field(	int,	prio			)
		__field(	int,	orig_cpu		)
		__field(	int,	dest_cpu		)
		__cpumask(	cpumask, cpus			)
	),

	TP_fast_assign(
		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
		__entry->pid		= p->pid;
		__entry->prio		= p->prio;
		__entry->orig_cpu	= task_cpu(p);
		__entry->dest_cpu	= dest_cpu;
		__assign_cpumask(cpumask, cpus);
	),

	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
		  __entry->comm, __entry->pid, __entry->prio,
		  __entry->orig_cpu, __entry->dest_cpu,
		  __get_cpumask(cpumask))
);

With the output of:

        ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f
     migration/1-13    [001] d..5   485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f
             awk-3615  [002] d.H5   485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff
     migration/2-18    [002] d..5   485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f

Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com

Suggested-by: Javi Merino <javi.merino@arm.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---

Note, the tools/lib/traceevent will need to be updated to handle the
new __get_cpumask() macro in the TP_printk().

---
 include/linux/ftrace_event.h |  4 ++++
 include/linux/trace_seq.h    | 10 ++++++++
 include/trace/ftrace.h       | 57 +++++++++++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_output.c  | 43 +++++++++++++++++++++++++++++++++
 4 files changed, 113 insertions(+), 1 deletion(-)

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index d16da3e..f68ae9b 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -7,6 +7,7 @@
 #include <linux/percpu.h>
 #include <linux/hardirq.h>
 #include <linux/perf_event.h>
+#include <linux/cpumask.h>
 #include <linux/tracepoint.h>
 
 struct trace_array;
@@ -38,6 +39,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq *p,
 								 *symbol_array);
 #endif
 
+const char *ftrace_print_cpumask_seq(struct trace_seq *p, void *cpumask_ptr,
+				     unsigned int cpumask_size);
+
 const char *ftrace_print_hex_seq(struct trace_seq *p,
 				 const unsigned char *buf, int len);
 
diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
index a32d86e..052b675 100644
--- a/include/linux/trace_seq.h
+++ b/include/linux/trace_seq.h
@@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const void *mem,
 extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
 extern int trace_seq_path(struct trace_seq *s, const struct path *path);
 
+extern int trace_seq_cpumask(struct trace_seq *s, const unsigned long *maskp,
+			     int nmaskbits);
+
 #else /* CONFIG_TRACING */
 static inline int trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 {
@@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt, const u32 *binary)
 	return 0;
 }
 
+static inline int
+trace_seq_cpumask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	return 0;
+}
+
 static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
 {
 	return 0;
diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index 0a1a4f7..ff3c64e 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -53,6 +53,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __cpumask
+#define __cpumask(item, src) __dynamic_array(char, item, -1)
+
 #undef TP_STRUCT__entry
 #define TP_STRUCT__entry(args...) args
 
@@ -128,6 +131,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __string
+#define __string(item, src) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 	struct ftrace_data_offsets_##call {				\
@@ -200,6 +206,15 @@
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_cpumask
+#define __get_cpumask(field)						\
+	({								\
+		void *__cpumask = __get_dynamic_array(field);		\
+		unsigned int __cpumask_size;				\
+		__cpumask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
+		ftrace_print_cpumask_seq(p, __cpumask, __cpumask_size);	\
+	})
+
 #undef __print_flags
 #define __print_flags(flag, delim, flag_array...)			\
 	({								\
@@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __cpumask
+#define __cpumask(item, src) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
 static int notrace __init						\
@@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
 #define __string(item, src) __dynamic_array(char, item,			\
 		    strlen((src) ? (const char *)(src) : "(null)") + 1)
 
+/*
+ * __cpumask_size_in_bytes_raw is the number of bytes needed to hold
+ * num_possible_cpus().
+ */
+#define __cpumask_size_in_bytes_raw			\
+	((num_possible_cpus() + 7) / 8)
+
+#define __cpumask_size_in_longs						\
+	((__cpumask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
+	 / (BITS_PER_LONG / 8))
+
+/*
+ * __cpumask_size_in_bytes is the number of bytes needed to hold
+ * num_possible_cpus() padded out to the nearest long. This is what
+ * is saved in the buffer, just to be consistent.
+ */
+#define __cpumask_size_in_bytes				\
+	(__cpumask_size_in_longs * (BITS_PER_LONG / 8))
+
+#undef __cpumask
+#define __cpumask(item, src) __dynamic_array(unsigned long, item,	\
+					     __cpumask_size_in_longs)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 static inline notrace int ftrace_get_offsets_##call(			\
@@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
 	__entry->__data_loc_##item = __data_offsets.item;
 
 #undef __string
-#define __string(item, src) __dynamic_array(char, item, -1)       	\
+#define __string(item, src) __dynamic_array(char, item, -1)
 
 #undef __assign_str
 #define __assign_str(dst, src)						\
 	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
 
+#undef __cpumask
+#define __cpumask(item, src) __dynamic_array(unsigned long, item, -1)
+
+#undef __get_cpumask
+#define __get_cpumask(field) (char *)__get_dynamic_array(field)
+
+#undef __assign_cpumask
+#define __assign_cpumask(dst, src)					\
+	memcpy(__get_cpumask(dst), (src), __cpumask_size_in_bytes)
+
 #undef TP_fast_assign
 #define TP_fast_assign(args...) args
 
@@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
 #undef __print_hex
 #undef __get_dynamic_array
 #undef __get_str
+#undef __get_cpumask
 
 #undef TP_printk
 #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
@@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_cpumask
+#define __get_cpumask(field) (char *)__get_dynamic_array(field)
+
 #undef __perf_addr
 #define __perf_addr(a)	(__addr = (a))
 
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index a436de1..de43631 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -126,6 +126,36 @@ trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 EXPORT_SYMBOL_GPL(trace_seq_printf);
 
 /**
+ * trace_seq_cpumask - put a list of longs as a cpumask print output
+ * @s:		trace sequence descriptor
+ * @maskp:	points to an array of unsigned longs that represent a cpumask
+ * @nmaskbits:	The number of bits that are valid in @maskp
+ *
+ * It returns 0 if the trace oversizes the buffer's free
+ * space, 1 otherwise.
+ *
+ * Although the name has cpumask, it does not use the cpumask structure,
+ * but instead the internal bitmask structure used by cpumask. This
+ * is used for printing cpumasks in tracepoints.
+ */
+int
+trace_seq_cpumask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	int len = (PAGE_SIZE - 1) - s->len;
+	int ret;
+
+	if (s->full || !len)
+		return 0;
+
+	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
+	s->len += ret;
+
+	return 1;
+}
+EXPORT_SYMBOL_GPL(trace_seq_cpumask);
+
+/**
  * trace_seq_vprintf - sequence printing of trace information
  * @s: trace sequence descriptor
  * @fmt: printf format string
@@ -399,6 +429,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
 #endif
 
 const char *
+ftrace_print_cpumask_seq(struct trace_seq *p, void *cpumask_ptr,
+			 unsigned int cpumask_size)
+{
+	const char *ret = p->buffer + p->len;
+
+	trace_seq_cpumask(p, cpumask_ptr, cpumask_size * 8);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+EXPORT_SYMBOL_GPL(ftrace_print_cpumask_seq);
+
+const char *
 ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len)
 {
 	int i;
-- 
1.8.1.4

Re: [RFC][PATCH] tracing: Add __cpumask() macro to trace events to record cpumasks

[Mathieu Desnoyers]

----- Original Message -----
> From: "Steven Rostedt" <rostedt@goodmis.org>
> To: "LKML" <linux-kernel@vger.kernel.org>
> Cc: "Javi Merino" <javi.merino@arm.com>, "Andrew Morton" <akpm@linux-foundation.org>, "Mathieu Desnoyers"
> <mathieu.desnoyers@efficios.com>, "Ingo Molnar" <mingo@kernel.org>, "Namhyung Kim" <namhyung@kernel.org>, "Jiri
> Olsa" <jolsa@redhat.com>
> Sent: Tuesday, May 6, 2014 1:22:38 PM
> Subject: [RFC][PATCH] tracing: Add __cpumask() macro to trace events to record cpumasks
> 
> 
> Being able to show a cpumask of events can be useful as some events
> may affect only some CPUs. There is no standard way to record the
> cpumask and converting it to a string is rather expensive during
> the trace as traces happen in hotpaths. It would be better to record
> the raw event mask and be able to parse it at print time.

Why name the type cpumask especially ? The type could be a "bitmask",
and the specific field semantic in this case (field name) could
be "cpus", thus implying that this is a cpu mask. This would allow
using bitmasks for other things than cpu masks.

Moreover, I've been thinking about eventually adding a bitmask associated
with an enumeration, so each bit of the bitmask could be associated with
an entry from an enumeration (a string). So having a bitmask type would
be a good step in that direction. For instance, the block layer
instrumentation could use this for the rwbs field, instead of
printing characters with blk_fill_rwbs(). This would save space and
cpu time at trace collection.

Thoughts ?

Thanks,

Mathieu


> 
> The following macros were added for use with the TRACE_EVENT() macro:
> 
>   __cpumask()
>   __assign_cpumask()
>   __get_cpumask()
> 
> To test this, I added this to the sched_migrate_task event, which
> looked like this:
> 
> TRACE_EVENT(sched_migrate_task,
> 
> 	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),
> 
> 	TP_ARGS(p, dest_cpu, cpus),
> 
> 	TP_STRUCT__entry(
> 		__array(	char,	comm,	TASK_COMM_LEN	)
> 		__field(	pid_t,	pid			)
> 		__field(	int,	prio			)
> 		__field(	int,	orig_cpu		)
> 		__field(	int,	dest_cpu		)
> 		__cpumask(	cpumask, cpus			)
> 	),
> 
> 	TP_fast_assign(
> 		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
> 		__entry->pid		= p->pid;
> 		__entry->prio		= p->prio;
> 		__entry->orig_cpu	= task_cpu(p);
> 		__entry->dest_cpu	= dest_cpu;
> 		__assign_cpumask(cpumask, cpus);
> 	),
> 
> 	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
> 		  __entry->comm, __entry->pid, __entry->prio,
> 		  __entry->orig_cpu, __entry->dest_cpu,
> 		  __get_cpumask(cpumask))
> );
> 
> With the output of:
> 
>         ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task:
>         comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2
>         cpumask=00000000,0000000f
>      migration/1-13    [001] d..5   485.221202: sched_migrate_task:
>      comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0
>      cpumask=00000000,0000000f
>              awk-3615  [002] d.H5   485.221747: sched_migrate_task:
>              comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1
>              cpumask=00000000,000000ff
>      migration/2-18    [002] d..5   485.222062: sched_migrate_task:
>      comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3
>      cpumask=00000000,0000000f
> 
> Link:
> http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com
> 
> Suggested-by: Javi Merino <javi.merino@arm.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
> 
> Note, the tools/lib/traceevent will need to be updated to handle the
> new __get_cpumask() macro in the TP_printk().
> 
> ---
>  include/linux/ftrace_event.h |  4 ++++
>  include/linux/trace_seq.h    | 10 ++++++++
>  include/trace/ftrace.h       | 57
>  +++++++++++++++++++++++++++++++++++++++++++-
>  kernel/trace/trace_output.c  | 43 +++++++++++++++++++++++++++++++++
>  4 files changed, 113 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index d16da3e..f68ae9b 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -7,6 +7,7 @@
>  #include <linux/percpu.h>
>  #include <linux/hardirq.h>
>  #include <linux/perf_event.h>
> +#include <linux/cpumask.h>
>  #include <linux/tracepoint.h>
>  
>  struct trace_array;
> @@ -38,6 +39,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq
> *p,
>  								 *symbol_array);
>  #endif
>  
> +const char *ftrace_print_cpumask_seq(struct trace_seq *p, void *cpumask_ptr,
> +				     unsigned int cpumask_size);
> +
>  const char *ftrace_print_hex_seq(struct trace_seq *p,
>  				 const unsigned char *buf, int len);
>  
> diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
> index a32d86e..052b675 100644
> --- a/include/linux/trace_seq.h
> +++ b/include/linux/trace_seq.h
> @@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const
> void *mem,
>  extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
>  extern int trace_seq_path(struct trace_seq *s, const struct path *path);
>  
> +extern int trace_seq_cpumask(struct trace_seq *s, const unsigned long
> *maskp,
> +			     int nmaskbits);
> +
>  #else /* CONFIG_TRACING */
>  static inline int trace_seq_printf(struct trace_seq *s, const char *fmt,
>  ...)
>  {
> @@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt,
> const u32 *binary)
>  	return 0;
>  }
>  
> +static inline int
> +trace_seq_cpumask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	return 0;
> +}
> +
>  static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
>  {
>  	return 0;
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 0a1a4f7..ff3c64e 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -53,6 +53,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __cpumask
> +#define __cpumask(item, src) __dynamic_array(char, item, -1)
> +
>  #undef TP_STRUCT__entry
>  #define TP_STRUCT__entry(args...) args
>  
> @@ -128,6 +131,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __string
> +#define __string(item, src) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  	struct ftrace_data_offsets_##call {				\
> @@ -200,6 +206,15 @@
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_cpumask
> +#define __get_cpumask(field)						\
> +	({								\
> +		void *__cpumask = __get_dynamic_array(field);		\
> +		unsigned int __cpumask_size;				\
> +		__cpumask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> +		ftrace_print_cpumask_seq(p, __cpumask, __cpumask_size);	\
> +	})
> +
>  #undef __print_flags
>  #define __print_flags(flag, delim, flag_array...)			\
>  	({								\
> @@ -322,6 +337,9 @@ static struct trace_event_functions
> ftrace_event_type_funcs_##call = {	\
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __cpumask
> +#define __cpumask(item, src) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
>  static int notrace __init						\
> @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call
> *event_call)	\
>  #define __string(item, src) __dynamic_array(char, item,			\
>  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
>  
> +/*
> + * __cpumask_size_in_bytes_raw is the number of bytes needed to hold
> + * num_possible_cpus().
> + */
> +#define __cpumask_size_in_bytes_raw			\
> +	((num_possible_cpus() + 7) / 8)
> +
> +#define __cpumask_size_in_longs						\
> +	((__cpumask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
> +	 / (BITS_PER_LONG / 8))
> +
> +/*
> + * __cpumask_size_in_bytes is the number of bytes needed to hold
> + * num_possible_cpus() padded out to the nearest long. This is what
> + * is saved in the buffer, just to be consistent.
> + */
> +#define __cpumask_size_in_bytes				\
> +	(__cpumask_size_in_longs * (BITS_PER_LONG / 8))
> +
> +#undef __cpumask
> +#define __cpumask(item, src) __dynamic_array(unsigned long, item,	\
> +					     __cpumask_size_in_longs)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  static inline notrace int ftrace_get_offsets_##call(			\
> @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(
> 			\
>  	__entry->__data_loc_##item = __data_offsets.item;
>  
>  #undef __string
> -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> +#define __string(item, src) __dynamic_array(char, item, -1)
>  
>  #undef __assign_str
>  #define __assign_str(dst, src)						\
>  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
>  
> +#undef __cpumask
> +#define __cpumask(item, src) __dynamic_array(unsigned long, item, -1)
> +
> +#undef __get_cpumask
> +#define __get_cpumask(field) (char *)__get_dynamic_array(field)
> +
> +#undef __assign_cpumask
> +#define __assign_cpumask(dst, src)					\
> +	memcpy(__get_cpumask(dst), (src), __cpumask_size_in_bytes)
> +
>  #undef TP_fast_assign
>  #define TP_fast_assign(args...) args
>  
> @@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
>  #undef __print_hex
>  #undef __get_dynamic_array
>  #undef __get_str
> +#undef __get_cpumask
>  
>  #undef TP_printk
>  #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
> @@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events")))
> *__event_##call = &event_##call
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_cpumask
> +#define __get_cpumask(field) (char *)__get_dynamic_array(field)
> +
>  #undef __perf_addr
>  #define __perf_addr(a)	(__addr = (a))
>  
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index a436de1..de43631 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -126,6 +126,36 @@ trace_seq_printf(struct trace_seq *s, const char *fmt,
> ...)
>  EXPORT_SYMBOL_GPL(trace_seq_printf);
>  
>  /**
> + * trace_seq_cpumask - put a list of longs as a cpumask print output
> + * @s:		trace sequence descriptor
> + * @maskp:	points to an array of unsigned longs that represent a cpumask
> + * @nmaskbits:	The number of bits that are valid in @maskp
> + *
> + * It returns 0 if the trace oversizes the buffer's free
> + * space, 1 otherwise.
> + *
> + * Although the name has cpumask, it does not use the cpumask structure,
> + * but instead the internal bitmask structure used by cpumask. This
> + * is used for printing cpumasks in tracepoints.
> + */
> +int
> +trace_seq_cpumask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	int len = (PAGE_SIZE - 1) - s->len;
> +	int ret;
> +
> +	if (s->full || !len)
> +		return 0;
> +
> +	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
> +	s->len += ret;
> +
> +	return 1;
> +}
> +EXPORT_SYMBOL_GPL(trace_seq_cpumask);
> +
> +/**
>   * trace_seq_vprintf - sequence printing of trace information
>   * @s: trace sequence descriptor
>   * @fmt: printf format string
> @@ -399,6 +429,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
>  #endif
>  
>  const char *
> +ftrace_print_cpumask_seq(struct trace_seq *p, void *cpumask_ptr,
> +			 unsigned int cpumask_size)
> +{
> +	const char *ret = p->buffer + p->len;
> +
> +	trace_seq_cpumask(p, cpumask_ptr, cpumask_size * 8);
> +	trace_seq_putc(p, 0);
> +
> +	return ret;
> +}
> +EXPORT_SYMBOL_GPL(ftrace_print_cpumask_seq);
> +
> +const char *
>  ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int
>  buf_len)
>  {
>  	int i;
> --
> 1.8.1.4
> 
> 

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [RFC][PATCH] tracing: Add __cpumask() macro to trace events to record cpumasks

[Steven Rostedt]

On Tue, 6 May 2014 19:16:34 +0000 (UTC)
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> ----- Original Message -----
> > From: "Steven Rostedt" <rostedt@goodmis.org>
> > To: "LKML" <linux-kernel@vger.kernel.org>
> > Cc: "Javi Merino" <javi.merino@arm.com>, "Andrew Morton" <akpm@linux-foundation.org>, "Mathieu Desnoyers"
> > <mathieu.desnoyers@efficios.com>, "Ingo Molnar" <mingo@kernel.org>, "Namhyung Kim" <namhyung@kernel.org>, "Jiri
> > Olsa" <jolsa@redhat.com>
> > Sent: Tuesday, May 6, 2014 1:22:38 PM
> > Subject: [RFC][PATCH] tracing: Add __cpumask() macro to trace events to record cpumasks
> > 
> > 
> > Being able to show a cpumask of events can be useful as some events
> > may affect only some CPUs. There is no standard way to record the
> > cpumask and converting it to a string is rather expensive during
> > the trace as traces happen in hotpaths. It would be better to record
> > the raw event mask and be able to parse it at print time.
> 
> Why name the type cpumask especially ? The type could be a "bitmask",
> and the specific field semantic in this case (field name) could
> be "cpus", thus implying that this is a cpu mask. This would allow
> using bitmasks for other things than cpu masks.

Hmm, sure, perhaps it would be better to call it bitmask instead. It
basically is already.

> 
> Moreover, I've been thinking about eventually adding a bitmask associated
> with an enumeration, so each bit of the bitmask could be associated with
> an entry from an enumeration (a string). So having a bitmask type would
> be a good step in that direction. For instance, the block layer
> instrumentation could use this for the rwbs field, instead of
> printing characters with blk_fill_rwbs(). This would save space and
> cpu time at trace collection.

Perhaps.

-- Steve

[RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

Being able to show a cpumask of events can be useful as some events
may affect only some CPUs. There is no standard way to record the
cpumask and converting it to a string is rather expensive during
the trace as traces happen in hotpaths. It would be better to record
the raw event mask and be able to parse it at print time.

The following macros were added for use with the TRACE_EVENT() macro:

  __bitmask()
  __assign_bitmask()
  __get_bitmask()

To test this, I added this to the sched_migrate_task event, which
looked like this:

TRACE_EVENT(sched_migrate_task,

	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),

	TP_ARGS(p, dest_cpu, cpus),

	TP_STRUCT__entry(
		__array(	char,	comm,	TASK_COMM_LEN	)
		__field(	pid_t,	pid			)
		__field(	int,	prio			)
		__field(	int,	orig_cpu		)
		__field(	int,	dest_cpu		)
		__bitmask(	cpumask, cpus			)
	),

	TP_fast_assign(
		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
		__entry->pid		= p->pid;
		__entry->prio		= p->prio;
		__entry->orig_cpu	= task_cpu(p);
		__entry->dest_cpu	= dest_cpu;
		__assign_bitmask(cpumask, cpumask_bits(cpus));
	),

	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
		  __entry->comm, __entry->pid, __entry->prio,
		  __entry->orig_cpu, __entry->dest_cpu,
		  __get_bitmask(cpumask))
);

With the output of:

        ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f
     migration/1-13    [001] d..5   485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f
             awk-3615  [002] d.H5   485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff
     migration/2-18    [002] d..5   485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f

Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com

Suggested-by: Javi Merino <javi.merino@arm.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---

Changes since v1: Use bitmask name instead of cpumask naming.

---
 include/linux/ftrace_event.h |  3 +++
 include/linux/trace_seq.h    | 10 ++++++++
 include/trace/ftrace.h       | 57 +++++++++++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_output.c  | 41 +++++++++++++++++++++++++++++++
 4 files changed, 110 insertions(+), 1 deletion(-)

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index d16da3e..cff3106 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -38,6 +38,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq *p,
 								 *symbol_array);
 #endif
 
+const char *ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
+				     unsigned int bitmask_size);
+
 const char *ftrace_print_hex_seq(struct trace_seq *p,
 				 const unsigned char *buf, int len);
 
diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
index a32d86e..1361169 100644
--- a/include/linux/trace_seq.h
+++ b/include/linux/trace_seq.h
@@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const void *mem,
 extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
 extern int trace_seq_path(struct trace_seq *s, const struct path *path);
 
+extern int trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+			     int nmaskbits);
+
 #else /* CONFIG_TRACING */
 static inline int trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 {
@@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt, const u32 *binary)
 	return 0;
 }
 
+static inline int
+trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	return 0;
+}
+
 static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
 {
 	return 0;
diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index 0a1a4f7..d9c44af 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -53,6 +53,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __bitmask
+#define __bitmask(item, src) __dynamic_array(char, item, -1)
+
 #undef TP_STRUCT__entry
 #define TP_STRUCT__entry(args...) args
 
@@ -128,6 +131,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __string
+#define __string(item, src) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 	struct ftrace_data_offsets_##call {				\
@@ -200,6 +206,15 @@
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_bitmask
+#define __get_bitmask(field)						\
+	({								\
+		void *__bitmask = __get_dynamic_array(field);		\
+		unsigned int __bitmask_size;				\
+		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
+		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
+	})
+
 #undef __print_flags
 #define __print_flags(flag, delim, flag_array...)			\
 	({								\
@@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __bitmask
+#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
 static int notrace __init						\
@@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
 #define __string(item, src) __dynamic_array(char, item,			\
 		    strlen((src) ? (const char *)(src) : "(null)") + 1)
 
+/*
+ * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
+ * num_possible_cpus().
+ */
+#define __bitmask_size_in_bytes_raw			\
+	((num_possible_cpus() + 7) / 8)
+
+#define __bitmask_size_in_longs						\
+	((__bitmask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
+	 / (BITS_PER_LONG / 8))
+
+/*
+ * __bitmask_size_in_bytes is the number of bytes needed to hold
+ * num_possible_cpus() padded out to the nearest long. This is what
+ * is saved in the buffer, just to be consistent.
+ */
+#define __bitmask_size_in_bytes				\
+	(__bitmask_size_in_longs * (BITS_PER_LONG / 8))
+
+#undef __bitmask
+#define __bitmask(item, src) __dynamic_array(unsigned long, item,	\
+					     __bitmask_size_in_longs)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 static inline notrace int ftrace_get_offsets_##call(			\
@@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
 	__entry->__data_loc_##item = __data_offsets.item;
 
 #undef __string
-#define __string(item, src) __dynamic_array(char, item, -1)       	\
+#define __string(item, src) __dynamic_array(char, item, -1)
 
 #undef __assign_str
 #define __assign_str(dst, src)						\
 	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
 
+#undef __bitmask
+#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
+
+#undef __get_bitmask
+#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+
+#undef __assign_bitmask
+#define __assign_bitmask(dst, src)					\
+	memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes)
+
 #undef TP_fast_assign
 #define TP_fast_assign(args...) args
 
@@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
 #undef __print_hex
 #undef __get_dynamic_array
 #undef __get_str
+#undef __get_bitmask
 
 #undef TP_printk
 #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
@@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_bitmask
+#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+
 #undef __perf_addr
 #define __perf_addr(a)	(__addr = (a))
 
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index a436de1..f3dad80 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -126,6 +126,34 @@ trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 EXPORT_SYMBOL_GPL(trace_seq_printf);
 
 /**
+ * trace_seq_bitmask - put a list of longs as a bitmask print output
+ * @s:		trace sequence descriptor
+ * @maskp:	points to an array of unsigned longs that represent a bitmask
+ * @nmaskbits:	The number of bits that are valid in @maskp
+ *
+ * It returns 0 if the trace oversizes the buffer's free
+ * space, 1 otherwise.
+ *
+ * Writes a ASCII representation of a bitmask string into @s.
+ */
+int
+trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	int len = (PAGE_SIZE - 1) - s->len;
+	int ret;
+
+	if (s->full || !len)
+		return 0;
+
+	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
+	s->len += ret;
+
+	return 1;
+}
+EXPORT_SYMBOL_GPL(trace_seq_bitmask);
+
+/**
  * trace_seq_vprintf - sequence printing of trace information
  * @s: trace sequence descriptor
  * @fmt: printf format string
@@ -399,6 +427,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
 #endif
 
 const char *
+ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
+			 unsigned int bitmask_size)
+{
+	const char *ret = p->buffer + p->len;
+
+	trace_seq_bitmask(p, bitmask_ptr, bitmask_size * 8);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+EXPORT_SYMBOL_GPL(ftrace_print_bitmask_seq);
+
+const char *
 ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len)
 {
 	int i;
-- 
1.8.1.4

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Mathieu Desnoyers]

----- Original Message -----
> From: "Steven Rostedt" <rostedt@goodmis.org>
> To: "LKML" <linux-kernel@vger.kernel.org>
> Cc: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>, "Javi Merino" <javi.merino@arm.com>, "Andrew Morton"
> <akpm@linux-foundation.org>, "Ingo Molnar" <mingo@kernel.org>, "Namhyung Kim" <namhyung@kernel.org>, "Jiri Olsa"
> <jolsa@redhat.com>
> Sent: Tuesday, May 6, 2014 11:12:38 PM
> Subject: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks
> 
> 
> Being able to show a cpumask of events can be useful as some events
> may affect only some CPUs. There is no standard way to record the
> cpumask and converting it to a string is rather expensive during
> the trace as traces happen in hotpaths. It would be better to record
> the raw event mask and be able to parse it at print time.

Hi Steven,

OK. Changing cpumask into bitmask helps making this more generic. Now
I'm concerned about another topic: the type backing the bitmask, as well
as its endianness, have an important impact when storing and reading
the trace on different machines. This is not a problem cpumask typically
has, because the test_bit() and set bit APIs are always used from within
the kernel.

Looking at:

/**
 * test_bit - Determine whether a bit is set
 * @nr: bit number to test
 * @addr: Address to start counting from
 */
static inline int test_bit(int nr, const volatile unsigned long *addr)
{
        return 1UL & (addr[BIT_WORD(nr)] >> (nr & (BITS_PER_LONG-1)));
}

We notice that the kernel's bit operations use an unsigned long
as "backing type" for the bitfield, with a native kernel endianness.

Therefore, the trace reader needs to take into account those two
informations (backing type size, and endianness) in order to get the
bit order right.

I remember that you made sure Ftrace's event description files expose
the endianness of the kernel, which partially takes care of this
concern, but how do you plan exposing the bitmask backing type size ?
(unsigned long maps to 32-bit or 64-bit depending on the architecture).

Thanks,

Mathieu

> 
> The following macros were added for use with the TRACE_EVENT() macro:
> 
>   __bitmask()
>   __assign_bitmask()
>   __get_bitmask()
> 
> To test this, I added this to the sched_migrate_task event, which
> looked like this:
> 
> TRACE_EVENT(sched_migrate_task,
> 
> 	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),
> 
> 	TP_ARGS(p, dest_cpu, cpus),
> 
> 	TP_STRUCT__entry(
> 		__array(	char,	comm,	TASK_COMM_LEN	)
> 		__field(	pid_t,	pid			)
> 		__field(	int,	prio			)
> 		__field(	int,	orig_cpu		)
> 		__field(	int,	dest_cpu		)
> 		__bitmask(	cpumask, cpus			)
> 	),
> 
> 	TP_fast_assign(
> 		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
> 		__entry->pid		= p->pid;
> 		__entry->prio		= p->prio;
> 		__entry->orig_cpu	= task_cpu(p);
> 		__entry->dest_cpu	= dest_cpu;
> 		__assign_bitmask(cpumask, cpumask_bits(cpus));
> 	),
> 
> 	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
> 		  __entry->comm, __entry->pid, __entry->prio,
> 		  __entry->orig_cpu, __entry->dest_cpu,
> 		  __get_bitmask(cpumask))
> );
> 
> With the output of:
> 
>         ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task:
>         comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2
>         cpumask=00000000,0000000f
>      migration/1-13    [001] d..5   485.221202: sched_migrate_task:
>      comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0
>      cpumask=00000000,0000000f
>              awk-3615  [002] d.H5   485.221747: sched_migrate_task:
>              comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1
>              cpumask=00000000,000000ff
>      migration/2-18    [002] d..5   485.222062: sched_migrate_task:
>      comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3
>      cpumask=00000000,0000000f
> 
> Link:
> http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com
> 
> Suggested-by: Javi Merino <javi.merino@arm.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
> 
> Changes since v1: Use bitmask name instead of cpumask naming.
> 
> ---
>  include/linux/ftrace_event.h |  3 +++
>  include/linux/trace_seq.h    | 10 ++++++++
>  include/trace/ftrace.h       | 57
>  +++++++++++++++++++++++++++++++++++++++++++-
>  kernel/trace/trace_output.c  | 41 +++++++++++++++++++++++++++++++
>  4 files changed, 110 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index d16da3e..cff3106 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -38,6 +38,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq
> *p,
>  								 *symbol_array);
>  #endif
>  
> +const char *ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
> +				     unsigned int bitmask_size);
> +
>  const char *ftrace_print_hex_seq(struct trace_seq *p,
>  				 const unsigned char *buf, int len);
>  
> diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
> index a32d86e..1361169 100644
> --- a/include/linux/trace_seq.h
> +++ b/include/linux/trace_seq.h
> @@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const
> void *mem,
>  extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
>  extern int trace_seq_path(struct trace_seq *s, const struct path *path);
>  
> +extern int trace_seq_bitmask(struct trace_seq *s, const unsigned long
> *maskp,
> +			     int nmaskbits);
> +
>  #else /* CONFIG_TRACING */
>  static inline int trace_seq_printf(struct trace_seq *s, const char *fmt,
>  ...)
>  {
> @@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt,
> const u32 *binary)
>  	return 0;
>  }
>  
> +static inline int
> +trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	return 0;
> +}
> +
>  static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
>  {
>  	return 0;
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 0a1a4f7..d9c44af 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -53,6 +53,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(char, item, -1)
> +
>  #undef TP_STRUCT__entry
>  #define TP_STRUCT__entry(args...) args
>  
> @@ -128,6 +131,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __string
> +#define __string(item, src) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  	struct ftrace_data_offsets_##call {				\
> @@ -200,6 +206,15 @@
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_bitmask
> +#define __get_bitmask(field)						\
> +	({								\
> +		void *__bitmask = __get_dynamic_array(field);		\
> +		unsigned int __bitmask_size;				\
> +		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> +		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
> +	})
> +
>  #undef __print_flags
>  #define __print_flags(flag, delim, flag_array...)			\
>  	({								\
> @@ -322,6 +337,9 @@ static struct trace_event_functions
> ftrace_event_type_funcs_##call = {	\
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
>  static int notrace __init						\
> @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call
> *event_call)	\
>  #define __string(item, src) __dynamic_array(char, item,			\
>  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
>  
> +/*
> + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
> + * num_possible_cpus().
> + */
> +#define __bitmask_size_in_bytes_raw			\
> +	((num_possible_cpus() + 7) / 8)
> +
> +#define __bitmask_size_in_longs						\
> +	((__bitmask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
> +	 / (BITS_PER_LONG / 8))
> +
> +/*
> + * __bitmask_size_in_bytes is the number of bytes needed to hold
> + * num_possible_cpus() padded out to the nearest long. This is what
> + * is saved in the buffer, just to be consistent.
> + */
> +#define __bitmask_size_in_bytes				\
> +	(__bitmask_size_in_longs * (BITS_PER_LONG / 8))
> +
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item,	\
> +					     __bitmask_size_in_longs)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  static inline notrace int ftrace_get_offsets_##call(			\
> @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(
> 			\
>  	__entry->__data_loc_##item = __data_offsets.item;
>  
>  #undef __string
> -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> +#define __string(item, src) __dynamic_array(char, item, -1)
>  
>  #undef __assign_str
>  #define __assign_str(dst, src)						\
>  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> +
> +#undef __get_bitmask
> +#define __get_bitmask(field) (char *)__get_dynamic_array(field)
> +
> +#undef __assign_bitmask
> +#define __assign_bitmask(dst, src)					\
> +	memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes)
> +
>  #undef TP_fast_assign
>  #define TP_fast_assign(args...) args
>  
> @@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
>  #undef __print_hex
>  #undef __get_dynamic_array
>  #undef __get_str
> +#undef __get_bitmask
>  
>  #undef TP_printk
>  #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
> @@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events")))
> *__event_##call = &event_##call
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_bitmask
> +#define __get_bitmask(field) (char *)__get_dynamic_array(field)
> +
>  #undef __perf_addr
>  #define __perf_addr(a)	(__addr = (a))
>  
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index a436de1..f3dad80 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -126,6 +126,34 @@ trace_seq_printf(struct trace_seq *s, const char *fmt,
> ...)
>  EXPORT_SYMBOL_GPL(trace_seq_printf);
>  
>  /**
> + * trace_seq_bitmask - put a list of longs as a bitmask print output
> + * @s:		trace sequence descriptor
> + * @maskp:	points to an array of unsigned longs that represent a bitmask
> + * @nmaskbits:	The number of bits that are valid in @maskp
> + *
> + * It returns 0 if the trace oversizes the buffer's free
> + * space, 1 otherwise.
> + *
> + * Writes a ASCII representation of a bitmask string into @s.
> + */
> +int
> +trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	int len = (PAGE_SIZE - 1) - s->len;
> +	int ret;
> +
> +	if (s->full || !len)
> +		return 0;
> +
> +	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
> +	s->len += ret;
> +
> +	return 1;
> +}
> +EXPORT_SYMBOL_GPL(trace_seq_bitmask);
> +
> +/**
>   * trace_seq_vprintf - sequence printing of trace information
>   * @s: trace sequence descriptor
>   * @fmt: printf format string
> @@ -399,6 +427,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
>  #endif
>  
>  const char *
> +ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
> +			 unsigned int bitmask_size)
> +{
> +	const char *ret = p->buffer + p->len;
> +
> +	trace_seq_bitmask(p, bitmask_ptr, bitmask_size * 8);
> +	trace_seq_putc(p, 0);
> +
> +	return ret;
> +}
> +EXPORT_SYMBOL_GPL(ftrace_print_bitmask_seq);
> +
> +const char *
>  ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int
>  buf_len)
>  {
>  	int i;
> --
> 1.8.1.4
> 
> 
> 
> 

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

On Wed, 7 May 2014 11:40:21 +0000 (UTC)
Mathieu Desnoyers <mathieu.desnoyers@efficios.com> wrote:

> ----- Original Message -----
> > From: "Steven Rostedt" <rostedt@goodmis.org>
> > To: "LKML" <linux-kernel@vger.kernel.org>
> > Cc: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>, "Javi Merino" <javi.merino@arm.com>, "Andrew Morton"
> > <akpm@linux-foundation.org>, "Ingo Molnar" <mingo@kernel.org>, "Namhyung Kim" <namhyung@kernel.org>, "Jiri Olsa"
> > <jolsa@redhat.com>
> > Sent: Tuesday, May 6, 2014 11:12:38 PM
> > Subject: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks
> > 
> > 
> > Being able to show a cpumask of events can be useful as some events
> > may affect only some CPUs. There is no standard way to record the
> > cpumask and converting it to a string is rather expensive during
> > the trace as traces happen in hotpaths. It would be better to record
> > the raw event mask and be able to parse it at print time.
> 
> Hi Steven,
> 
> OK. Changing cpumask into bitmask helps making this more generic. Now
> I'm concerned about another topic: the type backing the bitmask, as well
> as its endianness, have an important impact when storing and reading
> the trace on different machines. This is not a problem cpumask typically
> has, because the test_bit() and set bit APIs are always used from within
> the kernel.
> 
> Looking at:
> 
> /**
>  * test_bit - Determine whether a bit is set
>  * @nr: bit number to test
>  * @addr: Address to start counting from
>  */
> static inline int test_bit(int nr, const volatile unsigned long *addr)
> {
>         return 1UL & (addr[BIT_WORD(nr)] >> (nr & (BITS_PER_LONG-1)));
> }
> 
> We notice that the kernel's bit operations use an unsigned long
> as "backing type" for the bitfield, with a native kernel endianness.
> 
> Therefore, the trace reader needs to take into account those two
> informations (backing type size, and endianness) in order to get the
> bit order right.
> 
> I remember that you made sure Ftrace's event description files expose
> the endianness of the kernel, which partially takes care of this
> concern, but how do you plan exposing the bitmask backing type size ?
> (unsigned long maps to 32-bit or 64-bit depending on the architecture).

Well, actually, the files don't expose endianess, but that is done by
the userspace tracer running on the machine. I'm not sure of any
machine that would have userspace and kernel space endianess different.

But the 32-bit vs 64-bit is exposed. Not really directly, but the way
traceevent finds this out is with pevent->header_page_size_size. That
is, in /debug/tracing/events/header_page the field "commit" is of size
long in the kernel. It's 8 for 64bit and 4 for 32bit.

This works even if userspace is 32 and kernel is 64.

With both endian and long size, it should be trivial for the reader to
be able to parse the cpumask on any machine.

-- Steve

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Javi Merino]

Hi Steven,

On Wed, May 07, 2014 at 04:12:38AM +0100, Steven Rostedt wrote:
> 
> Being able to show a cpumask of events can be useful as some events
> may affect only some CPUs. There is no standard way to record the
> cpumask and converting it to a string is rather expensive during
> the trace as traces happen in hotpaths. It would be better to record
> the raw event mask and be able to parse it at print time.
> 
> The following macros were added for use with the TRACE_EVENT() macro:
> 
>   __bitmask()
>   __assign_bitmask()
>   __get_bitmask()
> 
> To test this, I added this to the sched_migrate_task event, which
> looked like this:
> 
> TRACE_EVENT(sched_migrate_task,
> 
> 	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),
> 
> 	TP_ARGS(p, dest_cpu, cpus),
> 
> 	TP_STRUCT__entry(
> 		__array(	char,	comm,	TASK_COMM_LEN	)
> 		__field(	pid_t,	pid			)
> 		__field(	int,	prio			)
> 		__field(	int,	orig_cpu		)
> 		__field(	int,	dest_cpu		)
> 		__bitmask(	cpumask, cpus			)
> 	),
> 
> 	TP_fast_assign(
> 		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
> 		__entry->pid		= p->pid;
> 		__entry->prio		= p->prio;
> 		__entry->orig_cpu	= task_cpu(p);
> 		__entry->dest_cpu	= dest_cpu;
> 		__assign_bitmask(cpumask, cpumask_bits(cpus));
> 	),
> 
> 	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
> 		  __entry->comm, __entry->pid, __entry->prio,
> 		  __entry->orig_cpu, __entry->dest_cpu,
> 		  __get_bitmask(cpumask))
> );
> 
> With the output of:
> 
>         ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f
>      migration/1-13    [001] d..5   485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f
>              awk-3615  [002] d.H5   485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff
>      migration/2-18    [002] d..5   485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f
> 
> Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com
> 
> Suggested-by: Javi Merino <javi.merino@arm.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
> 
> Changes since v1: Use bitmask name instead of cpumask naming.
> 
> ---
>  include/linux/ftrace_event.h |  3 +++
>  include/linux/trace_seq.h    | 10 ++++++++
>  include/trace/ftrace.h       | 57 +++++++++++++++++++++++++++++++++++++++++++-
>  kernel/trace/trace_output.c  | 41 +++++++++++++++++++++++++++++++
>  4 files changed, 110 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index d16da3e..cff3106 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -38,6 +38,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq *p,
>  								 *symbol_array);
>  #endif
>  
> +const char *ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
> +				     unsigned int bitmask_size);
> +
>  const char *ftrace_print_hex_seq(struct trace_seq *p,
>  				 const unsigned char *buf, int len);
>  
> diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
> index a32d86e..1361169 100644
> --- a/include/linux/trace_seq.h
> +++ b/include/linux/trace_seq.h
> @@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const void *mem,
>  extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
>  extern int trace_seq_path(struct trace_seq *s, const struct path *path);
>  
> +extern int trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +			     int nmaskbits);
> +
>  #else /* CONFIG_TRACING */
>  static inline int trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
>  {
> @@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt, const u32 *binary)
>  	return 0;
>  }
>  
> +static inline int
> +trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	return 0;
> +}
> +
>  static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
>  {
>  	return 0;
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 0a1a4f7..d9c44af 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -53,6 +53,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(char, item, -1)
> +
>  #undef TP_STRUCT__entry
>  #define TP_STRUCT__entry(args...) args
>  
> @@ -128,6 +131,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __string
> +#define __string(item, src) __dynamic_array(unsigned long, item, -1)
> +

This overrides the previous definition of __string() and looks like it
shouldn't be here.

>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  	struct ftrace_data_offsets_##call {				\
> @@ -200,6 +206,15 @@
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_bitmask
> +#define __get_bitmask(field)						\
> +	({								\
> +		void *__bitmask = __get_dynamic_array(field);		\
> +		unsigned int __bitmask_size;				\
> +		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> +		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
> +	})
> +
>  #undef __print_flags
>  #define __print_flags(flag, delim, flag_array...)			\
>  	({								\
> @@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> +
>
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
>  static int notrace __init						\
> @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
>  #define __string(item, src) __dynamic_array(char, item,			\
>  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
>  
> +/*
> + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
> + * num_possible_cpus().
> + */
> +#define __bitmask_size_in_bytes_raw			\
> +	((num_possible_cpus() + 7) / 8)
> +
> +#define __bitmask_size_in_longs						\
> +	((__bitmask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
> +	 / (BITS_PER_LONG / 8))
> +
> +/*
> + * __bitmask_size_in_bytes is the number of bytes needed to hold
> + * num_possible_cpus() padded out to the nearest long. This is what
> + * is saved in the buffer, just to be consistent.
> + */
> +#define __bitmask_size_in_bytes				\
> +	(__bitmask_size_in_longs * (BITS_PER_LONG / 8))
> +
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item,	\
> +					     __bitmask_size_in_longs)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  static inline notrace int ftrace_get_offsets_##call(			\
> @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
>  	__entry->__data_loc_##item = __data_offsets.item;
>  
>  #undef __string
> -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> +#define __string(item, src) __dynamic_array(char, item, -1)
>  
>  #undef __assign_str
>  #define __assign_str(dst, src)						\
>  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
>  
> +#undef __bitmask
> +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)

Why src?  It's not used in any of the definitions of the __bitmask()
macro, can we remove it?

Cheers,
Javi

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

On Wed, 14 May 2014 15:23:24 +0100
Javi Merino <javi.merino@arm.com> wrote:

> > diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> > index 0a1a4f7..d9c44af 100644
> > --- a/include/trace/ftrace.h
> > +++ b/include/trace/ftrace.h
> > @@ -53,6 +53,9 @@
> >  #undef __string
> >  #define __string(item, src) __dynamic_array(char, item, -1)
> >  
> > +#undef __bitmask
> > +#define __bitmask(item, src) __dynamic_array(char, item, -1)
> > +
> >  #undef TP_STRUCT__entry
> >  #define TP_STRUCT__entry(args...) args
> >  
> > @@ -128,6 +131,9 @@
> >  #undef __string
> >  #define __string(item, src) __dynamic_array(char, item, -1)
> >  
> > +#undef __string
> > +#define __string(item, src) __dynamic_array(unsigned long, item, -1)
> > +
> 
> This overrides the previous definition of __string() and looks like it
> shouldn't be here.

Bah! I knew there was a reason I didn't push this out to my for-next
branch yet. I can still rebase :-)

That should have been __bitmask(). Hmm, amazing it still worked.

> 
> >  #undef DECLARE_EVENT_CLASS
> >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
> >  	struct ftrace_data_offsets_##call {				\
> > @@ -200,6 +206,15 @@
> >  #undef __get_str
> >  #define __get_str(field) (char *)__get_dynamic_array(field)
> >  
> > +#undef __get_bitmask
> > +#define __get_bitmask(field)						\
> > +	({								\
> > +		void *__bitmask = __get_dynamic_array(field);		\
> > +		unsigned int __bitmask_size;				\
> > +		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> > +		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
> > +	})
> > +
> >  #undef __print_flags
> >  #define __print_flags(flag, delim, flag_array...)			\
> >  	({								\
> > @@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
> >  #undef __string
> >  #define __string(item, src) __dynamic_array(char, item, -1)
> >  
> > +#undef __bitmask
> > +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> > +
> >
> >  #undef DECLARE_EVENT_CLASS
> >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
> >  static int notrace __init						\
> > @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
> >  #define __string(item, src) __dynamic_array(char, item,			\
> >  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
> >  
> > +/*
> > + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
> > + * num_possible_cpus().
> > + */
> > +#define __bitmask_size_in_bytes_raw			\
> > +	((num_possible_cpus() + 7) / 8)
> > +
> > +#define __bitmask_size_in_longs						\
> > +	((__bitmask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
> > +	 / (BITS_PER_LONG / 8))
> > +
> > +/*
> > + * __bitmask_size_in_bytes is the number of bytes needed to hold
> > + * num_possible_cpus() padded out to the nearest long. This is what
> > + * is saved in the buffer, just to be consistent.
> > + */
> > +#define __bitmask_size_in_bytes				\
> > +	(__bitmask_size_in_longs * (BITS_PER_LONG / 8))
> > +
> > +#undef __bitmask
> > +#define __bitmask(item, src) __dynamic_array(unsigned long, item,	\
> > +					     __bitmask_size_in_longs)
> > +
> >  #undef DECLARE_EVENT_CLASS
> >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
> >  static inline notrace int ftrace_get_offsets_##call(			\
> > @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
> >  	__entry->__data_loc_##item = __data_offsets.item;
> >  
> >  #undef __string
> > -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> > +#define __string(item, src) __dynamic_array(char, item, -1)
> >  
> >  #undef __assign_str
> >  #define __assign_str(dst, src)						\
> >  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
> >  
> > +#undef __bitmask
> > +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> 
> Why src?  It's not used in any of the definitions of the __bitmask()
> macro, can we remove it?

Hmm, I may need to refactor this. I may pull this patch for now to push
the rest to for-next.

I just noticed that we need a way to specify the length of the bitmask.
Right now it's hardcoded as "num_possible_cpus", which Mathieu was
asking for a more generic approach.

OK, let me pull this patch out of my tree (thank god I never pushed
it), and work on it a bit more.

Thanks,

-- Steve

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Javi Merino]

On Wed, May 14, 2014 at 04:36:23PM +0100, Steven Rostedt wrote:
> On Wed, 14 May 2014 15:23:24 +0100
> Javi Merino <javi.merino@arm.com> wrote:
> 
> > > diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> > > index 0a1a4f7..d9c44af 100644
> > > --- a/include/trace/ftrace.h
> > > +++ b/include/trace/ftrace.h
> > > @@ -53,6 +53,9 @@
> > >  #undef __string
> > >  #define __string(item, src) __dynamic_array(char, item, -1)
> > >  
> > > +#undef __bitmask
> > > +#define __bitmask(item, src) __dynamic_array(char, item, -1)
> > > +
> > >  #undef TP_STRUCT__entry
> > >  #define TP_STRUCT__entry(args...) args
> > >  
> > > @@ -128,6 +131,9 @@
> > >  #undef __string
> > >  #define __string(item, src) __dynamic_array(char, item, -1)
> > >  
> > > +#undef __string
> > > +#define __string(item, src) __dynamic_array(unsigned long, item, -1)
> > > +
> > 
> > This overrides the previous definition of __string() and looks like it
> > shouldn't be here.
> 
> Bah! I knew there was a reason I didn't push this out to my for-next
> branch yet. I can still rebase :-)
> 
> That should have been __bitmask(). Hmm, amazing it still worked.
> 
> > 
> > >  #undef DECLARE_EVENT_CLASS
> > >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
> > >  	struct ftrace_data_offsets_##call {				\
> > > @@ -200,6 +206,15 @@
> > >  #undef __get_str
> > >  #define __get_str(field) (char *)__get_dynamic_array(field)
> > >  
> > > +#undef __get_bitmask
> > > +#define __get_bitmask(field)						\
> > > +	({								\
> > > +		void *__bitmask = __get_dynamic_array(field);		\
> > > +		unsigned int __bitmask_size;				\
> > > +		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> > > +		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
> > > +	})
> > > +
> > >  #undef __print_flags
> > >  #define __print_flags(flag, delim, flag_array...)			\
> > >  	({								\
> > > @@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
> > >  #undef __string
> > >  #define __string(item, src) __dynamic_array(char, item, -1)
> > >  
> > > +#undef __bitmask
> > > +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> > > +
> > >
> > >  #undef DECLARE_EVENT_CLASS
> > >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
> > >  static int notrace __init						\
> > > @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
> > >  #define __string(item, src) __dynamic_array(char, item,			\
> > >  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
> > >  
> > > +/*
> > > + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
> > > + * num_possible_cpus().
> > > + */
> > > +#define __bitmask_size_in_bytes_raw			\
> > > +	((num_possible_cpus() + 7) / 8)
> > > +
> > > +#define __bitmask_size_in_longs						\
> > > +	((__bitmask_size_in_bytes_raw + ((BITS_PER_LONG / 8) - 1))	\
> > > +	 / (BITS_PER_LONG / 8))
> > > +
> > > +/*
> > > + * __bitmask_size_in_bytes is the number of bytes needed to hold
> > > + * num_possible_cpus() padded out to the nearest long. This is what
> > > + * is saved in the buffer, just to be consistent.
> > > + */
> > > +#define __bitmask_size_in_bytes				\
> > > +	(__bitmask_size_in_longs * (BITS_PER_LONG / 8))
> > > +
> > > +#undef __bitmask
> > > +#define __bitmask(item, src) __dynamic_array(unsigned long, item,	\
> > > +					     __bitmask_size_in_longs)
> > > +
> > >  #undef DECLARE_EVENT_CLASS
> > >  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
> > >  static inline notrace int ftrace_get_offsets_##call(			\
> > > @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
> > >  	__entry->__data_loc_##item = __data_offsets.item;
> > >  
> > >  #undef __string
> > > -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> > > +#define __string(item, src) __dynamic_array(char, item, -1)
> > >  
> > >  #undef __assign_str
> > >  #define __assign_str(dst, src)						\
> > >  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
> > >  
> > > +#undef __bitmask
> > > +#define __bitmask(item, src) __dynamic_array(unsigned long, item, -1)
> > 
> > Why src?  It's not used in any of the definitions of the __bitmask()
> > macro, can we remove it?
> 
> Hmm, I may need to refactor this. I may pull this patch for now to push
> the rest to for-next.
> 
> I just noticed that we need a way to specify the length of the bitmask.
> Right now it's hardcoded as "num_possible_cpus", which Mathieu was
> asking for a more generic approach.
> 
> OK, let me pull this patch out of my tree (thank god I never pushed
> it), and work on it a bit more.

Ok, well keep me posted on this, I've tried to use it but trace-cmd
says "[FAILED TO PARSE]" and I'm still trying to figure out if it's me
not using it properly or some bug in the code.

Cheers,
Javi

Re: [RFC][PATCH v2] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

On Wed, 14 May 2014 16:50:53 +0100
Javi Merino <javi.merino@arm.com> wrote:


> > OK, let me pull this patch out of my tree (thank god I never pushed
> > it), and work on it a bit more.
> 
> Ok, well keep me posted on this, I've tried to use it but trace-cmd
> says "[FAILED TO PARSE]" and I'm still trying to figure out if it's me
> not using it properly or some bug in the code.

Oh, it's going to require a trace-cmd patch. But that's rather trivial.
(actually, it will require a update to libtraceevent).

I can send you a patch for trace-cmd after I get this figured out. I
think I have an idea that can still keep this as 3.16 material.

Thanks,

-- Steve

[RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

[-- Attachment #1: Type: text/plain, Size: 10594 bytes --]

Updated version.

You can test it with the attached trace-cmd patch. I tested it against
big and little endian machines (each reading their own and the other
machine's trace.dat file). I did not test against 32bit, but it should
still work. I will test it before I commit it to traceevent library.

Can you review this and try it out?

Thanks!

-- Steve

From be2f29847428f5a290496d1c44ad938f2c2ad040 Mon Sep 17 00:00:00 2001
From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
Date: Tue, 6 May 2014 13:10:24 -0400
Subject: [PATCH] tracing: Add __bitmask() macro to trace events to cpumasks
 and other bitmasks

Being able to show a cpumask of events can be useful as some events
may affect only some CPUs. There is no standard way to record the
cpumask and converting it to a string is rather expensive during
the trace as traces happen in hotpaths. It would be better to record
the raw event mask and be able to parse it at print time.

The following macros were added for use with the TRACE_EVENT() macro:

  __bitmask()
  __assign_bitmask()
  __get_bitmask()

To test this, I added this to the sched_migrate_task event, which
looked like this:

TRACE_EVENT(sched_migrate_task,

	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),

	TP_ARGS(p, dest_cpu, cpus),

	TP_STRUCT__entry(
		__array(	char,	comm,	TASK_COMM_LEN	)
		__field(	pid_t,	pid			)
		__field(	int,	prio			)
		__field(	int,	orig_cpu		)
		__field(	int,	dest_cpu		)
		__bitmask(	cpumask, num_possible_cpus()	)
	),

	TP_fast_assign(
		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
		__entry->pid		= p->pid;
		__entry->prio		= p->prio;
		__entry->orig_cpu	= task_cpu(p);
		__entry->dest_cpu	= dest_cpu;
		__assign_bitmask(cpumask, cpumask_bits(cpus), num_possible_cpus());
	),

	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
		  __entry->comm, __entry->pid, __entry->prio,
		  __entry->orig_cpu, __entry->dest_cpu,
		  __get_bitmask(cpumask))
);

With the output of:

        ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f
     migration/1-13    [001] d..5   485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f
             awk-3615  [002] d.H5   485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff
     migration/2-18    [002] d..5   485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f

Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com

Suggested-by: Javi Merino <javi.merino@arm.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 include/linux/ftrace_event.h |  3 +++
 include/linux/trace_seq.h    | 10 ++++++++
 include/trace/ftrace.h       | 57 +++++++++++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_output.c  | 41 +++++++++++++++++++++++++++++++
 4 files changed, 110 insertions(+), 1 deletion(-)

diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index d16da3e..cff3106 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -38,6 +38,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq *p,
 								 *symbol_array);
 #endif
 
+const char *ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
+				     unsigned int bitmask_size);
+
 const char *ftrace_print_hex_seq(struct trace_seq *p,
 				 const unsigned char *buf, int len);
 
diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
index a32d86e..1361169 100644
--- a/include/linux/trace_seq.h
+++ b/include/linux/trace_seq.h
@@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const void *mem,
 extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
 extern int trace_seq_path(struct trace_seq *s, const struct path *path);
 
+extern int trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+			     int nmaskbits);
+
 #else /* CONFIG_TRACING */
 static inline int trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 {
@@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt, const u32 *binary)
 	return 0;
 }
 
+static inline int
+trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	return 0;
+}
+
 static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
 {
 	return 0;
diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index 0a1a4f7..9b7a989 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -53,6 +53,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __bitmask
+#define __bitmask(item, nr_bits) __dynamic_array(char, item, -1)
+
 #undef TP_STRUCT__entry
 #define TP_STRUCT__entry(args...) args
 
@@ -128,6 +131,9 @@
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __bitmask
+#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 	struct ftrace_data_offsets_##call {				\
@@ -200,6 +206,15 @@
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_bitmask
+#define __get_bitmask(field)						\
+	({								\
+		void *__bitmask = __get_dynamic_array(field);		\
+		unsigned int __bitmask_size;				\
+		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
+		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
+	})
+
 #undef __print_flags
 #define __print_flags(flag, delim, flag_array...)			\
 	({								\
@@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
 #undef __string
 #define __string(item, src) __dynamic_array(char, item, -1)
 
+#undef __bitmask
+#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
 static int notrace __init						\
@@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
 #define __string(item, src) __dynamic_array(char, item,			\
 		    strlen((src) ? (const char *)(src) : "(null)") + 1)
 
+/*
+ * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
+ * num_possible_cpus().
+ */
+#define __bitmask_size_in_bytes_raw(nr_bits)	\
+	(((nr_bits) + 7) / 8)
+
+#define __bitmask_size_in_longs(nr_bits)			\
+	((__bitmask_size_in_bytes_raw(nr_bits) +		\
+	  ((BITS_PER_LONG / 8) - 1)) / (BITS_PER_LONG / 8))
+
+/*
+ * __bitmask_size_in_bytes is the number of bytes needed to hold
+ * num_possible_cpus() padded out to the nearest long. This is what
+ * is saved in the buffer, just to be consistent.
+ */
+#define __bitmask_size_in_bytes(nr_bits)				\
+	(__bitmask_size_in_longs(nr_bits) * (BITS_PER_LONG / 8))
+
+#undef __bitmask
+#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item,	\
+					 __bitmask_size_in_longs(nr_bits))
+
 #undef DECLARE_EVENT_CLASS
 #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
 static inline notrace int ftrace_get_offsets_##call(			\
@@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
 	__entry->__data_loc_##item = __data_offsets.item;
 
 #undef __string
-#define __string(item, src) __dynamic_array(char, item, -1)       	\
+#define __string(item, src) __dynamic_array(char, item, -1)
 
 #undef __assign_str
 #define __assign_str(dst, src)						\
 	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
 
+#undef __bitmask
+#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
+
+#undef __get_bitmask
+#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+
+#undef __assign_bitmask
+#define __assign_bitmask(dst, src, nr_bits)					\
+	memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes(nr_bits))
+
 #undef TP_fast_assign
 #define TP_fast_assign(args...) args
 
@@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
 #undef __print_hex
 #undef __get_dynamic_array
 #undef __get_str
+#undef __get_bitmask
 
 #undef TP_printk
 #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
@@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
 #undef __get_str
 #define __get_str(field) (char *)__get_dynamic_array(field)
 
+#undef __get_bitmask
+#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+
 #undef __perf_addr
 #define __perf_addr(a)	(__addr = (a))
 
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index a436de1..f3dad80 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -126,6 +126,34 @@ trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
 EXPORT_SYMBOL_GPL(trace_seq_printf);
 
 /**
+ * trace_seq_bitmask - put a list of longs as a bitmask print output
+ * @s:		trace sequence descriptor
+ * @maskp:	points to an array of unsigned longs that represent a bitmask
+ * @nmaskbits:	The number of bits that are valid in @maskp
+ *
+ * It returns 0 if the trace oversizes the buffer's free
+ * space, 1 otherwise.
+ *
+ * Writes a ASCII representation of a bitmask string into @s.
+ */
+int
+trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
+		  int nmaskbits)
+{
+	int len = (PAGE_SIZE - 1) - s->len;
+	int ret;
+
+	if (s->full || !len)
+		return 0;
+
+	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
+	s->len += ret;
+
+	return 1;
+}
+EXPORT_SYMBOL_GPL(trace_seq_bitmask);
+
+/**
  * trace_seq_vprintf - sequence printing of trace information
  * @s: trace sequence descriptor
  * @fmt: printf format string
@@ -399,6 +427,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
 #endif
 
 const char *
+ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
+			 unsigned int bitmask_size)
+{
+	const char *ret = p->buffer + p->len;
+
+	trace_seq_bitmask(p, bitmask_ptr, bitmask_size * 8);
+	trace_seq_putc(p, 0);
+
+	return ret;
+}
+EXPORT_SYMBOL_GPL(ftrace_print_bitmask_seq);
+
+const char *
 ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len)
 {
 	int i;
-- 
1.8.1.4



[-- Attachment #2: print-cpumask.patch --]
[-- Type: text/x-patch, Size: 5552 bytes --]

diff --git a/event-parse.c b/event-parse.c
index 114b41b..ca0d1fe 100644
--- a/event-parse.c
+++ b/event-parse.c
@@ -753,6 +753,9 @@ static void free_arg(struct print_arg *arg)
 	case PRINT_BSTRING:
 		free(arg->string.string);
 		break;
+	case PRINT_BITMASK:
+		free(arg->bitmask.bitmask);
+		break;
 	case PRINT_DYNAMIC_ARRAY:
 		free(arg->dynarray.index);
 		break;
@@ -2256,6 +2259,7 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		ret = 0;
@@ -2284,6 +2288,7 @@ static char *arg_eval (struct print_arg *arg)
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		break;
@@ -2670,6 +2675,35 @@ process_str(struct event_format *event __maybe_unused, struct print_arg *arg,
 	return EVENT_ERROR;
 }
 
+static enum event_type
+process_bitmask(struct event_format *event __maybe_unused, struct print_arg *arg,
+	    char **tok)
+{
+	enum event_type type;
+	char *token;
+
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto out_free;
+
+	arg->type = PRINT_BITMASK;
+	arg->bitmask.bitmask = token;
+	arg->bitmask.offset = -1;
+
+	if (read_expected(EVENT_DELIM, ")") < 0)
+		goto out_err;
+
+	type = read_token(&token);
+	*tok = token;
+
+	return type;
+
+ out_free:
+	free_token(token);
+ out_err:
+	*tok = NULL;
+	return EVENT_ERROR;
+}
+
 static struct pevent_function_handler *
 find_func_handler(struct pevent *pevent, char *func_name)
 {
@@ -2781,6 +2815,10 @@ process_function(struct event_format *event, struct print_arg *arg,
 		free_token(token);
 		return process_str(event, arg, tok);
 	}
+	if (strcmp(token, "__get_bitmask") == 0) {
+		free_token(token);
+		return process_bitmask(event, arg, tok);
+	}
 	if (strcmp(token, "__get_dynamic_array") == 0) {
 		free_token(token);
 		return process_dynamic_array(event, arg, tok);
@@ -3307,6 +3345,7 @@ eval_num_arg(void *data, int size, struct event_format *event, struct print_arg
 		return eval_type(val, arg, 0);
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 		return 0;
 	case PRINT_FUNC: {
 		struct trace_seq s;
@@ -3538,6 +3577,60 @@ static void print_str_to_seq(struct trace_seq *s, const char *format,
 		trace_seq_printf(s, format, str);
 }
 
+static void print_bitmask_to_seq(struct pevent *pevent,
+				 struct trace_seq *s, const char *format,
+				 int len_arg, const void *data, int size)
+{
+	int nr_bits = size * 8;
+	int str_size = (nr_bits + 3) / 4;
+	int len = 0;
+	char buf[3];
+	char *str;
+	int index;
+	int i;
+
+	/*
+	 * The kernel likes to put in commas every 32 bits, we
+	 * can do the same.
+	 */
+	str_size += nr_bits / 32;
+
+	str = malloc(str_size + 1);
+	if (!str) {
+		do_warning("%s: not enough memory!", __func__);
+		return;
+	}
+	str[str_size] = 0;
+
+	/* Start out with -3, 1 for the \0 and two for the byte */
+	for (i = str_size - 3; i >= 0; i -= 2) {
+		/*
+		 * data points to a bit mask of size bytes.
+		 * In the kernel, this is an array of long words, thus
+		 * endianess is very important.
+		 */
+		if (pevent->file_bigendian)
+			index = size - (len + 1);
+		else
+			index = len;
+
+		snprintf(buf, 3, "%02x", *((unsigned char *)data + index));
+		memcpy(str + i, buf, 2);
+		len++;
+		if (!(len & 3) && i > 0) {
+			i--;
+			str[i] = ',';
+		}
+	}			
+
+	if (len_arg >= 0)
+		trace_seq_printf(s, format, len_arg, str);
+	else
+		trace_seq_printf(s, format, str);
+
+	free(str);
+}
+
 static void print_str_arg(struct trace_seq *s, void *data, int size,
 			  struct event_format *event, const char *format,
 			  int len_arg, struct print_arg *arg)
@@ -3672,6 +3765,23 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
 	case PRINT_BSTRING:
 		print_str_to_seq(s, format, len_arg, arg->string.string);
 		break;
+	case PRINT_BITMASK: {
+		int bitmask_offset;
+		int bitmask_size;
+
+		if (arg->bitmask.offset == -1) {
+			struct format_field *f;
+
+			f = pevent_find_any_field(event, arg->bitmask.bitmask);
+			arg->bitmask.offset = f->offset;
+		}
+		bitmask_offset = data2host4(pevent, data + arg->string.offset);
+		bitmask_size = bitmask_offset >> 16;
+		bitmask_offset &= 0xffff;
+		print_bitmask_to_seq(pevent, s, format, len_arg,
+				     data + bitmask_offset, bitmask_size);
+		break;
+	}
 	case PRINT_OP:
 		/*
 		 * The only op for string should be ? :
@@ -4889,6 +4999,9 @@ static void print_args(struct print_arg *args)
 	case PRINT_BSTRING:
 		printf("__get_str(%s)", args->string.string);
 		break;
+	case PRINT_BITMASK:
+		printf("__get_bitmask(%s)", args->bitmask.bitmask);
+		break;
 	case PRINT_TYPE:
 		printf("(%s)", args->typecast.type);
 		print_args(args->typecast.item);
diff --git a/event-parse.h b/event-parse.h
index 108a4ef..babd4a4 100644
--- a/event-parse.h
+++ b/event-parse.h
@@ -211,6 +211,11 @@ struct print_arg_string {
 	int			offset;
 };
 
+struct print_arg_bitmask {
+	char			*bitmask;
+	int			offset;
+};
+
 struct print_arg_field {
 	char			*name;
 	struct format_field	*field;
@@ -277,6 +282,7 @@ enum print_arg_type {
 	PRINT_DYNAMIC_ARRAY,
 	PRINT_OP,
 	PRINT_FUNC,
+	PRINT_BITMASK,
 };
 
 struct print_arg {
@@ -291,6 +297,7 @@ struct print_arg {
 		struct print_arg_hex		hex;
 		struct print_arg_func		func;
 		struct print_arg_string		string;
+		struct print_arg_bitmask	bitmask;
 		struct print_arg_op		op;
 		struct print_arg_dynarray	dynarray;
 	};

Re: [RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Javi Merino]

On Wed, May 14, 2014 at 07:25:00PM +0100, Steven Rostedt wrote:
> Updated version.
> 
> You can test it with the attached trace-cmd patch. I tested it against
> big and little endian machines (each reading their own and the other
> machine's trace.dat file). I did not test against 32bit, but it should
> still work. I will test it before I commit it to traceevent library.
> 
> Can you review this and try it out?

I've tested it in a 32-bit system.  It generates the data and it's
able to read its own trace.dat fine.  However, If I read the
trace.dat on a 64-bit machine I get a random character at the
end of the mask:

$ ./trace-cmd report /tmp/trace.dat | grep thermal_power_limit
trace-cmd: No such file or directory
  bad op token {
  unknown op '{'
  unknown op '{'
  function scsi_trace_parse_cdb not defined
  function scsi_trace_parse_cdb not defined
  function scsi_trace_parse_cdb not defined
  function scsi_trace_parse_cdb not defined
  bad op token {
  bad op token {
  bad op token {
  bad op token {
  Error: expected type 4 but read 0
  bad op token {
  bad op token {
  Error: expected type 4 but read 0
  function jiffies_to_msecs not defined
  function jiffies_to_msecs not defined
  bad op token {
  bad op token {
 test_thermal.sh-2886  [000]    30.035000: thermal_power_limit: cpus=000000f0` freq=1400000 cdev_state=0 power=196
 test_thermal.sh-2886  [000]    30.035000: thermal_power_limit: cpus=0000000fP freq=1900000 cdev_state=0 power=5252
     kworker/0:1-195   [000]    34.265000: thermal_power_limit: cpus=000000f0� freq=1400000 cdev_state=0 power=196
     kworker/0:1-195   [000]    34.265000: thermal_power_limit: cpus=0000000f� freq=1900000 cdev_state=0 power=5252
 test_thermal.sh-2886  [000]    38.375000: thermal_power_limit: cpus=000000f0� freq=1400000 cdev_state=0 power=196
 test_thermal.sh-2886  [000]    38.375000: thermal_power_limit: cpus=0000000f@ freq=1900000 cdev_state=0 power=5252
     kworker/0:1-195   [000]    38.380000: thermal_power_limit: cpus=000000f0freq=500000 cdev_state=9 power=0
     kworker/0:1-195   [000]    38.380000: thermal_power_limit: cpus=0000000f0 freq=1900000 cdev_state=0 power=1745
     kworker/0:1-195   [000]    48.415000: thermal_power_limit: cpus=000000f0� freq=500000 cdev_state=9 power=0
     kworker/0:1-195   [000]    48.415000: thermal_power_limit: cpus=0000000f� freq=1900000 cdev_state=0 power=1740k

It looks like an off-by-one error.  The system that generated the
trace.dat is running a kernel configured with NR_CPUS=5, can that be
the culprit?

FWIW, this is the event I'm using:

TRACE_EVENT(thermal_power_limit,
	TP_PROTO(const struct cpumask *cpus, unsigned int freq, unsigned long cdev_state,
		unsigned long power),

	TP_ARGS(cpus, freq, cdev_state, power),

	TP_STRUCT__entry(
		__bitmask(cpumask, num_possible_cpus())
		__field(unsigned int,  freq      )
		__field(unsigned long, cdev_state)
		__field(unsigned long, power     )
	),

	TP_fast_assign(
		__assign_bitmask(cpumask, cpumask_bits(cpus), num_possible_cpus());
		__entry->freq = freq;
		__entry->cdev_state = cdev_state;
		__entry->power = power;
	),

	TP_printk("cpus=%s freq=%u cdev_state=%lu power=%lu",
		__get_bitmask(cpumask), __entry->freq, __entry->cdev_state,
		__entry->power)
);

Thanks!
Javi

> From be2f29847428f5a290496d1c44ad938f2c2ad040 Mon Sep 17 00:00:00 2001
> From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
> Date: Tue, 6 May 2014 13:10:24 -0400
> Subject: [PATCH] tracing: Add __bitmask() macro to trace events to cpumasks
>  and other bitmasks
> 
> Being able to show a cpumask of events can be useful as some events
> may affect only some CPUs. There is no standard way to record the
> cpumask and converting it to a string is rather expensive during
> the trace as traces happen in hotpaths. It would be better to record
> the raw event mask and be able to parse it at print time.
> 
> The following macros were added for use with the TRACE_EVENT() macro:
> 
>   __bitmask()
>   __assign_bitmask()
>   __get_bitmask()
> 
> To test this, I added this to the sched_migrate_task event, which
> looked like this:
> 
> TRACE_EVENT(sched_migrate_task,
> 
> 	TP_PROTO(struct task_struct *p, int dest_cpu, const struct cpumask *cpus),
> 
> 	TP_ARGS(p, dest_cpu, cpus),
> 
> 	TP_STRUCT__entry(
> 		__array(	char,	comm,	TASK_COMM_LEN	)
> 		__field(	pid_t,	pid			)
> 		__field(	int,	prio			)
> 		__field(	int,	orig_cpu		)
> 		__field(	int,	dest_cpu		)
> 		__bitmask(	cpumask, num_possible_cpus()	)
> 	),
> 
> 	TP_fast_assign(
> 		memcpy(__entry->comm, p->comm, TASK_COMM_LEN);
> 		__entry->pid		= p->pid;
> 		__entry->prio		= p->prio;
> 		__entry->orig_cpu	= task_cpu(p);
> 		__entry->dest_cpu	= dest_cpu;
> 		__assign_bitmask(cpumask, cpumask_bits(cpus), num_possible_cpus());
> 	),
> 
> 	TP_printk("comm=%s pid=%d prio=%d orig_cpu=%d dest_cpu=%d cpumask=%s",
> 		  __entry->comm, __entry->pid, __entry->prio,
> 		  __entry->orig_cpu, __entry->dest_cpu,
> 		  __get_bitmask(cpumask))
> );
> 
> With the output of:
> 
>         ksmtuned-3613  [003] d..2   485.220508: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=3 dest_cpu=2 cpumask=00000000,0000000f
>      migration/1-13    [001] d..5   485.221202: sched_migrate_task: comm=ksmtuned pid=3614 prio=120 orig_cpu=1 dest_cpu=0 cpumask=00000000,0000000f
>              awk-3615  [002] d.H5   485.221747: sched_migrate_task: comm=rcu_preempt pid=7 prio=120 orig_cpu=0 dest_cpu=1 cpumask=00000000,000000ff
>      migration/2-18    [002] d..5   485.222062: sched_migrate_task: comm=ksmtuned pid=3615 prio=120 orig_cpu=2 dest_cpu=3 cpumask=00000000,0000000f
> 
> Link: http://lkml.kernel.org/r/1399377998-14870-6-git-send-email-javi.merino@arm.com
> 
> Suggested-by: Javi Merino <javi.merino@arm.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
>  include/linux/ftrace_event.h |  3 +++
>  include/linux/trace_seq.h    | 10 ++++++++
>  include/trace/ftrace.h       | 57 +++++++++++++++++++++++++++++++++++++++++++-
>  kernel/trace/trace_output.c  | 41 +++++++++++++++++++++++++++++++
>  4 files changed, 110 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index d16da3e..cff3106 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -38,6 +38,9 @@ const char *ftrace_print_symbols_seq_u64(struct trace_seq *p,
>  								 *symbol_array);
>  #endif
>  
> +const char *ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
> +				     unsigned int bitmask_size);
> +
>  const char *ftrace_print_hex_seq(struct trace_seq *p,
>  				 const unsigned char *buf, int len);
>  
> diff --git a/include/linux/trace_seq.h b/include/linux/trace_seq.h
> index a32d86e..1361169 100644
> --- a/include/linux/trace_seq.h
> +++ b/include/linux/trace_seq.h
> @@ -46,6 +46,9 @@ extern int trace_seq_putmem_hex(struct trace_seq *s, const void *mem,
>  extern void *trace_seq_reserve(struct trace_seq *s, size_t len);
>  extern int trace_seq_path(struct trace_seq *s, const struct path *path);
>  
> +extern int trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +			     int nmaskbits);
> +
>  #else /* CONFIG_TRACING */
>  static inline int trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
>  {
> @@ -57,6 +60,13 @@ trace_seq_bprintf(struct trace_seq *s, const char *fmt, const u32 *binary)
>  	return 0;
>  }
>  
> +static inline int
> +trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	return 0;
> +}
> +
>  static inline int trace_print_seq(struct seq_file *m, struct trace_seq *s)
>  {
>  	return 0;
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index 0a1a4f7..9b7a989 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -53,6 +53,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, nr_bits) __dynamic_array(char, item, -1)
> +
>  #undef TP_STRUCT__entry
>  #define TP_STRUCT__entry(args...) args
>  
> @@ -128,6 +131,9 @@
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  	struct ftrace_data_offsets_##call {				\
> @@ -200,6 +206,15 @@
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_bitmask
> +#define __get_bitmask(field)						\
> +	({								\
> +		void *__bitmask = __get_dynamic_array(field);		\
> +		unsigned int __bitmask_size;				\
> +		__bitmask_size = (__entry->__data_loc_##field >> 16) & 0xffff; \
> +		ftrace_print_bitmask_seq(p, __bitmask, __bitmask_size);	\
> +	})
> +
>  #undef __print_flags
>  #define __print_flags(flag, delim, flag_array...)			\
>  	({								\
> @@ -322,6 +337,9 @@ static struct trace_event_functions ftrace_event_type_funcs_##call = {	\
>  #undef __string
>  #define __string(item, src) __dynamic_array(char, item, -1)
>  
> +#undef __bitmask
> +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print)	\
>  static int notrace __init						\
> @@ -372,6 +390,29 @@ ftrace_define_fields_##call(struct ftrace_event_call *event_call)	\
>  #define __string(item, src) __dynamic_array(char, item,			\
>  		    strlen((src) ? (const char *)(src) : "(null)") + 1)
>  
> +/*
> + * __bitmask_size_in_bytes_raw is the number of bytes needed to hold
> + * num_possible_cpus().
> + */
> +#define __bitmask_size_in_bytes_raw(nr_bits)	\
> +	(((nr_bits) + 7) / 8)
> +
> +#define __bitmask_size_in_longs(nr_bits)			\
> +	((__bitmask_size_in_bytes_raw(nr_bits) +		\
> +	  ((BITS_PER_LONG / 8) - 1)) / (BITS_PER_LONG / 8))
> +
> +/*
> + * __bitmask_size_in_bytes is the number of bytes needed to hold
> + * num_possible_cpus() padded out to the nearest long. This is what
> + * is saved in the buffer, just to be consistent.
> + */
> +#define __bitmask_size_in_bytes(nr_bits)				\
> +	(__bitmask_size_in_longs(nr_bits) * (BITS_PER_LONG / 8))
> +
> +#undef __bitmask
> +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item,	\
> +					 __bitmask_size_in_longs(nr_bits))
> +
>  #undef DECLARE_EVENT_CLASS
>  #define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print)	\
>  static inline notrace int ftrace_get_offsets_##call(			\
> @@ -513,12 +554,22 @@ static inline notrace int ftrace_get_offsets_##call(			\
>  	__entry->__data_loc_##item = __data_offsets.item;
>  
>  #undef __string
> -#define __string(item, src) __dynamic_array(char, item, -1)       	\
> +#define __string(item, src) __dynamic_array(char, item, -1)
>  
>  #undef __assign_str
>  #define __assign_str(dst, src)						\
>  	strcpy(__get_str(dst), (src) ? (const char *)(src) : "(null)");
>  
> +#undef __bitmask
> +#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
> +
> +#undef __get_bitmask
> +#define __get_bitmask(field) (char *)__get_dynamic_array(field)
> +
> +#undef __assign_bitmask
> +#define __assign_bitmask(dst, src, nr_bits)					\
> +	memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes(nr_bits))
> +
>  #undef TP_fast_assign
>  #define TP_fast_assign(args...) args
>  
> @@ -586,6 +637,7 @@ static inline void ftrace_test_probe_##call(void)			\
>  #undef __print_hex
>  #undef __get_dynamic_array
>  #undef __get_str
> +#undef __get_bitmask
>  
>  #undef TP_printk
>  #define TP_printk(fmt, args...) "\"" fmt "\", "  __stringify(args)
> @@ -651,6 +703,9 @@ __attribute__((section("_ftrace_events"))) *__event_##call = &event_##call
>  #undef __get_str
>  #define __get_str(field) (char *)__get_dynamic_array(field)
>  
> +#undef __get_bitmask
> +#define __get_bitmask(field) (char *)__get_dynamic_array(field)
> +
>  #undef __perf_addr
>  #define __perf_addr(a)	(__addr = (a))
>  
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index a436de1..f3dad80 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -126,6 +126,34 @@ trace_seq_printf(struct trace_seq *s, const char *fmt, ...)
>  EXPORT_SYMBOL_GPL(trace_seq_printf);
>  
>  /**
> + * trace_seq_bitmask - put a list of longs as a bitmask print output
> + * @s:		trace sequence descriptor
> + * @maskp:	points to an array of unsigned longs that represent a bitmask
> + * @nmaskbits:	The number of bits that are valid in @maskp
> + *
> + * It returns 0 if the trace oversizes the buffer's free
> + * space, 1 otherwise.
> + *
> + * Writes a ASCII representation of a bitmask string into @s.
> + */
> +int
> +trace_seq_bitmask(struct trace_seq *s, const unsigned long *maskp,
> +		  int nmaskbits)
> +{
> +	int len = (PAGE_SIZE - 1) - s->len;
> +	int ret;
> +
> +	if (s->full || !len)
> +		return 0;
> +
> +	ret = bitmap_scnprintf(s->buffer, len, maskp, nmaskbits);
> +	s->len += ret;
> +
> +	return 1;
> +}
> +EXPORT_SYMBOL_GPL(trace_seq_bitmask);
> +
> +/**
>   * trace_seq_vprintf - sequence printing of trace information
>   * @s: trace sequence descriptor
>   * @fmt: printf format string
> @@ -399,6 +427,19 @@ EXPORT_SYMBOL(ftrace_print_symbols_seq_u64);
>  #endif
>  
>  const char *
> +ftrace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr,
> +			 unsigned int bitmask_size)
> +{
> +	const char *ret = p->buffer + p->len;
> +
> +	trace_seq_bitmask(p, bitmask_ptr, bitmask_size * 8);
> +	trace_seq_putc(p, 0);
> +
> +	return ret;
> +}
> +EXPORT_SYMBOL_GPL(ftrace_print_bitmask_seq);
> +
> +const char *
>  ftrace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len)
>  {
>  	int i;
> -- 
> 1.8.1.4
> 

> diff --git a/event-parse.c b/event-parse.c
> index 114b41b..ca0d1fe 100644
> --- a/event-parse.c
> +++ b/event-parse.c
> @@ -753,6 +753,9 @@ static void free_arg(struct print_arg *arg)
>  	case PRINT_BSTRING:
>  		free(arg->string.string);
>  		break;
> +	case PRINT_BITMASK:
> +		free(arg->bitmask.bitmask);
> +		break;
>  	case PRINT_DYNAMIC_ARRAY:
>  		free(arg->dynarray.index);
>  		break;
> @@ -2256,6 +2259,7 @@ static int arg_num_eval(struct print_arg *arg, long long *val)
>  	case PRINT_FIELD ... PRINT_SYMBOL:
>  	case PRINT_STRING:
>  	case PRINT_BSTRING:
> +	case PRINT_BITMASK:
>  	default:
>  		do_warning("invalid eval type %d", arg->type);
>  		ret = 0;
> @@ -2284,6 +2288,7 @@ static char *arg_eval (struct print_arg *arg)
>  	case PRINT_FIELD ... PRINT_SYMBOL:
>  	case PRINT_STRING:
>  	case PRINT_BSTRING:
> +	case PRINT_BITMASK:
>  	default:
>  		do_warning("invalid eval type %d", arg->type);
>  		break;
> @@ -2670,6 +2675,35 @@ process_str(struct event_format *event __maybe_unused, struct print_arg *arg,
>  	return EVENT_ERROR;
>  }
>  
> +static enum event_type
> +process_bitmask(struct event_format *event __maybe_unused, struct print_arg *arg,
> +	    char **tok)
> +{
> +	enum event_type type;
> +	char *token;
> +
> +	if (read_expect_type(EVENT_ITEM, &token) < 0)
> +		goto out_free;
> +
> +	arg->type = PRINT_BITMASK;
> +	arg->bitmask.bitmask = token;
> +	arg->bitmask.offset = -1;
> +
> +	if (read_expected(EVENT_DELIM, ")") < 0)
> +		goto out_err;
> +
> +	type = read_token(&token);
> +	*tok = token;
> +
> +	return type;
> +
> + out_free:
> +	free_token(token);
> + out_err:
> +	*tok = NULL;
> +	return EVENT_ERROR;
> +}
> +
>  static struct pevent_function_handler *
>  find_func_handler(struct pevent *pevent, char *func_name)
>  {
> @@ -2781,6 +2815,10 @@ process_function(struct event_format *event, struct print_arg *arg,
>  		free_token(token);
>  		return process_str(event, arg, tok);
>  	}
> +	if (strcmp(token, "__get_bitmask") == 0) {
> +		free_token(token);
> +		return process_bitmask(event, arg, tok);
> +	}
>  	if (strcmp(token, "__get_dynamic_array") == 0) {
>  		free_token(token);
>  		return process_dynamic_array(event, arg, tok);
> @@ -3307,6 +3345,7 @@ eval_num_arg(void *data, int size, struct event_format *event, struct print_arg
>  		return eval_type(val, arg, 0);
>  	case PRINT_STRING:
>  	case PRINT_BSTRING:
> +	case PRINT_BITMASK:
>  		return 0;
>  	case PRINT_FUNC: {
>  		struct trace_seq s;
> @@ -3538,6 +3577,60 @@ static void print_str_to_seq(struct trace_seq *s, const char *format,
>  		trace_seq_printf(s, format, str);
>  }
>  
> +static void print_bitmask_to_seq(struct pevent *pevent,
> +				 struct trace_seq *s, const char *format,
> +				 int len_arg, const void *data, int size)
> +{
> +	int nr_bits = size * 8;
> +	int str_size = (nr_bits + 3) / 4;
> +	int len = 0;
> +	char buf[3];
> +	char *str;
> +	int index;
> +	int i;
> +
> +	/*
> +	 * The kernel likes to put in commas every 32 bits, we
> +	 * can do the same.
> +	 */
> +	str_size += nr_bits / 32;
> +
> +	str = malloc(str_size + 1);
> +	if (!str) {
> +		do_warning("%s: not enough memory!", __func__);
> +		return;
> +	}
> +	str[str_size] = 0;
> +
> +	/* Start out with -3, 1 for the \0 and two for the byte */
> +	for (i = str_size - 3; i >= 0; i -= 2) {
> +		/*
> +		 * data points to a bit mask of size bytes.
> +		 * In the kernel, this is an array of long words, thus
> +		 * endianess is very important.
> +		 */
> +		if (pevent->file_bigendian)
> +			index = size - (len + 1);
> +		else
> +			index = len;
> +
> +		snprintf(buf, 3, "%02x", *((unsigned char *)data + index));
> +		memcpy(str + i, buf, 2);
> +		len++;
> +		if (!(len & 3) && i > 0) {
> +			i--;
> +			str[i] = ',';
> +		}
> +	}			
> +
> +	if (len_arg >= 0)
> +		trace_seq_printf(s, format, len_arg, str);
> +	else
> +		trace_seq_printf(s, format, str);
> +
> +	free(str);
> +}
> +
>  static void print_str_arg(struct trace_seq *s, void *data, int size,
>  			  struct event_format *event, const char *format,
>  			  int len_arg, struct print_arg *arg)
> @@ -3672,6 +3765,23 @@ static void print_str_arg(struct trace_seq *s, void *data, int size,
>  	case PRINT_BSTRING:
>  		print_str_to_seq(s, format, len_arg, arg->string.string);
>  		break;
> +	case PRINT_BITMASK: {
> +		int bitmask_offset;
> +		int bitmask_size;
> +
> +		if (arg->bitmask.offset == -1) {
> +			struct format_field *f;
> +
> +			f = pevent_find_any_field(event, arg->bitmask.bitmask);
> +			arg->bitmask.offset = f->offset;
> +		}
> +		bitmask_offset = data2host4(pevent, data + arg->string.offset);
> +		bitmask_size = bitmask_offset >> 16;
> +		bitmask_offset &= 0xffff;
> +		print_bitmask_to_seq(pevent, s, format, len_arg,
> +				     data + bitmask_offset, bitmask_size);
> +		break;
> +	}
>  	case PRINT_OP:
>  		/*
>  		 * The only op for string should be ? :
> @@ -4889,6 +4999,9 @@ static void print_args(struct print_arg *args)
>  	case PRINT_BSTRING:
>  		printf("__get_str(%s)", args->string.string);
>  		break;
> +	case PRINT_BITMASK:
> +		printf("__get_bitmask(%s)", args->bitmask.bitmask);
> +		break;
>  	case PRINT_TYPE:
>  		printf("(%s)", args->typecast.type);
>  		print_args(args->typecast.item);
> diff --git a/event-parse.h b/event-parse.h
> index 108a4ef..babd4a4 100644
> --- a/event-parse.h
> +++ b/event-parse.h
> @@ -211,6 +211,11 @@ struct print_arg_string {
>  	int			offset;
>  };
>  
> +struct print_arg_bitmask {
> +	char			*bitmask;
> +	int			offset;
> +};
> +
>  struct print_arg_field {
>  	char			*name;
>  	struct format_field	*field;
> @@ -277,6 +282,7 @@ enum print_arg_type {
>  	PRINT_DYNAMIC_ARRAY,
>  	PRINT_OP,
>  	PRINT_FUNC,
> +	PRINT_BITMASK,
>  };
>  
>  struct print_arg {
> @@ -291,6 +297,7 @@ struct print_arg {
>  		struct print_arg_hex		hex;
>  		struct print_arg_func		func;
>  		struct print_arg_string		string;
> +		struct print_arg_bitmask	bitmask;
>  		struct print_arg_op		op;
>  		struct print_arg_dynarray	dynarray;
>  	};

Re: [RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

On Wed, 14 May 2014 20:42:41 +0100
Javi Merino <javi.merino@arm.com> wrote:

> On Wed, May 14, 2014 at 07:25:00PM +0100, Steven Rostedt wrote:
> > Updated version.
> > 
> > You can test it with the attached trace-cmd patch. I tested it against
> > big and little endian machines (each reading their own and the other
> > machine's trace.dat file). I did not test against 32bit, but it should
> > still work. I will test it before I commit it to traceevent library.
> > 
> > Can you review this and try it out?
> 
> I've tested it in a 32-bit system.  It generates the data and it's
> able to read its own trace.dat fine.  However, If I read the
> trace.dat on a 64-bit machine I get a random character at the
> end of the mask:
> 

Can you send me your trace.dat file privately. Also, please compress it
with either gzip, bzip or xz.

Thanks!

-- Steve

Re: [RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

[-- Attachment #1: Type: text/plain, Size: 688 bytes --]

On Wed, 14 May 2014 20:42:41 +0100
Javi Merino <javi.merino@arm.com> wrote:


> It looks like an off-by-one error.  The system that generated the
> trace.dat is running a kernel configured with NR_CPUS=5, can that be
> the culprit?

You were correct! Actually, I had two off by one errors :-/

One was with calculating the number of added commas

-	str_size += nr_bits / 32;
+	str_size += (nr_bits - 1) / 32

No comma if the we have exactly 32 bits (only one if we have 64).

The other was with the start:

-	for (i = str_size - 3; i >= 0; i -= 2) {
+	for (i = str_size - 2; i >= 0; i -= 2) {

I included the '\0' when I didn't have to :-p

Should work now. Thanks for testing.

-- Steve

[-- Attachment #2: print-cpumask.patch --]
[-- Type: text/x-patch, Size: 5325 bytes --]

---
 event-parse.c |  113 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 event-parse.h |    7 +++
 2 files changed, 120 insertions(+)

Index: trace-cmd.git/event-parse.c
===================================================================
--- trace-cmd.git.orig/event-parse.c	2014-05-15 07:29:18.552527943 -0400
+++ trace-cmd.git/event-parse.c	2014-05-15 07:29:54.483122795 -0400
@@ -753,6 +753,9 @@
 	case PRINT_BSTRING:
 		free(arg->string.string);
 		break;
+	case PRINT_BITMASK:
+		free(arg->bitmask.bitmask);
+		break;
 	case PRINT_DYNAMIC_ARRAY:
 		free(arg->dynarray.index);
 		break;
@@ -2256,6 +2259,7 @@
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		ret = 0;
@@ -2284,6 +2288,7 @@
 	case PRINT_FIELD ... PRINT_SYMBOL:
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 	default:
 		do_warning("invalid eval type %d", arg->type);
 		break;
@@ -2670,6 +2675,35 @@
 	return EVENT_ERROR;
 }
 
+static enum event_type
+process_bitmask(struct event_format *event __maybe_unused, struct print_arg *arg,
+	    char **tok)
+{
+	enum event_type type;
+	char *token;
+
+	if (read_expect_type(EVENT_ITEM, &token) < 0)
+		goto out_free;
+
+	arg->type = PRINT_BITMASK;
+	arg->bitmask.bitmask = token;
+	arg->bitmask.offset = -1;
+
+	if (read_expected(EVENT_DELIM, ")") < 0)
+		goto out_err;
+
+	type = read_token(&token);
+	*tok = token;
+
+	return type;
+
+ out_free:
+	free_token(token);
+ out_err:
+	*tok = NULL;
+	return EVENT_ERROR;
+}
+
 static struct pevent_function_handler *
 find_func_handler(struct pevent *pevent, char *func_name)
 {
@@ -2781,6 +2815,10 @@
 		free_token(token);
 		return process_str(event, arg, tok);
 	}
+	if (strcmp(token, "__get_bitmask") == 0) {
+		free_token(token);
+		return process_bitmask(event, arg, tok);
+	}
 	if (strcmp(token, "__get_dynamic_array") == 0) {
 		free_token(token);
 		return process_dynamic_array(event, arg, tok);
@@ -3307,6 +3345,7 @@
 		return eval_type(val, arg, 0);
 	case PRINT_STRING:
 	case PRINT_BSTRING:
+	case PRINT_BITMASK:
 		return 0;
 	case PRINT_FUNC: {
 		struct trace_seq s;
@@ -3538,6 +3577,60 @@
 		trace_seq_printf(s, format, str);
 }
 
+static void print_bitmask_to_seq(struct pevent *pevent,
+				 struct trace_seq *s, const char *format,
+				 int len_arg, const void *data, int size)
+{
+	int nr_bits = size * 8;
+	int str_size = (nr_bits + 3) / 4;
+	int len = 0;
+	char buf[3];
+	char *str;
+	int index;
+	int i;
+
+	/*
+	 * The kernel likes to put in commas every 32 bits, we
+	 * can do the same.
+	 */
+	str_size += (nr_bits - 1) / 32;
+
+	str = malloc(str_size + 1);
+	if (!str) {
+		do_warning("%s: not enough memory!", __func__);
+		return;
+	}
+	str[str_size] = 0;
+
+	/* Start out with -2 for the two chars per byte */
+	for (i = str_size - 2; i >= 0; i -= 2) {
+		/*
+		 * data points to a bit mask of size bytes.
+		 * In the kernel, this is an array of long words, thus
+		 * endianess is very important.
+		 */
+		if (pevent->file_bigendian)
+			index = size - (len + 1);
+		else
+			index = len;
+
+		snprintf(buf, 3, "%02x", *((unsigned char *)data + index));
+		memcpy(str + i, buf, 2);
+		len++;
+		if (!(len & 3) && i > 0) {
+			i--;
+			str[i] = ',';
+		}
+	}
+
+	if (len_arg >= 0)
+		trace_seq_printf(s, format, len_arg, str);
+	else
+		trace_seq_printf(s, format, str);
+
+	free(str);
+}
+
 static void print_str_arg(struct trace_seq *s, void *data, int size,
 			  struct event_format *event, const char *format,
 			  int len_arg, struct print_arg *arg)
@@ -3672,6 +3765,23 @@
 	case PRINT_BSTRING:
 		print_str_to_seq(s, format, len_arg, arg->string.string);
 		break;
+	case PRINT_BITMASK: {
+		int bitmask_offset;
+		int bitmask_size;
+
+		if (arg->bitmask.offset == -1) {
+			struct format_field *f;
+
+			f = pevent_find_any_field(event, arg->bitmask.bitmask);
+			arg->bitmask.offset = f->offset;
+		}
+		bitmask_offset = data2host4(pevent, data + arg->string.offset);
+		bitmask_size = bitmask_offset >> 16;
+		bitmask_offset &= 0xffff;
+		print_bitmask_to_seq(pevent, s, format, len_arg,
+				     data + bitmask_offset, bitmask_size);
+		break;
+	}
 	case PRINT_OP:
 		/*
 		 * The only op for string should be ? :
@@ -4889,6 +4999,9 @@
 	case PRINT_BSTRING:
 		printf("__get_str(%s)", args->string.string);
 		break;
+	case PRINT_BITMASK:
+		printf("__get_bitmask(%s)", args->bitmask.bitmask);
+		break;
 	case PRINT_TYPE:
 		printf("(%s)", args->typecast.type);
 		print_args(args->typecast.item);
Index: trace-cmd.git/event-parse.h
===================================================================
--- trace-cmd.git.orig/event-parse.h	2014-05-15 07:29:18.552527943 -0400
+++ trace-cmd.git/event-parse.h	2014-05-15 07:29:19.772514187 -0400
@@ -211,6 +211,11 @@
 	int			offset;
 };
 
+struct print_arg_bitmask {
+	char			*bitmask;
+	int			offset;
+};
+
 struct print_arg_field {
 	char			*name;
 	struct format_field	*field;
@@ -277,6 +282,7 @@
 	PRINT_DYNAMIC_ARRAY,
 	PRINT_OP,
 	PRINT_FUNC,
+	PRINT_BITMASK,
 };
 
 struct print_arg {
@@ -291,6 +297,7 @@
 		struct print_arg_hex		hex;
 		struct print_arg_func		func;
 		struct print_arg_string		string;
+		struct print_arg_bitmask	bitmask;
 		struct print_arg_op		op;
 		struct print_arg_dynarray	dynarray;
 	};

Re: [RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Steven Rostedt]

On Thu, 15 May 2014 07:34:05 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:


> Should work now. Thanks for testing.

If all goes well, can you please give me your "Tested-by" for both
patches. I've already ran my updated bitmask kernel patch through my
tests (although, there's still no event that uses it).

I'll push it to my for-next repo. I'll also work on updating
libtraceevent with the trace-cmd patch such that perf gets the benefit
of this new macro as well.

-- Steve

Re: [RFC][PATCH v3] tracing: Add __bitmask() macro to trace events to cpumasks and other bitmasks

[Javi Merino]

On Thu, May 15, 2014 at 12:36:09PM +0100, Steven Rostedt wrote:
> On Thu, 15 May 2014 07:34:05 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> 
> > Should work now. Thanks for testing.
> 
> If all goes well, can you please give me your "Tested-by" for both
> patches. I've already ran my updated bitmask kernel patch through my
> tests (although, there's still no event that uses it).

I've tested it on my setup and it works beautifully now.  You can add
my Tested-by to both the kernel and the trace-cmd patches.  I'll
include the kernel one together with a patch that uses it as part of
our next series, thanks!

> I'll push it to my for-next repo. I'll also work on updating
> libtraceevent with the trace-cmd patch such that perf gets the benefit
> of this new macro as well.

Yup, I guess we'll need a new version of trace-cmd to support this
when it gets into the kernel.

Thanks for the prompt response,
Javi