[PATCH v7 0/2] perf: add support for logging debug messages to file

[PATCH v7 0/2] perf: add support for logging debug messages to file

[Changbin Du]

When in TUI mode, it is impossible to show all the debug messages to
console. This make it hard to debug perf issues using debug messages.
This patch adds support for logging debug messages to file to resolve
this problem.

v7:
  o fix a mistake.
v6:
  o rebase to perf/core.
v5:
  o doc default log path.
v4:
  o fix another segfault.
v3:
  o fix a segfault issue.
v2:
  o specific all debug options one time.

Changbin Du (2):
  perf: support multiple debug options separated by ','
  perf: add support for logging debug messages to file

 tools/perf/Documentation/perf.txt |  24 +++---
 tools/perf/util/debug.c           | 127 ++++++++++++++++++++----------
 2 files changed, 98 insertions(+), 53 deletions(-)

-- 
2.20.1

[PATCH v7 1/2] perf: support multiple debug options separated by ','

[Changbin Du]

This patch adds support for multiple debug options separated by ',' and
non-int values.
	--debug verbose=2,stderr

Signed-off-by: Changbin Du <changbin.du@gmail.com>
---
 tools/perf/Documentation/perf.txt | 18 +++----
 tools/perf/util/debug.c           | 89 ++++++++++++++++---------------
 2 files changed, 56 insertions(+), 51 deletions(-)

diff --git a/tools/perf/Documentation/perf.txt b/tools/perf/Documentation/perf.txt
index 3f37ded13f8c..dcf9d98065f2 100644
--- a/tools/perf/Documentation/perf.txt
+++ b/tools/perf/Documentation/perf.txt
@@ -13,19 +13,19 @@ SYNOPSIS
 OPTIONS
 -------
 --debug::
-	Setup debug variable (see list below) in value
-	range (0, 10). Use like:
+	Setup debug variable (see list below). The range of 'level' value
+	is (0, 10). Use like:
 	  --debug verbose   # sets verbose = 1
 	  --debug verbose=2 # sets verbose = 2
 
 	List of debug variables allowed to set:
-	  verbose          - general debug messages
-	  ordered-events   - ordered events object debug messages
-	  data-convert     - data convert command debug messages
-	  stderr           - write debug output (option -v) to stderr
-	                     in browser mode
-	  perf-event-open  - Print perf_event_open() arguments and
-			     return value
+	  verbose[=level]	- general debug messages
+	  ordered-events[=level]- ordered events object debug messages
+	  data-convert[=level]	- data convert command debug messages
+	  stderr		- write debug output (option -v) to stderr
+	                          in browser mode
+	  perf-event-open	- Print perf_event_open() arguments and
+	                          return value
 
 --buildid-dir::
 	Setup buildid cache directory. It has higher priority than
diff --git a/tools/perf/util/debug.c b/tools/perf/util/debug.c
index adb656745ecc..929da46ece92 100644
--- a/tools/perf/util/debug.c
+++ b/tools/perf/util/debug.c
@@ -27,7 +27,7 @@ int verbose;
 int debug_peo_args;
 bool dump_trace = false, quiet = false;
 int debug_ordered_events;
-static int redirect_to_stderr;
+static bool redirect_to_stderr;
 int debug_data_convert;
 
 int veprintf(int level, int var, const char *fmt, va_list args)
@@ -173,42 +173,18 @@ void trace_event(union perf_event *event)
 		     trace_event_printer, event);
 }
 
-static struct debug_variable {
-	const char *name;
-	int *ptr;
-} debug_variables[] = {
-	{ .name = "verbose",		.ptr = &verbose },
-	{ .name = "ordered-events",	.ptr = &debug_ordered_events},
-	{ .name = "stderr",		.ptr = &redirect_to_stderr},
-	{ .name = "data-convert",	.ptr = &debug_data_convert },
-	{ .name = "perf-event-open",	.ptr = &debug_peo_args },
-	{ .name = NULL, }
-};
-
-int perf_debug_option(const char *str)
+static int str2loglevel(const char *vstr)
 {
-	struct debug_variable *var = &debug_variables[0];
-	char *vstr, *s = strdup(str);
 	int v = 1;
-
-	vstr = strchr(s, '=');
-	if (vstr)
-		*vstr++ = 0;
-
-	while (var->name) {
-		if (!strcmp(s, var->name))
-			break;
-		var++;
-	}
-
-	if (!var->name) {
-		pr_err("Unknown debug variable name '%s'\n", s);
-		free(s);
-		return -1;
-	}
+	char *endptr;
 
 	if (vstr) {
-		v = atoi(vstr);
+		v = strtol(vstr, &endptr,0);
+		if (vstr == endptr) {
+			fprintf(stderr, "warning: '%s' is not a digit\n", vstr);
+			return -1;
+		}
+
 		/*
 		 * Allow only values in range (0, 10),
 		 * otherwise set 0.
@@ -219,20 +195,49 @@ int perf_debug_option(const char *str)
 	if (quiet)
 		v = -1;
 
-	*var->ptr = v;
-	free(s);
+	return v;
+}
+
+int perf_debug_option(const char *str)
+{
+	char *sep, *vstr;
+	char *dstr = strdup(str);
+	char *opt = dstr;
+
+	do {
+		if ((sep = strchr(opt, ',')) != NULL)
+			*sep = '\0';
+
+		vstr = strchr(opt, '=');
+		if (vstr)
+			*vstr++ = 0;
+
+		if (!strcmp(opt, "verbose"))
+			verbose = str2loglevel(vstr);
+		else if (!strcmp(opt, "ordered-events"))
+			debug_ordered_events = str2loglevel(vstr);
+		else if (!strcmp(opt, "data-convert"))
+			debug_data_convert = str2loglevel(vstr);
+		else if (!strcmp(opt, "stderr"))
+			redirect_to_stderr = true;
+		else if (!strcmp(opt, "perf-event-open"))
+			debug_peo_args = true;
+		else {
+			fprintf(stderr, "unkown debug option '%s'\n", opt);
+			free(dstr);
+			return -1;
+		}
+
+		opt = sep + 1;
+	} while (sep && sep[1]);
+
+	free(dstr);
 	return 0;
 }
 
 int perf_quiet_option(void)
 {
-	struct debug_variable *var = &debug_variables[0];
-
-	/* disable all debug messages */
-	while (var->name) {
-		*var->ptr = -1;
-		var++;
-	}
+	verbose = debug_ordered_events = debug_data_convert = -1;
 
 	return 0;
 }
-- 
2.20.1

[PATCH v7 2/2] perf: add support for logging debug messages to file

[Changbin Du]

When in TUI mode, it is impossible to show all the debug messages to
console. This make it hard to debug perf issues using debug messages.
This patch adds support for logging debug messages to file to resolve
this problem.

The usage is:
perf -debug verbose=2,file=~/perf.log COMMAND

Signed-off-by: Changbin Du <changbin.du@gmail.com>

---
v5: doc default log path.
v4: fix another segfault.
v3: fix a segfault issue.
---
 tools/perf/Documentation/perf.txt |  6 ++++-
 tools/perf/util/debug.c           | 44 ++++++++++++++++++++++++++++---
 2 files changed, 45 insertions(+), 5 deletions(-)

diff --git a/tools/perf/Documentation/perf.txt b/tools/perf/Documentation/perf.txt
index dcf9d98065f2..52c6ba825552 100644
--- a/tools/perf/Documentation/perf.txt
+++ b/tools/perf/Documentation/perf.txt
@@ -16,7 +16,8 @@ OPTIONS
 	Setup debug variable (see list below). The range of 'level' value
 	is (0, 10). Use like:
 	  --debug verbose   # sets verbose = 1
-	  --debug verbose=2 # sets verbose = 2
+	  --debug verbose=2,file=~/perf.log
+	                    # sets verbose = 2 and save log to file
 
 	List of debug variables allowed to set:
 	  verbose[=level]	- general debug messages
@@ -26,6 +27,9 @@ OPTIONS
 	                          in browser mode
 	  perf-event-open	- Print perf_event_open() arguments and
 	                          return value
+	  file[=path]           - write debug output to log file, default
+	                          'perf.log' (stderr and file options are
+	                          exclusive)
 
 --buildid-dir::
 	Setup buildid cache directory. It has higher priority than
diff --git a/tools/perf/util/debug.c b/tools/perf/util/debug.c
index 929da46ece92..21bc889976bc 100644
--- a/tools/perf/util/debug.c
+++ b/tools/perf/util/debug.c
@@ -6,6 +6,7 @@
 #include <stdarg.h>
 #include <stdio.h>
 #include <stdlib.h>
+#include <errno.h>
 #include <sys/wait.h>
 #include <api/debug.h>
 #include <linux/kernel.h>
@@ -27,7 +28,7 @@ int verbose;
 int debug_peo_args;
 bool dump_trace = false, quiet = false;
 int debug_ordered_events;
-static bool redirect_to_stderr;
+static FILE *log_file;
 int debug_data_convert;
 
 int veprintf(int level, int var, const char *fmt, va_list args)
@@ -35,8 +36,10 @@ int veprintf(int level, int var, const char *fmt, va_list args)
 	int ret = 0;
 
 	if (var >= level) {
-		if (use_browser >= 1 && !redirect_to_stderr)
+		if (use_browser >= 1 && !log_file)
 			ui_helpline__vshow(fmt, args);
+		else if (log_file)
+			ret = vfprintf(log_file, fmt, args);
 		else
 			ret = vfprintf(stderr, fmt, args);
 	}
@@ -198,6 +201,24 @@ static int str2loglevel(const char *vstr)
 	return v;
 }
 
+static void flush_log(void)
+{
+	if (log_file)
+		fflush(log_file);
+}
+
+static void set_log_output(FILE *f)
+{
+	if (f == log_file)
+		return;
+
+	if (log_file && log_file != stderr)
+		fclose(log_file);
+
+	log_file = f;
+	atexit(flush_log);
+}
+
 int perf_debug_option(const char *str)
 {
 	char *sep, *vstr;
@@ -219,10 +240,25 @@ int perf_debug_option(const char *str)
 		else if (!strcmp(opt, "data-convert"))
 			debug_data_convert = str2loglevel(vstr);
 		else if (!strcmp(opt, "stderr"))
-			redirect_to_stderr = true;
+			set_log_output(stderr);
 		else if (!strcmp(opt, "perf-event-open"))
 			debug_peo_args = true;
-		else {
+		else if (!strcmp(opt, "file")) {
+			FILE *f;
+
+			if (!vstr)
+				vstr = (char *)"perf.log";
+
+			f = fopen(vstr, "a");
+			if (!f) {
+				pr_err("Can not create log file: %s\n",
+				       strerror(errno));
+				free(dstr);
+				return -1;
+			}
+			fprintf(f, "\n===========perf log===========\n");
+			set_log_output(f);
+		} else {
 			fprintf(stderr, "unkown debug option '%s'\n", opt);
 			free(dstr);
 			return -1;
-- 
2.20.1

Re: [PATCH v7 0/2] perf: add support for logging debug messages to file

[Andi Kleen]

Changbin Du <changbin.du@gmail.com> writes:

> When in TUI mode, it is impossible to show all the debug messages to
> console. This make it hard to debug perf issues using debug messages.
> This patch adds support for logging debug messages to file to resolve
> this problem.

This was already solved in

commit f78eaef0e0493f6068777a246b9c4d9d5cf2b7aa
Author: Andi Kleen <ak@linux.intel.com>
Date:   Fri Nov 21 13:38:00 2014 -0800

    perf tools: Allow to force redirect pr_debug to stderr.

    When debugging the tui browser I find it useful to redirect the
    debug
        log into a file. Currently it's always forced to the message
    line.

    Add an option to force it to stderr. Then it can be easily
    redirected.
    
You can do

perf report --debug stderr 2> file ...

-Andi

Re: [PATCH v7 0/2] perf: add support for logging debug messages to file

[Changbin Du]

On Tue, Nov 26, 2019 at 12:19:11PM -0800, Andi Kleen wrote:
> Changbin Du <changbin.du@gmail.com> writes:
> 
> > When in TUI mode, it is impossible to show all the debug messages to
> > console. This make it hard to debug perf issues using debug messages.
> > This patch adds support for logging debug messages to file to resolve
> > this problem.
> 
> This was already solved in
> 
> commit f78eaef0e0493f6068777a246b9c4d9d5cf2b7aa
> Author: Andi Kleen <ak@linux.intel.com>
> Date:   Fri Nov 21 13:38:00 2014 -0800
> 
>     perf tools: Allow to force redirect pr_debug to stderr.
> 
>     When debugging the tui browser I find it useful to redirect the
>     debug
>         log into a file. Currently it's always forced to the message
>     line.
> 
>     Add an option to force it to stderr. Then it can be easily
>     redirected.
>     
> You can do
> 
> perf report --debug stderr 2> file ...
>
Yes, this is a good alternate approach with existing code. I still think
a new option 'file' is not bad. And later maybe we can ouput debug messages
to file only while errors ouput to both.

> -Andi

-- 
Cheers,
Changbin Du