perf tools: Add switch-output size and time threshold options

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

  $ perf record --switch-output=2G ...
  [ perf record: dump data: Woken up 7244 times ]
  [ perf record: Dump perf.data.2017010214093746 ]
  ...

The size is expected to be a number with appended unit character - B/K/M/G.

Signed-off-by Jiri Olsa <[email protected]>

Cc David Ahern <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Peter Zijlstra <[email protected]>

Cc Wang Nan <[email protected]>

Link http://lkml.kernel.org/n/[email protected] open here

---
 tools/perf/Documentation/perf-record.txt |  7 +++-
 tools/perf/builtin-record.c              | 66 ++++++++++++++++++++++++++------
 2 files changed, 59 insertions(+), 14 deletions(-)

tools/perf/Documentation/perf-record.txt +5 -2

index 5054d9147f0f..d838354df417 100644
@@ -421,9 +421,12 @@ Configure all used events to run in user space.
 --timestamp-filename
 Append timestamp to output file name.
 
---switch-output::
+--switch-output[=mode]::
 Generate multiple perf.data files, timestamp prefixed, switching to a new one
-when receiving a SIGUSR2.
+based on 'mode' value:
+  "signal" - when receiving a SIGUSR2 (default value) or
+  <size>   - when reaching the size threshold, size is expected to
+             be a number with appended unit character - B/K/M/G
 
 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

tools/perf/builtin-record.c +54 -12

index b503e5ebc1e7..42321a0fa80e 100644
@@ -47,7 +47,9 @@
 #include <linux/time64.h>
 
 struct switch_output {
+	bool		 enabled;
 	bool		 signal;
+	unsigned long	 size;
 	const char	*str;
 	bool		 set;
 };

@@ -72,6 +74,23 @@ struct record {
 	unsigned long long	samples;
 };
 
+static volatile int auxtrace_record__snapshot_started;
+static DEFINE_TRIGGER(auxtrace_snapshot_trigger);
+static DEFINE_TRIGGER(switch_output_trigger);
+
+static bool switch_output_signal(struct record *rec)
+{
+	return rec->switch_output.signal &&
+	       trigger_is_ready(&switch_output_trigger);
+}
+
+static bool switch_output_size(struct record *rec)
+{
+	return rec->switch_output.size &&
+	       trigger_is_ready(&switch_output_trigger) &&
+	       (rec->bytes_written >= rec->switch_output.size);
+}
+
 static int record__write(struct record *rec, void *bf, size_t size)
 {
 	if (perf_data_file__write(rec->session->file, bf, size) < 0) {

@@ -80,6 +99,10 @@ static int record__write(struct record *rec, void *bf, size_t size)
 	}
 
 	rec->bytes_written += size;
+
+	if (switch_output_size(rec))
+		trigger_hit(&switch_output_trigger);
+
 	return 0;
 }
 

@@ -199,10 +222,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_trigger);
-static DEFINE_TRIGGER(switch_output_trigger);
-
 static void sig_handler(int sig)
 {
 	if (sig == SIGCHLD)

@@ -848,11 +867,11 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	signal(SIGTERM, sig_handler);
 	signal(SIGSEGV, sigsegv_handler);
 
-	if (rec->opts.auxtrace_snapshot_mode || rec->switch_output.signal) {
+	if (rec->opts.auxtrace_snapshot_mode || rec->switch_output.enabled) {
 		signal(SIGUSR2, snapshot_sig_handler);
 		if (rec->opts.auxtrace_snapshot_mode)
 			trigger_on(&auxtrace_snapshot_trigger);
-		if (rec->switch_output.signal)
+		if (rec->switch_output.enabled)
 			trigger_on(&switch_output_trigger);
 	} else {
 		signal(SIGUSR2, SIG_IGN);

@@ -1360,13 +1379,33 @@ static int record__parse_mmap_pages(const struct option *opt,
 
 static int switch_output_setup(struct switch_output *s)
 {
+	unsigned long val;
+	static struct parse_tag tags_size[] = {
+		{ .tag  = 'B', .mult = 1       },
+		{ .tag  = 'K', .mult = 1 << 10 },
+		{ .tag  = 'M', .mult = 1 << 20 },
+		{ .tag  = 'G', .mult = 1 << 30 },
+		{ .tag  = 0 },
+	};
+
 	if (!strcmp(s->str, "signal")) {
 		s->signal = true;
 		pr_debug("switch-output with SIGUSR2 signal\n");
-		return 0;
+		goto enabled;
+	}
+
+	val = parse_tag_value(s->str, tags_size);
+	if (val != (unsigned long) -1) {
+		s->size = val;
+		pr_debug("switch-output with %s size threshold\n", s->str);
+		goto enabled;
 	}
 
 	return -1;
+
+enabled:
+	s->enabled = true;
+	return 0;
 }
 
 static const char * const __record_usage[] = {

@@ -1537,8 +1576,9 @@ static struct option __record_options[] = {
 	OPT_BOOLEAN(0, "timestamp-filename", &record.timestamp_filename,
 		    "append timestamp to output filename"),
 	OPT_STRING_OPTARG_SET(0, "switch-output", &record.switch_output.str,
-			  &record.switch_output.set, "signal",
-			  "Switch output when receive SIGUSR2", "signal"),
+			  &record.switch_output.set, "signal,size",
+			  "Switch output when receive SIGUSR2 or cross size threshold",
+			  "signal"),
 	OPT_BOOLEAN(0, "dry-run", &dry_run,
 		    "Parse options then exit"),
 	OPT_END()

@@ -1602,7 +1642,7 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 		return -EINVAL;
 	}
 
-	if (rec->switch_output.signal)
+	if (rec->switch_output.enabled)
 		rec->timestamp_filename = true;
 
 	if (!rec->itr) {

@@ -1653,7 +1693,7 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 
 	if (rec->no_buildid_cache || rec->no_buildid) {
 		disable_buildid_cache();
-	} else if (rec->switch_output.signal) {
+	} else if (rec->switch_output.enabled) {
 		/*
 		 * In 'perf record --switch-output', disable buildid
 		 * generation by default to reduce data file switching

@@ -1745,6 +1785,8 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 
 static void snapshot_sig_handler(int sig __maybe_unused)
 {
+	struct record *rec = &record;
+
 	if (trigger_is_ready(&auxtrace_snapshot_trigger)) {
 		trigger_hit(&auxtrace_snapshot_trigger);
 		auxtrace_record__snapshot_started = 1;

@@ -1752,6 +1794,6 @@ static void snapshot_sig_handler(int sig __maybe_unused)
 			trigger_error(&auxtrace_snapshot_trigger);
 	}
 
-	if (trigger_is_ready(&switch_output_trigger))
+	if (switch_output_signal(rec))
 		trigger_hit(&switch_output_trigger);
 }

Signature · 1 line

2.7.4

Em Tue, Jan 03, 2017 at 09:19:59AM +0100, Jiri Olsa escreveu:

Quoted 7 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

s/does/goes/g

But:

[root@jouet ~]# perf record -F9000 -a --switch-output=1K sleep 5 [ perf record: dump data: Woken up 0 times ]
[ perf record: Dump perf.data.2017010311185502 ]
[ perf record: dump data: Woken up 1 times ]
[ perf record: Dump perf.data.2017010311190003 ]
[ perf record: Woken up 0 times to write data ]
[ perf record: Dump perf.data.2017010311190020 ]
[ perf record: Captured and wrote 2.240 MB perf.data.<timestamp> ] [root@jouet ~]# ls -larth perf.data.*

(quoted diff) +0 -5

-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311181984
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311182002
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311185502
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190003
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190020

[root@jouet ~]#

What is that I am missing?

- Arnaldo

Quoted 196 lines

  $ perf record --switch-output=2G ...
  [ perf record: dump data: Woken up 7244 times ]
  [ perf record: Dump perf.data.2017010214093746 ]
  ...

The size is expected to be a number with appended unit character - B/K/M/G.

Signed-off-by Jiri Olsa <[email protected]>

Cc David Ahern <[email protected]>

Cc Namhyung Kim <[email protected]>

Cc Peter Zijlstra <[email protected]>

Cc Wang Nan <[email protected]>

Link http://lkml.kernel.org/n/[email protected] open here

---
 tools/perf/Documentation/perf-record.txt |  7 +++-
 tools/perf/builtin-record.c              | 66 ++++++++++++++++++++++++++------
 2 files changed, 59 insertions(+), 14 deletions(-)

tools/perf/Documentation/perf-record.txt +5 -2

index 5054d9147f0f..d838354df417 100644
@@ -421,9 +421,12 @@ Configure all used events to run in user space.
 --timestamp-filename
 Append timestamp to output file name.
 
---switch-output::
+--switch-output[=mode]::
 Generate multiple perf.data files, timestamp prefixed, switching to a new one
-when receiving a SIGUSR2.
+based on 'mode' value:
+  "signal" - when receiving a SIGUSR2 (default value) or
+  <size>   - when reaching the size threshold, size is expected to
+             be a number with appended unit character - B/K/M/G
 
 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

tools/perf/builtin-record.c +54 -12

index b503e5ebc1e7..42321a0fa80e 100644
@@ -47,7 +47,9 @@
 #include <linux/time64.h>
 
 struct switch_output {
+	bool		 enabled;
 	bool		 signal;
+	unsigned long	 size;
 	const char	*str;
 	bool		 set;
 };

@@ -72,6 +74,23 @@ struct record {
 	unsigned long long	samples;
 };
 
+static volatile int auxtrace_record__snapshot_started;
+static DEFINE_TRIGGER(auxtrace_snapshot_trigger);
+static DEFINE_TRIGGER(switch_output_trigger);
+
+static bool switch_output_signal(struct record *rec)
+{
+	return rec->switch_output.signal &&
+	       trigger_is_ready(&switch_output_trigger);
+}
+
+static bool switch_output_size(struct record *rec)
+{
+	return rec->switch_output.size &&
+	       trigger_is_ready(&switch_output_trigger) &&
+	       (rec->bytes_written >= rec->switch_output.size);
+}
+
 static int record__write(struct record *rec, void *bf, size_t size)
 {
 	if (perf_data_file__write(rec->session->file, bf, size) < 0) {

@@ -80,6 +99,10 @@ static int record__write(struct record *rec, void *bf, size_t size)
 	}
 
 	rec->bytes_written += size;
+
+	if (switch_output_size(rec))
+		trigger_hit(&switch_output_trigger);
+
 	return 0;
 }
 

@@ -199,10 +222,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_trigger);
-static DEFINE_TRIGGER(switch_output_trigger);
-
 static void sig_handler(int sig)
 {
 	if (sig == SIGCHLD)

@@ -848,11 +867,11 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 	signal(SIGTERM, sig_handler);
 	signal(SIGSEGV, sigsegv_handler);
 
-	if (rec->opts.auxtrace_snapshot_mode || rec->switch_output.signal) {
+	if (rec->opts.auxtrace_snapshot_mode || rec->switch_output.enabled) {
 		signal(SIGUSR2, snapshot_sig_handler);
 		if (rec->opts.auxtrace_snapshot_mode)
 			trigger_on(&auxtrace_snapshot_trigger);
-		if (rec->switch_output.signal)
+		if (rec->switch_output.enabled)
 			trigger_on(&switch_output_trigger);
 	} else {
 		signal(SIGUSR2, SIG_IGN);

@@ -1360,13 +1379,33 @@ static int record__parse_mmap_pages(const struct option *opt,
 
 static int switch_output_setup(struct switch_output *s)
 {
+	unsigned long val;
+	static struct parse_tag tags_size[] = {
+		{ .tag  = 'B', .mult = 1       },
+		{ .tag  = 'K', .mult = 1 << 10 },
+		{ .tag  = 'M', .mult = 1 << 20 },
+		{ .tag  = 'G', .mult = 1 << 30 },
+		{ .tag  = 0 },
+	};
+
 	if (!strcmp(s->str, "signal")) {
 		s->signal = true;
 		pr_debug("switch-output with SIGUSR2 signal\n");
-		return 0;
+		goto enabled;
+	}
+
+	val = parse_tag_value(s->str, tags_size);
+	if (val != (unsigned long) -1) {
+		s->size = val;
+		pr_debug("switch-output with %s size threshold\n", s->str);
+		goto enabled;
 	}
 
 	return -1;
+
+enabled:
+	s->enabled = true;
+	return 0;
 }
 
 static const char * const __record_usage[] = {

@@ -1537,8 +1576,9 @@ static struct option __record_options[] = {
 	OPT_BOOLEAN(0, "timestamp-filename", &record.timestamp_filename,
 		    "append timestamp to output filename"),
 	OPT_STRING_OPTARG_SET(0, "switch-output", &record.switch_output.str,
-			  &record.switch_output.set, "signal",
-			  "Switch output when receive SIGUSR2", "signal"),
+			  &record.switch_output.set, "signal,size",
+			  "Switch output when receive SIGUSR2 or cross size threshold",
+			  "signal"),
 	OPT_BOOLEAN(0, "dry-run", &dry_run,
 		    "Parse options then exit"),
 	OPT_END()

@@ -1602,7 +1642,7 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 		return -EINVAL;
 	}
 
-	if (rec->switch_output.signal)
+	if (rec->switch_output.enabled)
 		rec->timestamp_filename = true;
 
 	if (!rec->itr) {

@@ -1653,7 +1693,7 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 
 	if (rec->no_buildid_cache || rec->no_buildid) {
 		disable_buildid_cache();
-	} else if (rec->switch_output.signal) {
+	} else if (rec->switch_output.enabled) {
 		/*
 		 * In 'perf record --switch-output', disable buildid
 		 * generation by default to reduce data file switching

@@ -1745,6 +1785,8 @@ int cmd_record(int argc, const char **argv, const char *prefix __maybe_unused)
 
 static void snapshot_sig_handler(int sig __maybe_unused)
 {
+	struct record *rec = &record;
+
 	if (trigger_is_ready(&auxtrace_snapshot_trigger)) {
 		trigger_hit(&auxtrace_snapshot_trigger);
 		auxtrace_record__snapshot_started = 1;

@@ -1752,6 +1794,6 @@ static void snapshot_sig_handler(int sig __maybe_unused)
 			trigger_error(&auxtrace_snapshot_trigger);
 	}
 
-	if (trigger_is_ready(&switch_output_trigger))
+	if (switch_output_signal(rec))
 		trigger_hit(&switch_output_trigger);
 }

Signature · 1 line

2.7.4

Em Tue, Jan 03, 2017 at 09:19:59AM +0100, Jiri Olsa escreveu:

Quoted 7 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

s/does/goes/g

But:

[root@jouet ~]# perf record -F9000 -a --switch-output=1K sleep 5 [ perf record: dump data: Woken up 0 times ]
[ perf record: Dump perf.data.2017010311185502 ]
[ perf record: dump data: Woken up 1 times ]
[ perf record: Dump perf.data.2017010311190003 ]
[ perf record: Woken up 0 times to write data ]
[ perf record: Dump perf.data.2017010311190020 ]
[ perf record: Captured and wrote 2.240 MB perf.data.<timestamp> ] [root@jouet ~]# ls -larth perf.data.*

(quoted diff) +0 -5

-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311181984
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311182002
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311185502
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190003
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190020

[root@jouet ~]#

What is that I am missing?

Quoted 29 lines

Em Tue, Jan 03, 2017 at 09:19:59AM +0100, Jiri Olsa escreveu:

Quoted 7 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

s/does/goes/g

But:

[root@jouet ~]# perf record -F9000 -a --switch-output=1K sleep 5 [ perf record: dump data: Woken up 0 times ]
[ perf record: Dump perf.data.2017010311185502 ]
[ perf record: dump data: Woken up 1 times ]
[ perf record: Dump perf.data.2017010311190003 ]
[ perf record: Woken up 0 times to write data ]
[ perf record: Dump perf.data.2017010311190020 ]
[ perf record: Captured and wrote 2.240 MB perf.data.<timestamp> ] [root@jouet ~]# ls -larth perf.data.*

(quoted diff) +0 -5

-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311181984
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311182002
-rw-------. 1 root root 2.3M Jan  3 11:18 perf.data.2017010311185502
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190003
-rw-------. 1 root root 2.3M Jan  3 11:19 perf.data.2017010311190020

[root@jouet ~]#

Quoted 1 line

What is that I am missing?

hum, I think the size you configured is smaller then the size of the shared kernel buffer and perf gets woken up by default only when we cross some level of data that's in.. would need to check

also I dont think 1K won't fit even the perf.data header.. are you trying to break it? ;-)

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

Quoted 7 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

How about something like max-file-size instead of switch-output?

Em Tue, Jan 03, 2017 at 08:33:35AM -0700, David Ahern escreveu:

Quoted 9 lines · Jiri Olsa

Quoted 7 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

Quoted 1 line

How about something like max-file-size instead of switch-output?

Well, I think he wants to use the "switch-output" semantic, which will go on "slicing" the output into multiple files according to the specified criteria, be it the existing signal one or a file size.

"max-file-size" looks like a hard limit, no hint about producing multiple files.

Quoted 7 lines · Arnaldo Carvalho de Melo

Em Tue, Jan 03, 2017 at 08:33:35AM -0700, David Ahern escreveu:

Quoted 6 lines · Jiri Olsa

Quoted 5 lines

It's now possible to specify the threshold size for perf.data like:

  $ perf record --switch-output=2G ...

Quoted 8 lines

Quoted 4 lines

Quoted 2 lines

Once it's reached, the current data are dumped in to the perf.data.<timestamp> file and session does on.

How about something like max-file-size instead of switch-output?

Well, I think he wants to use the "switch-output" semantic, which will go on "slicing" the output into multiple files according to the specified criteria, be it the existing signal one or a file size.

Quoted 3 lines

"max-file-size" looks like a hard limit, no hint about producing multiple files.

Sure, my point is that switch-output is an odd name for the option.

file-slice?

hi,
adding a way to configure switch data output
for size and time, like:

   $ sudo perf record -e 'sched:*' --switch-output=10M -avg
   callchain: type FP
   switch-output with 10M size threshold
   mmap size 528384B
   [ perf record: dump data: Woken up 37 times ]
   [ perf record: Dump perf.data.2017010309135512 ]
   [ perf record: dump data: Woken up 39 times ]
   [ perf record: Dump perf.data.2017010309135771 ]
   [ perf record: dump data: Woken up 38 times ]
   [ perf record: Dump perf.data.2017010309140005 ]
   ^C[ perf record: Woken up 16 times to write data ]
   [ perf record: Dump perf.data.2017010309140111 ]
   [ perf record: Captured and wrote 4.748 MB perf.data.<timestamp> ]
   ...

the default for switch-output option stays
and does the SIGUSR2 output switch

Also available in:
git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf.git
perf/fixes

thanks,
jirka

Cc Wang Nan <[email protected]>

---

Jiri Olsa (7):
tools lib subcmd: Add OPT_STRING_OPTARG_SET option perf record: Make __record_options static
perf record: Fix --switch-output documentation and comment perf record: Add struct switch_output
perf record: Change switch-output option to take optional argument perf record: Add switch-output size option argument perf record: Add switch-output time option argument

  tools/lib/subcmd/parse-options.c         |   3 ++
  tools/lib/subcmd/parse-options.h         |   5 ++++
  tools/perf/Documentation/perf-record.txt |  13 +++++++--
  tools/perf/builtin-record.c              | 134 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++----------
  4 files changed, 139 insertions(+), 16 deletions(-)

Quoted 30 lines · Jiri Olsa

hi,
adding a way to configure switch data output
for size and time, like:

   $ sudo perf record -e 'sched:*' --switch-output=10M -avg
   callchain: type FP
   switch-output with 10M size threshold
   mmap size 528384B
   [ perf record: dump data: Woken up 37 times ]
   [ perf record: Dump perf.data.2017010309135512 ]
   [ perf record: dump data: Woken up 39 times ]
   [ perf record: Dump perf.data.2017010309135771 ]
   [ perf record: dump data: Woken up 38 times ]
   [ perf record: Dump perf.data.2017010309140005 ]
   ^C[ perf record: Woken up 16 times to write data ]
   [ perf record: Dump perf.data.2017010309140111 ]
   [ perf record: Captured and wrote 4.748 MB perf.data.<timestamp> ]
   ...

the default for switch-output option stays
and does the SIGUSR2 output switch

Also available in:
git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf.git
perf/fixes

thanks,
jirka

Quoted 2 lines

Cc Wang Nan <[email protected]>

---

Good functions, and thank you for fixing documentations.

You didn't cc patch 1 and 2 to me.

Quoted 2 lines

Cc Wang Nan <[email protected]>

---

Good functions, and thank you for fixing documentations.

You didn't cc patch 1 and 2 to me.

Tested-by Wang Nan <[email protected]>

Em Tue, Jan 03, 2017 at 05:51:46PM +0800, Wangnan (F) escreveu:

Quoted 4 lines · Jiri Olsa

Quoted 2 lines

Cc Wang Nan <[email protected]>

---

Quoted 5 lines

Good functions, and thank you for fixing documentations.

You didn't cc patch 1 and 2 to me.

Tested-by Wang Nan <[email protected]>

I'm tentatively switching this to an Acked-by for the latest version from Jiri, that should have no major changes, right?