2019-10-04 07:59:33

by Changbin Du

[permalink] [raw]
Subject: [PATCH v3 0/2] perf: add support for logging debug messages to file

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.

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 | 15 ++--
tools/perf/util/debug.c | 124 +++++++++++++++++++-----------
2 files changed, 90 insertions(+), 49 deletions(-)

--
2.20.1


2019-10-04 07:59:45

by Changbin Du

[permalink] [raw]
Subject: [PATCH v3 1/2] perf: support multiple debug options separated by ','

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

Signed-off-by: Changbin Du <[email protected]>
---
tools/perf/Documentation/perf.txt | 10 ++--
tools/perf/util/debug.c | 86 ++++++++++++++++---------------
2 files changed, 50 insertions(+), 46 deletions(-)

diff --git a/tools/perf/Documentation/perf.txt b/tools/perf/Documentation/perf.txt
index 401f0ed67439..c05a94b2488e 100644
--- a/tools/perf/Documentation/perf.txt
+++ b/tools/perf/Documentation/perf.txt
@@ -19,11 +19,11 @@ OPTIONS
--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
+ 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

--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 e55114f0336f..df82ad9cd16d 100644
--- a/tools/perf/util/debug.c
+++ b/tools/perf/util/debug.c
@@ -26,7 +26,7 @@
int verbose;
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)
@@ -172,41 +172,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 = 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.
@@ -217,20 +194,47 @@ 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 {
+ 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

2019-10-04 08:01:55

by Changbin Du

[permalink] [raw]
Subject: [PATCH v3 2/2] perf: add support for logging debug messages to file

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 <[email protected]>

--
v3: fix a segfault issue.
---
tools/perf/Documentation/perf.txt | 15 ++++++-----
tools/perf/util/debug.c | 44 +++++++++++++++++++++++++++----
2 files changed, 48 insertions(+), 11 deletions(-)

diff --git a/tools/perf/Documentation/perf.txt b/tools/perf/Documentation/perf.txt
index c05a94b2488e..a6b19661e5c3 100644
--- a/tools/perf/Documentation/perf.txt
+++ b/tools/perf/Documentation/perf.txt
@@ -16,14 +16,17 @@ OPTIONS
Setup debug variable (see list below) in value
range (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
- 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
+ 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
+ file=path - write debug output to log file (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 df82ad9cd16d..bfb0b886266f 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>
@@ -26,7 +27,7 @@
int verbose;
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)
@@ -34,10 +35,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
- ret = vfprintf(stderr, fmt, args);
+ ret = vfprintf(log_file, fmt, args);
}

return ret;
@@ -197,6 +198,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;
@@ -218,8 +237,23 @@ 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;
- else {
+ set_log_output(stderr);
+ 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

2019-10-07 11:27:33

by Jiri Olsa

[permalink] [raw]
Subject: Re: [PATCH v3 0/2] perf: add support for logging debug messages to file

On Fri, Oct 04, 2019 at 10:39:52AM +0800, Changbin Du wrote:
> 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.
>
> v3:
> o fix a segfault issue.

heya,
getting segfault for this:

[jolsa@krava perf]$ ./perf report -vv 2>out
Segmentation fault (core dumped)

jirka

> 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 | 15 ++--
> tools/perf/util/debug.c | 124 +++++++++++++++++++-----------
> 2 files changed, 90 insertions(+), 49 deletions(-)
>
> --
> 2.20.1
>

2019-10-08 12:32:53

by Changbin Du

[permalink] [raw]
Subject: Re: [PATCH v3 0/2] perf: add support for logging debug messages to file

On Mon, Oct 07, 2019 at 01:26:24PM +0200, Jiri Olsa wrote:
> On Fri, Oct 04, 2019 at 10:39:52AM +0800, Changbin Du wrote:
> > 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.
> >
> > v3:
> > o fix a segfault issue.
>
> heya,
> getting segfault for this:
>
> [jolsa@krava perf]$ ./perf report -vv 2>out
> Segmentation fault (core dumped)
>
This can be fixed by below change. In this case, log_file is NULL.

--- a/tools/perf/util/debug.c
+++ b/tools/perf/util/debug.c
@@ -37,8 +37,10 @@ int veprintf(int level, int var, const char *fmt, va_list args)
if (var >= level) {
if (use_browser >= 1 && !log_file)
ui_helpline__vshow(fmt, args);
- else
+ else if (log_file)
ret = vfprintf(log_file, fmt, args);
+ else
+ ret = vfprintf(stderr, fmt, args);
}

return ret;



> jirka
>
> > 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 | 15 ++--
> > tools/perf/util/debug.c | 124 +++++++++++++++++++-----------
> > 2 files changed, 90 insertions(+), 49 deletions(-)
> >
> > --
> > 2.20.1
> >

--
Cheers,
Changbin Du