lkml.org 
[lkml]   [2019]   [Oct]   [15]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH v4 2/2] perf: add support for logging debug messages to file
On Mon, Oct 14, 2019 at 05:29:53PM +0200, Jiri Olsa wrote:
> On Tue, Oct 08, 2019 at 08:35:54PM +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.
> >
> > The usage is:
> > perf -debug verbose=2,file=~/perf.log COMMAND
> >
> > Signed-off-by: Changbin Du <changbin.du@gmail.com>
> >
> > --
> > v4: fix another segfault.
> > v3: fix a segfault issue.
>
> hi,
> no crash this time ;-) some questions below
>
> > ---
> > tools/perf/Documentation/perf.txt | 15 ++++++-----
> > tools/perf/util/debug.c | 44 ++++++++++++++++++++++++++++---
> > 2 files changed, 49 insertions(+), 10 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..5cc2479d63ea 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,8 +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 if (log_file)
> > + ret = vfprintf(log_file, fmt, args);
> > else
> > ret = vfprintf(stderr, fmt, args);
> > }
> > @@ -197,6 +200,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 +239,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;
>
> do you ned to fflush stderr? I thought it's unbuffered
>
Acorrding to my test, some messages are lost after ctrl-c without flusing. So
I think it is buffered by libc?

> > - else {
> > + set_log_output(stderr);
> > + else if (!strcmp(opt, "file")) {
> > + FILE *f;
> > +
> > + if (!vstr)
> > + vstr = (char *)"perf.log";
>
> you did not mention in doc that perf.log is default
>
yes, it should be mentioned.

> > +
> > + 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");
>
> is this necessary?
>
Yes, because we will append new log to existing one. So we'd beeter put a margin
there.

> jirka
>
> > + set_log_output(f);
> > + } else {
> > fprintf(stderr, "unkown debug option '%s'\n", opt);
> > free(dstr);
> > return -1;
> > --
> > 2.20.1
> >

--
Cheers,
Changbin Du

\
 
 \ /
  Last update: 2019-10-16 02:15    [W:0.061 / U:0.212 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site