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

[Jiri Olsa]

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@xxxxxxxxx>
> 
> --
> 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

> -		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

> +
> +			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?

jirka

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