[PATCH v5 0/6] perf tools: Use SIGUSR2 control data dumpping

[PATCH v5 0/6] perf tools: Use SIGUSR2 control data dumpping

[Wang Nan]

v4 -> v5: 'PROCESSING' state has only one user. Remove it to
          reduce confusion.

Cc: Wang Nan <wangnan0@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: He Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com

Wang Nan (6):
  perf tools: Derive trigger class from auxtrace_snapshot
  perf record: Split output into multiple files via '--switch-output'
  perf record: Force enable --timestamp-filename when --switch-output is
    provided
  perf record: Disable buildid cache options by default in switch output
    mode
  perf record: Re-synthesize tracking events after output switching
  perf record: Generate tracking events for process forked by perf

 tools/perf/Documentation/perf-record.txt |  13 +++
 tools/perf/builtin-record.c              | 174 +++++++++++++++++++++----------
 tools/perf/util/trigger.h                | 109 +++++++++++++++++++
 3 files changed, 241 insertions(+), 55 deletions(-)
 create mode 100644 tools/perf/util/trigger.h

-- 
1.8.3.4

[PATCH v5 1/6] perf tools: Derive trigger class from auxtrace_snapshot

[Wang Nan]

Use 'trigger' to model operations which need to be executed when
an event (a signal, for example) is observed.

States and transits:

 OFF--(on)--> READY --(toggle)--> TOGGLED
                ^                    |
                |                 (ready)
                |                    |
                 \__________________/

is_toggled and is_ready are two key functions to query the state of
a trigger. is_toggled means the event already happen; is_ready means the
trigger is waiting for the event.

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: He Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
---
 tools/perf/builtin-record.c |  67 +++++++--------------------
 tools/perf/util/trigger.h   | 109 ++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 126 insertions(+), 50 deletions(-)
 create mode 100644 tools/perf/util/trigger.h

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 5b4758a..ad37f69 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -34,6 +34,7 @@
 #include "util/parse-regs-options.h"
 #include "util/llvm-utils.h"
 #include "util/bpf-loader.h"
+#include "util/trigger.h"
 #include "asm/bug.h"
 
 #include <unistd.h>
@@ -127,44 +128,8 @@ static volatile int done;
 static volatile int signr = -1;
 static volatile int child_finished;
 
-static volatile enum {
-	AUXTRACE_SNAPSHOT_OFF = -1,
-	AUXTRACE_SNAPSHOT_DISABLED = 0,
-	AUXTRACE_SNAPSHOT_ENABLED = 1,
-} auxtrace_snapshot_state = AUXTRACE_SNAPSHOT_OFF;
-
-static inline void
-auxtrace_snapshot_on(void)
-{
-	auxtrace_snapshot_state = AUXTRACE_SNAPSHOT_DISABLED;
-}
-
-static inline void
-auxtrace_snapshot_enable(void)
-{
-	if (auxtrace_snapshot_state == AUXTRACE_SNAPSHOT_OFF)
-		return;
-	auxtrace_snapshot_state = AUXTRACE_SNAPSHOT_ENABLED;
-}
-
-static inline void
-auxtrace_snapshot_disable(void)
-{
-	if (auxtrace_snapshot_state == AUXTRACE_SNAPSHOT_OFF)
-		return;
-	auxtrace_snapshot_state = AUXTRACE_SNAPSHOT_DISABLED;
-}
-
-static inline bool
-auxtrace_snapshot_is_enabled(void)
-{
-	if (auxtrace_snapshot_state == AUXTRACE_SNAPSHOT_OFF)
-		return false;
-	return auxtrace_snapshot_state == AUXTRACE_SNAPSHOT_ENABLED;
-}
-
-static volatile int auxtrace_snapshot_err;
 static volatile int auxtrace_record__snapshot_started;
+static DEFINE_TRIGGER(auxtrace_snapshot);
 
 static void sig_handler(int sig)
 {
@@ -282,11 +247,12 @@ static void record__read_auxtrace_snapshot(struct record *rec)
 {
 	pr_debug("Recording AUX area tracing snapshot\n");
 	if (record__auxtrace_read_snapshot_all(rec) < 0) {
-		auxtrace_snapshot_err = -1;
+		auxtrace_snapshot_error();
 	} else {
-		auxtrace_snapshot_err = auxtrace_record__snapshot_finish(rec->itr);
-		if (!auxtrace_snapshot_err)
-			auxtrace_snapshot_enable();
+		if (auxtrace_record__snapshot_finish(rec->itr))
+			auxtrace_snapshot_error();
+		else
+			auxtrace_snapshot_ready();
 	}
 }
 
@@ -815,21 +781,21 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		perf_evlist__enable(rec->evlist);
 	}
 
-	auxtrace_snapshot_enable();
+	auxtrace_snapshot_ready();
 	for (;;) {
 		unsigned long long hits = rec->samples;
 
 		if (record__mmap_read_all(rec) < 0) {
-			auxtrace_snapshot_disable();
+			auxtrace_snapshot_error();
 			err = -1;
 			goto out_child;
 		}
 
 		if (auxtrace_record__snapshot_started) {
 			auxtrace_record__snapshot_started = 0;
-			if (!auxtrace_snapshot_err)
+			if (!auxtrace_snapshot_is_error())
 				record__read_auxtrace_snapshot(rec);
-			if (auxtrace_snapshot_err) {
+			if (auxtrace_snapshot_is_error()) {
 				pr_err("AUX area tracing snapshot failed\n");
 				err = -1;
 				goto out_child;
@@ -858,12 +824,12 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		 * disable events in this case.
 		 */
 		if (done && !disabled && !target__none(&opts->target)) {
-			auxtrace_snapshot_disable();
+			auxtrace_snapshot_off();
 			perf_evlist__disable(rec->evlist);
 			disabled = true;
 		}
 	}
-	auxtrace_snapshot_disable();
+	auxtrace_snapshot_off();
 
 	if (forks && workload_exec_errno) {
 		char msg[STRERR_BUFSIZE];
@@ -1447,9 +1413,10 @@ out_symbol_exit:
 
 static void snapshot_sig_handler(int sig __maybe_unused)
 {
-	if (!auxtrace_snapshot_is_enabled())
+	if (!auxtrace_snapshot_is_ready())
 		return;
-	auxtrace_snapshot_disable();
-	auxtrace_snapshot_err = auxtrace_record__snapshot_start(record.itr);
+	auxtrace_snapshot_toggle();
 	auxtrace_record__snapshot_started = 1;
+	if (auxtrace_record__snapshot_start(record.itr))
+		auxtrace_snapshot_error();
 }
diff --git a/tools/perf/util/trigger.h b/tools/perf/util/trigger.h
new file mode 100644
index 0000000..89a30e9
--- /dev/null
+++ b/tools/perf/util/trigger.h
@@ -0,0 +1,109 @@
+#ifndef __TRIGGER_H_
+#define __TRIGGER_H_ 1
+
+#include "util/debug.h"
+#include "asm/bug.h"
+
+/*
+ * Use trigger to model operations which need to be executed when
+ * an event (a signal, for example) is observed.
+ *
+ * States and transits:
+ *
+ *
+ *  OFF--(on)--> READY --(toggle)--> TOGGLED
+ *                 ^                    |   
+ *                 |                 (ready)
+ *                 |                    |   
+ *                  \__________________/
+ *
+ * is_toggled and is_ready are two key functions to query the state of
+ * a trigger. is_toggled means the event already happen; is_ready means the
+ * trigger is waiting for the event.
+ */
+
+struct trigger {
+	volatile enum {
+		TRIGGER_ERROR		= -2,
+		TRIGGER_OFF		= -1,
+		TRIGGER_READY		= 0,
+		TRIGGER_TOGGLED		= 1,
+	} state;
+	const char *name;
+};
+
+#define TRIGGER_WARN_ONCE(t, exp) \
+	WARN_ONCE(t->state != exp, "trigger '%s' state transist error: %d in %s()\n", \
+		  t->name, t->state, __func__)
+
+static inline bool trigger_is_available(struct trigger *t)
+{
+	return t->state >= 0;
+}
+
+static inline bool trigger_is_error(struct trigger *t)
+{
+	return t->state <= TRIGGER_ERROR;
+}
+
+static inline void trigger_on(struct trigger *t)
+{
+	TRIGGER_WARN_ONCE(t, TRIGGER_OFF);
+	t->state = TRIGGER_READY;
+}
+
+static inline void trigger_ready(struct trigger *t)
+{
+	if (!trigger_is_available(t))
+		return;
+	t->state = TRIGGER_READY;
+}
+
+static inline void trigger_toggle(struct trigger *t)
+{
+	if (!trigger_is_available(t))
+		return;
+	TRIGGER_WARN_ONCE(t, TRIGGER_READY);
+	t->state = TRIGGER_TOGGLED;
+}
+
+static inline void trigger_off(struct trigger *t)
+{
+	if (!trigger_is_available(t))
+		return;
+	t->state = TRIGGER_OFF;
+}
+
+static inline void trigger_error(struct trigger *t)
+{
+	t->state = TRIGGER_ERROR;
+}
+
+static inline bool trigger_is_ready(struct trigger *t)
+{
+	return t->state == TRIGGER_READY;
+}
+
+static inline bool trigger_is_toggled(struct trigger *t)
+{
+	return t->state == TRIGGER_TOGGLED;
+}
+
+#define __TRIGGER_VAR(n) n##_state
+#define __DEF_TRIGGER_VOID_FUNC(n, op)	\
+static inline void n##_##op(void) {trigger_##op(&__TRIGGER_VAR(n)); }
+#define __DEF_TRIGGER_BOOL_FUNC(n, op)	\
+static inline bool n##_##op(void) {return trigger_##op(&__TRIGGER_VAR(n)); }
+
+#define DEFINE_TRIGGER(n)					\
+struct trigger n##_state = {.state = TRIGGER_OFF, .name = #n};	\
+__DEF_TRIGGER_VOID_FUNC(n, on)					\
+__DEF_TRIGGER_VOID_FUNC(n, ready)				\
+__DEF_TRIGGER_VOID_FUNC(n, toggle)				\
+__DEF_TRIGGER_VOID_FUNC(n, off)					\
+__DEF_TRIGGER_VOID_FUNC(n, error)				\
+__DEF_TRIGGER_BOOL_FUNC(n, is_ready)				\
+__DEF_TRIGGER_BOOL_FUNC(n, is_toggled)				\
+__DEF_TRIGGER_BOOL_FUNC(n, is_error)
+
+#endif
-- 
1.8.3.4

Re: [PATCH v5 1/6] perf tools: Derive trigger class from auxtrace_snapshot

[Jiri Olsa]

On Mon, Apr 18, 2016 at 02:55:27PM +0000, Wang Nan wrote:

SNIP

> -static volatile int auxtrace_snapshot_err;
>  static volatile int auxtrace_record__snapshot_started;
> +static DEFINE_TRIGGER(auxtrace_snapshot);
>  
>  static void sig_handler(int sig)
>  {
> @@ -282,11 +247,12 @@ static void record__read_auxtrace_snapshot(struct record *rec)
>  {
>  	pr_debug("Recording AUX area tracing snapshot\n");
>  	if (record__auxtrace_read_snapshot_all(rec) < 0) {
> -		auxtrace_snapshot_err = -1;
> +		auxtrace_snapshot_error();
>  	} else {
> -		auxtrace_snapshot_err = auxtrace_record__snapshot_finish(rec->itr);
> -		if (!auxtrace_snapshot_err)
> -			auxtrace_snapshot_enable();
> +		if (auxtrace_record__snapshot_finish(rec->itr))
> +			auxtrace_snapshot_error();
> +		else
> +			auxtrace_snapshot_ready();
>  	}
>  }
>  
> @@ -815,21 +781,21 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
>  		perf_evlist__enable(rec->evlist);
>  	}
>  
> -	auxtrace_snapshot_enable();
> +	auxtrace_snapshot_ready();
>  	for (;;) {
>  		unsigned long long hits = rec->samples;
>  
>  		if (record__mmap_read_all(rec) < 0) {
> -			auxtrace_snapshot_disable();
> +			auxtrace_snapshot_error();
>  			err = -1;
>  			goto out_child;
>  		}
>  
>  		if (auxtrace_record__snapshot_started) {
>  			auxtrace_record__snapshot_started = 0;

I'm ok with the chenge, however what I wanted to understand
is why we need auxtrace_record__snapshot_started ;-)

could we get rid of it like in the patch below?

thanks,
jirka


---
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index ad37f6937410..e220bd5eea0e 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -128,7 +128,6 @@ static volatile int done;
 static volatile int signr = -1;
 static volatile int child_finished;
 
-static volatile int auxtrace_record__snapshot_started;
 static DEFINE_TRIGGER(auxtrace_snapshot);
 
 static void sig_handler(int sig)
@@ -791,8 +790,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 			goto out_child;
 		}
 
-		if (auxtrace_record__snapshot_started) {
-			auxtrace_record__snapshot_started = 0;
+		if (auxtrace_snapshot_is_toggled()) {
 			if (!auxtrace_snapshot_is_error())
 				record__read_auxtrace_snapshot(rec);
 			if (auxtrace_snapshot_is_error()) {
@@ -1416,7 +1414,6 @@ static void snapshot_sig_handler(int sig __maybe_unused)
 	if (!auxtrace_snapshot_is_ready())
 		return;
 	auxtrace_snapshot_toggle();
-	auxtrace_record__snapshot_started = 1;
 	if (auxtrace_record__snapshot_start(record.itr))
 		auxtrace_snapshot_error();
 }

Re: [PATCH v5 1/6] perf tools: Derive trigger class from auxtrace_snapshot

[Namhyung Kim]

Hello,

On Mon, Apr 18, 2016 at 02:55:27PM +0000, Wang Nan wrote:
> Use 'trigger' to model operations which need to be executed when
> an event (a signal, for example) is observed.
> 
> States and transits:
> 
>  OFF--(on)--> READY --(toggle)--> TOGGLED
>                 ^                    |
>                 |                 (ready)
>                 |                    |
>                  \__________________/
> 
> is_toggled and is_ready are two key functions to query the state of
> a trigger. is_toggled means the event already happen; is_ready means the
> trigger is waiting for the event.

Not sure 'toggle' is the right word in this case.  Maybe 'set/reset'
or 'ready/hit' can be used, if each operation is one-way.  But this is
not a big deal anyway.

Btw why not split this patch into two parts - introducing trigger
logic and replacing snapshot code with the trigger?


> 
> Signed-off-by: Wang Nan <wangnan0@huawei.com>
> Cc: Adrian Hunter <adrian.hunter@intel.com>
> Cc: He Kuang <hekuang@huawei.com>
> Cc: Jiri Olsa <jolsa@kernel.org>
> Cc: Masami Hiramatsu <mhiramat@kernel.org>
> Cc: Namhyung Kim <namhyung@kernel.org>
> Cc: Zefan Li <lizefan@huawei.com>
> Cc: pi3orama@163.com
> ---

[SNIP]
> +#define __TRIGGER_VAR(n) n##_state
> +#define __DEF_TRIGGER_VOID_FUNC(n, op)	\
> +static inline void n##_##op(void) {trigger_##op(&__TRIGGER_VAR(n)); }
> +#define __DEF_TRIGGER_BOOL_FUNC(n, op)	\
> +static inline bool n##_##op(void) {return trigger_##op(&__TRIGGER_VAR(n)); }
> +
> +#define DEFINE_TRIGGER(n)					\
> +struct trigger n##_state = {.state = TRIGGER_OFF, .name = #n};	\
> +__DEF_TRIGGER_VOID_FUNC(n, on)					\
> +__DEF_TRIGGER_VOID_FUNC(n, ready)				\
> +__DEF_TRIGGER_VOID_FUNC(n, toggle)				\
> +__DEF_TRIGGER_VOID_FUNC(n, off)					\
> +__DEF_TRIGGER_VOID_FUNC(n, error)				\
> +__DEF_TRIGGER_BOOL_FUNC(n, is_ready)				\
> +__DEF_TRIGGER_BOOL_FUNC(n, is_toggled)				\
> +__DEF_TRIGGER_BOOL_FUNC(n, is_error)

Why did you define all functions for each trigger variable?  Wouldn't
it be better using generic trigger code and passing the trigger instead?

Thanks,
Namhyung

[PATCH v5 2/6] perf record: Split output into multiple files via '--switch-output'

[Wang Nan]

Allow 'perf record' to split its output into multiple files.

For example:

  # ~/perf record -a --timestamp-filename --switch-output &
  [1] 10763
  # kill -s SIGUSR2 10763
  [ perf record: dump data: Woken up 1 times ]
  # [ perf record: Dump perf.data.2015122622314468 ]

  # kill -s SIGUSR2 10763
  [ perf record: dump data: Woken up 1 times ]
  # [ perf record: Dump perf.data.2015122622314762 ]

  # kill -s SIGUSR2 10763
  [ perf record: dump data: Woken up 1 times ]
  #[ perf record: Dump perf.data.2015122622315171 ]

  # fg
  perf record -a --timestamp-filename --switch-output
  ^C[ perf record: Woken up 1 times to write data ]
  [ perf record: Dump perf.data.2015122622315513 ]
  [ perf record: Captured and wrote 0.014 MB perf.data.<timestamp> (296 samples) ]

  # ls -l
  total 920
  -rw------- 1 root root 797692 Dec 26 22:31 perf.data.2015122622314468
  -rw------- 1 root root  59960 Dec 26 22:31 perf.data.2015122622314762
  -rw------- 1 root root  59912 Dec 26 22:31 perf.data.2015122622315171
  -rw------- 1 root root  19220 Dec 26 22:31 perf.data.2015122622315513

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460643725-167413-3-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang <hekuang@huawei.com>
[ Added man page entry ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/Documentation/perf-record.txt |  8 ++++++
 tools/perf/builtin-record.c              | 46 ++++++++++++++++++++++++++------
 2 files changed, 46 insertions(+), 8 deletions(-)

diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index 19aa175..a77a431 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -347,6 +347,14 @@ Configure all used events to run in kernel space.
 --all-user::
 Configure all used events to run in user space.
 
+--switch-output::
+Generate multiple perf.data files, timestamp prefixed, switching to a new one
+when receiving a SIGUSR2.
+
+A possible use case is to, given an external event, slice the perf.data file
+that gets then processed, possibly via a perf script, to decide if that
+particular perf.data snapshot should be kept or not.
+
 SEE ALSO
 --------
 linkperf:perf-stat[1], linkperf:perf-list[1]
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index ad37f69..07e57d9 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -58,6 +58,7 @@ struct record {
 	bool			no_buildid_cache_set;
 	bool			buildid_all;
 	bool			timestamp_filename;
+	bool			switch_output;
 	unsigned long long	samples;
 };
 
@@ -131,6 +132,8 @@ static volatile int child_finished;
 static volatile int auxtrace_record__snapshot_started;
 static DEFINE_TRIGGER(auxtrace_snapshot);
 
+static DEFINE_TRIGGER(switch_output);
+
 static void sig_handler(int sig)
 {
 	if (sig == SIGCHLD)
@@ -650,9 +653,12 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	signal(SIGINT, sig_handler);
 	signal(SIGTERM, sig_handler);
 
-	if (rec->opts.auxtrace_snapshot_mode) {
+	if (rec->opts.auxtrace_snapshot_mode || rec->switch_output) {
 		signal(SIGUSR2, snapshot_sig_handler);
-		auxtrace_snapshot_on();
+		if (rec->opts.auxtrace_snapshot_mode)
+			auxtrace_snapshot_on();
+		if (rec->switch_output)
+			switch_output_on();
 	} else {
 		signal(SIGUSR2, SIG_IGN);
 	}
@@ -782,11 +788,13 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	}
 
 	auxtrace_snapshot_ready();
+	switch_output_ready();
 	for (;;) {
 		unsigned long long hits = rec->samples;
 
 		if (record__mmap_read_all(rec) < 0) {
 			auxtrace_snapshot_error();
+			switch_output_error();
 			err = -1;
 			goto out_child;
 		}
@@ -802,6 +810,22 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 			}
 		}
 
+		if (switch_output_is_toggled()) {
+			switch_output_ready();
+
+			if (!quiet)
+				fprintf(stderr, "[ perf record: dump data: Woken up %ld times ]\n",
+					waking);
+			waking = 0;
+			fd = record__switch_output(rec, false);
+			if (fd < 0) {
+				pr_err("Failed to switch to new file\n");
+				switch_output_error();
+				err = fd;
+				goto out_child;
+			}
+		}
+
 		if (hits == rec->samples) {
 			if (done || draining)
 				break;
@@ -830,6 +854,7 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		}
 	}
 	auxtrace_snapshot_off();
+	switch_output_off();
 
 	if (forks && workload_exec_errno) {
 		char msg[STRERR_BUFSIZE];
@@ -1265,6 +1290,8 @@ struct option __record_options[] = {
 		    "Record build-id of all DSOs regardless of hits"),
 	OPT_BOOLEAN(0, "timestamp-filename", &record.timestamp_filename,
 		    "append timestamp to output filename"),
+	OPT_BOOLEAN(0, "switch-output", &record.switch_output,
+		    "Switch output when receive SIGUSR2"),
 	OPT_END()
 };
 
@@ -1413,10 +1440,13 @@ out_symbol_exit:
 
 static void snapshot_sig_handler(int sig __maybe_unused)
 {
-	if (!auxtrace_snapshot_is_ready())
-		return;
-	auxtrace_snapshot_toggle();
-	auxtrace_record__snapshot_started = 1;
-	if (auxtrace_record__snapshot_start(record.itr))
-		auxtrace_snapshot_error();
+	if (auxtrace_snapshot_is_ready()) {
+		auxtrace_snapshot_toggle();
+		auxtrace_record__snapshot_started = 1;
+		if (auxtrace_record__snapshot_start(record.itr))
+			auxtrace_snapshot_error();
+	}
+
+	if (switch_output_is_ready())
+		switch_output_toggle();
 }
-- 
1.8.3.4

Re: [PATCH v5 2/6] perf record: Split output into multiple files via '--switch-output'

[Jiri Olsa]

On Mon, Apr 18, 2016 at 02:55:28PM +0000, Wang Nan wrote:

SNIP

>  		    "Record build-id of all DSOs regardless of hits"),
>  	OPT_BOOLEAN(0, "timestamp-filename", &record.timestamp_filename,
>  		    "append timestamp to output filename"),
> +	OPT_BOOLEAN(0, "switch-output", &record.switch_output,
> +		    "Switch output when receive SIGUSR2"),
>  	OPT_END()
>  };
>  
> @@ -1413,10 +1440,13 @@ out_symbol_exit:
>  
>  static void snapshot_sig_handler(int sig __maybe_unused)
>  {
> -	if (!auxtrace_snapshot_is_ready())
> -		return;
> -	auxtrace_snapshot_toggle();
> -	auxtrace_record__snapshot_started = 1;
> -	if (auxtrace_record__snapshot_start(record.itr))
> -		auxtrace_snapshot_error();
> +	if (auxtrace_snapshot_is_ready()) {
> +		auxtrace_snapshot_toggle();
> +		auxtrace_record__snapshot_started = 1;
> +		if (auxtrace_record__snapshot_start(record.itr))
> +			auxtrace_snapshot_error();

Adrian,
I know it's out of the scope of this patchset, however
should auxtrace_record__snapshot_start call be in the
__cmd_record's loop path rather then in here in signal? 

thanks,
jirka

[PATCH v5 3/6] perf record: Force enable --timestamp-filename when --switch-output is provided

[Wang Nan]

Without this patch, the last output doesn't have timestamp appended if
--timestamp-filename is not explicitly provided. For example:

  # perf record -a --switch-output &
  [1] 11224
  # kill -s SIGUSR2 11224
  [ perf record: dump data: Woken up 1 times ]
  # [ perf record: Dump perf.data.2015122622372823 ]

  # fg
  perf record -a --switch-output
  ^C[ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 0.027 MB perf.data (540 samples) ]

  # ls -l
  total 836
  -rw------- 1 root root  33256 Dec 26 22:37 perf.data   <---- *Odd*
  -rw------- 1 root root 817156 Dec 26 22:37 perf.data.2015122622372823

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460643725-167413-4-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang <hekuang@huawei.com>
[ Updated man page, that also got an entry for --timestamp-filename ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/Documentation/perf-record.txt | 5 +++++
 tools/perf/builtin-record.c              | 3 +++
 2 files changed, 8 insertions(+)

diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index a77a431..79a8a14 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -347,6 +347,9 @@ Configure all used events to run in kernel space.
 --all-user::
 Configure all used events to run in user space.
 
+--timestamp-filename
+Append timestamp to output file name.
+
 --switch-output::
 Generate multiple perf.data files, timestamp prefixed, switching to a new one
 when receiving a SIGUSR2.
@@ -355,6 +358,8 @@ A possible use case is to, given an external event, slice the perf.data file
 that gets then processed, possibly via a perf script, to decide if that
 particular perf.data snapshot should be kept or not.
 
+Implies --timestamp-filename.
+
 SEE ALSO
 --------
 linkperf:perf-stat[1], linkperf:perf-list[1]
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 07e57d9..13f0b9a 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -1347,6 +1347,9 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 		return -EINVAL;
 	}
 
+	if (rec->switch_output)
+		rec->timestamp_filename = true;
+
 	if (!rec->itr) {
 		rec->itr = auxtrace_record__init(rec->evlist, &err);
 		if (err)
-- 
1.8.3.4

Re: [PATCH v5 3/6] perf record: Force enable --timestamp-filename when --switch-output is provided

[Jiri Olsa]

On Mon, Apr 18, 2016 at 02:55:29PM +0000, Wang Nan wrote:
> Without this patch, the last output doesn't have timestamp appended if
> --timestamp-filename is not explicitly provided. For example:
> 
>   # perf record -a --switch-output &
>   [1] 11224
>   # kill -s SIGUSR2 11224
>   [ perf record: dump data: Woken up 1 times ]
>   # [ perf record: Dump perf.data.2015122622372823 ]
> 
>   # fg
>   perf record -a --switch-output
>   ^C[ perf record: Woken up 1 times to write data ]
>   [ perf record: Captured and wrote 0.027 MB perf.data (540 samples) ]
> 
>   # ls -l
>   total 836
>   -rw------- 1 root root  33256 Dec 26 22:37 perf.data   <---- *Odd*
>   -rw------- 1 root root 817156 Dec 26 22:37 perf.data.2015122622372823

I'm getting this:

[root@krava perf]# ./perf record -a --switch-output &
[root@krava perf]# kill -s SIGUSR2 18974
[ perf record: dump data: Woken up 4 times ]
[ perf record: Dump perf.data.2016042009574314 ]

[root@krava perf]# ./perf report -i perf.data.2016042009574314 
perf: Segmentation fault
-------- backtrace --------
./perf[0x552b0b]
/lib64/libc.so.6(+0x34a50)[0x7f711b434a50]
/lib64/libc.so.6(strlen+0x2a)[0x7f711b48b33a]
./perf(perf_hpp__reset_sort_width+0x4f)[0x4e9b1f]
./perf[0x54b113]
./perf(perf_evlist__tui_browse_hists+0x91)[0x551361]
./perf(cmd_report+0x1a34)[0x434b44]
./perf[0x485681]
./perf(main+0x672)[0x424382]
/lib64/libc.so.6(__libc_start_main+0xf0)[0x7f711b420700]
./perf(_start+0x29)[0x4244a9]
[0x0]


thanks,
jirka

Re: [PATCH v5 3/6] perf record: Force enable --timestamp-filename when --switch-output is provided

[Wangnan (F)]

On 2016/4/20 15:59, Jiri Olsa wrote:
> On Mon, Apr 18, 2016 at 02:55:29PM +0000, Wang Nan wrote:
>> Without this patch, the last output doesn't have timestamp appended if
>> --timestamp-filename is not explicitly provided. For example:
>>
>>    # perf record -a --switch-output &
>>    [1] 11224
>>    # kill -s SIGUSR2 11224
>>    [ perf record: dump data: Woken up 1 times ]
>>    # [ perf record: Dump perf.data.2015122622372823 ]
>>
>>    # fg
>>    perf record -a --switch-output
>>    ^C[ perf record: Woken up 1 times to write data ]
>>    [ perf record: Captured and wrote 0.027 MB perf.data (540 samples) ]
>>
>>    # ls -l
>>    total 836
>>    -rw------- 1 root root  33256 Dec 26 22:37 perf.data   <---- *Odd*
>>    -rw------- 1 root root 817156 Dec 26 22:37 perf.data.2015122622372823
> I'm getting this:
>
> [root@krava perf]# ./perf record -a --switch-output &
> [root@krava perf]# kill -s SIGUSR2 18974
> [ perf record: dump data: Woken up 4 times ]
> [ perf record: Dump perf.data.2016042009574314 ]
>
> [root@krava perf]# ./perf report -i perf.data.2016042009574314
> perf: Segmentation fault
> -------- backtrace --------
> ./perf[0x552b0b]
> /lib64/libc.so.6(+0x34a50)[0x7f711b434a50]
> /lib64/libc.so.6(strlen+0x2a)[0x7f711b48b33a]
> ./perf(perf_hpp__reset_sort_width+0x4f)[0x4e9b1f]
> ./perf[0x54b113]
> ./perf(perf_evlist__tui_browse_hists+0x91)[0x551361]
> ./perf(cmd_report+0x1a34)[0x434b44]
> ./perf[0x485681]
> ./perf(main+0x672)[0x424382]
> /lib64/libc.so.6(__libc_start_main+0xf0)[0x7f711b420700]
> ./perf(_start+0x29)[0x4244a9]
> [0x0]

Can't reproduce... Can you get reproduce problem without this patch (3/6)?

My local tree is based on newest perf/core (commit ccd62a8 "perf trace:
Fix build when DWARF unwind isn't available"). Could you please check your
source?

Thank you.

>
> thanks,
> jirka

Re: [PATCH v5 3/6] perf record: Force enable --timestamp-filename when --switch-output is provided

[Jiri Olsa]

On Wed, Apr 20, 2016 at 04:21:17PM +0800, Wangnan (F) wrote:
> 
> 
> On 2016/4/20 15:59, Jiri Olsa wrote:
> >On Mon, Apr 18, 2016 at 02:55:29PM +0000, Wang Nan wrote:
> >>Without this patch, the last output doesn't have timestamp appended if
> >>--timestamp-filename is not explicitly provided. For example:
> >>
> >>   # perf record -a --switch-output &
> >>   [1] 11224
> >>   # kill -s SIGUSR2 11224
> >>   [ perf record: dump data: Woken up 1 times ]
> >>   # [ perf record: Dump perf.data.2015122622372823 ]
> >>
> >>   # fg
> >>   perf record -a --switch-output
> >>   ^C[ perf record: Woken up 1 times to write data ]
> >>   [ perf record: Captured and wrote 0.027 MB perf.data (540 samples) ]
> >>
> >>   # ls -l
> >>   total 836
> >>   -rw------- 1 root root  33256 Dec 26 22:37 perf.data   <---- *Odd*
> >>   -rw------- 1 root root 817156 Dec 26 22:37 perf.data.2015122622372823
> >I'm getting this:
> >
> >[root@krava perf]# ./perf record -a --switch-output &
> >[root@krava perf]# kill -s SIGUSR2 18974
> >[ perf record: dump data: Woken up 4 times ]
> >[ perf record: Dump perf.data.2016042009574314 ]
> >
> >[root@krava perf]# ./perf report -i perf.data.2016042009574314
> >perf: Segmentation fault
> >-------- backtrace --------
> >./perf[0x552b0b]
> >/lib64/libc.so.6(+0x34a50)[0x7f711b434a50]
> >/lib64/libc.so.6(strlen+0x2a)[0x7f711b48b33a]
> >./perf(perf_hpp__reset_sort_width+0x4f)[0x4e9b1f]
> >./perf[0x54b113]
> >./perf(perf_evlist__tui_browse_hists+0x91)[0x551361]
> >./perf(cmd_report+0x1a34)[0x434b44]
> >./perf[0x485681]
> >./perf(main+0x672)[0x424382]
> >/lib64/libc.so.6(__libc_start_main+0xf0)[0x7f711b420700]
> >./perf(_start+0x29)[0x4244a9]
> >[0x0]
> 
> Can't reproduce... Can you get reproduce problem without this patch (3/6)?
> 
> My local tree is based on newest perf/core (commit ccd62a8 "perf trace:
> Fix build when DWARF unwind isn't available"). Could you please check your
> source?

you're right.. I rebuilt on latest Arnaldo's perf/core and can't reproduce again

jirka

[PATCH v5 4/6] perf record: Disable buildid cache options by default in switch output mode

[Wang Nan]

The cost of buildid cache processing is high: reading all events in
output perf.data, opening each elf file to read buildids then copying
them into ~/.debug directory. In switch output mode, these heavy works
block perf from receiving perf events for too long.

Enable no-buildid and no-buildid-cache by default if --switch-output
is provided. Still allow user use --no-no-buildid to explicitly enable
buildid in this case.

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460643725-167413-5-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang <hekuang@huawei.com>
[ Updated man page ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/Documentation/perf-record.txt |  2 +-
 tools/perf/builtin-record.c              | 30 +++++++++++++++++++++++++++++-
 2 files changed, 30 insertions(+), 2 deletions(-)

diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index 79a8a14..8dbee83 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -358,7 +358,7 @@ A possible use case is to, given an external event, slice the perf.data file
 that gets then processed, possibly via a perf script, to decide if that
 particular perf.data snapshot should be kept or not.
 
-Implies --timestamp-filename.
+Implies --timestamp-filename, --no-buildid and --no-buildid-cache.
 
 SEE ALSO
 --------
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 13f0b9a..e4a1a3d 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -1383,8 +1383,36 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 "If some relocation was applied (e.g. kexec) symbols may be misresolved\n"
 "even with a suitable vmlinux or kallsyms file.\n\n");
 
-	if (rec->no_buildid_cache || rec->no_buildid)
+	if (rec->no_buildid_cache || rec->no_buildid) {
 		disable_buildid_cache();
+	} else if (rec->switch_output) {
+		/*
+		 * In 'perf record --switch-output', disable buildid
+		 * generation by default to reduce data file switching
+		 * overhead. Still generate buildid if they are required
+		 * explicitly using
+		 *
+		 *  perf record --signal-trigger --no-no-buildid \
+		 *              --no-no-buildid-cache
+		 *
+		 * Following code equals to:
+		 *
+		 * if ((rec->no_buildid || !rec->no_buildid_set) &&
+		 *     (rec->no_buildid_cache || !rec->no_buildid_cache_set))
+		 *         disable_buildid_cache();
+		 */
+		bool disable = true;
+
+		if (rec->no_buildid_set && !rec->no_buildid)
+			disable = false;
+		if (rec->no_buildid_cache_set && !rec->no_buildid_cache)
+			disable = false;
+		if (disable) {
+			rec->no_buildid = true;
+			rec->no_buildid_cache = true;
+			disable_buildid_cache();
+		}
+	}
 
 	if (rec->evlist->nr_entries == 0 &&
 	    perf_evlist__add_default(rec->evlist) < 0) {
-- 
1.8.3.4

[PATCH v5 5/6] perf record: Re-synthesize tracking events after output switching

[Wang Nan]

Tracking events describe kernel and threads. They are generated by
reading /proc/kallsyms, /proc/*/maps and /proc/*/task/* during
initialization of 'perf record', serialized into event sequences and put
at the head of 'perf.data'. In case of output switching, each output
file should contain those events.

This patch calls record__synthesize() during output switching, so the
event sequences described above can be collected again.

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: He Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460643725-167413-6-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang <hekuang@huawei.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/builtin-record.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index e4a1a3d..a199476 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -501,6 +501,8 @@ record__finish_output(struct record *rec)
 	return;
 }
 
+static int record__synthesize(struct record *rec);
+
 static int
 record__switch_output(struct record *rec, bool at_exit)
 {
@@ -529,6 +531,11 @@ record__switch_output(struct record *rec, bool at_exit)
 	if (!quiet)
 		fprintf(stderr, "[ perf record: Dump %s.%s ]\n",
 			file->path, timestamp);
+
+	/* Output tracking events */
+	if (!at_exit)
+		record__synthesize(rec);
+
 	return fd;
 }
 
-- 
1.8.3.4

[PATCH v5 6/6] perf record: Generate tracking events for process forked by perf

[Wang Nan]

With 'perf record --switch-output' without -a, record__synthesize() in
record__switch_output() won't generate tracking events because there's
no thread_map in evlist. Which causes newly created perf.data doesn't
contain map and comm information.

This patch creates a fake thread_map and directly call
perf_event__synthesize_thread_map() for those events.

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460643725-167413-7-git-send-email-wangnan0@huawei.com
Signed-off-by: He Kuang <hekuang@huawei.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/builtin-record.c | 31 ++++++++++++++++++++++++++++++-
 1 file changed, 30 insertions(+), 1 deletion(-)

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index a199476..7c30539 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -501,6 +501,23 @@ record__finish_output(struct record *rec)
 	return;
 }
 
+static int record__synthesize_workload(struct record *rec)
+{
+	struct {
+		struct thread_map map;
+		struct thread_map_data map_data;
+	} thread_map;
+
+	thread_map.map.nr = 1;
+	thread_map.map.map[0].pid = rec->evlist->workload.pid;
+	thread_map.map.map[0].comm = NULL;
+	return perf_event__synthesize_thread_map(&rec->tool, &thread_map.map,
+						 process_synthesized_event,
+						 &rec->session->machines.host,
+						 rec->opts.sample_address,
+						 rec->opts.proc_map_timeout);
+}
+
 static int record__synthesize(struct record *rec);
 
 static int
@@ -533,9 +550,21 @@ record__switch_output(struct record *rec, bool at_exit)
 			file->path, timestamp);
 
 	/* Output tracking events */
-	if (!at_exit)
+	if (!at_exit) {
 		record__synthesize(rec);
 
+		/*
+		 * In 'perf record --switch-output' without -a,
+		 * record__synthesize() in record__switch_output() won't
+		 * generate tracking events because there's no thread_map
+		 * in evlist. Which causes newly created perf.data doesn't
+		 * contain map and comm information.
+		 * Create a fake thread_map and directly call
+		 * perf_event__synthesize_thread_map() for those events.
+		 */
+		if (target__none(&rec->opts.target))
+			record__synthesize_workload(rec);
+	}
 	return fd;
 }
 
-- 
1.8.3.4