perf record: Allow multiple recording time ranges

AUX area traces can produce too much data to record successfully or
analyze subsequently. Add another means to reduce data collection by
allowing multiple recording time ranges.

This is useful, for instance, in cases where a workload produces
predictably reproducible events in specific time ranges.

Today we only have perf record -D <msecs> to start at a specific region, or
some complicated approach using snapshot mode and external scripts sending
signals or using the fifos. But these approaches are difficult to set up
compared with simply having perf do it.

Extend perf record option -D/--delay option to specifying relative time
stamps for start stop controlled by perf with the right time offset, for
instance:

    perf record -e intel_pt// -D 10-20,30-40

to record 10ms to 20ms into the trace and 30ms to 40ms.

Example:

 The example workload is:

 $ cat repeat-usleep.c

 int usleep(useconds_t usec);

 int usage(int ret, const char *msg)
 {
         if (msg)
                 fprintf(stderr, "%s\n", msg);

         fprintf(stderr, "Usage is: repeat-usleep <microseconds>\n");

         return ret;
 }

 int main(int argc, char *argv[])
 {
         unsigned long usecs;
         char *end_ptr;

         if (argc != 2)
                 return usage(1, "Error: Wrong number of arguments!");

         errno = 0;
         usecs = strtoul(argv[1], &end_ptr, 0);
         if (errno || *end_ptr || usecs > UINT_MAX)
                 return usage(1, "Error: Invalid argument!");

         while (1) {
                 int ret = usleep(usecs);

                 if (ret & errno != EINTR)
                         return usage(1, "Error: usleep() failed!");
         }

         return 0;
 }

 $ perf record -e intel_pt//u --delay 10-20,40-70,110-160 -- ./repeat-usleep 500
 Events disabled
 Events enabled
 Events disabled
 Events enabled
 Events disabled
 Events enabled
 Events disabled
 [ perf record: Woken up 5 times to write data ]
 [ perf record: Captured and wrote 0.204 MB perf.data ]
 Terminated

 A dlfilter is used to determine continuous data collection (timestamps
 less than 1ms apart):

 $ cat dlfilter-show-delays.c

 static __u64 start_time;
 static __u64 last_time;

 int start(void **data, void *ctx)
 {
         printf("%-17s\t%-9s\t%-6s\n", " Time", " Duration", " Delay");
         return 0;
 }

 int filter_event_early(void *data, const struct perf_dlfilter_sample *sample, void *ctx)
 {
         __u64 delta;

         if (!sample->time)
                 return 1;
         if (!last_time)
                 goto out;
         delta = sample->time - last_time;
         if (delta < 1000000)
                 goto out2;;
         printf("%17.9f\t%9.1f\t%6.1f\n", start_time / 1000000000.0, (last_time - start_time) / 1000000.0, delta / 1000000.0);
 out:
         start_time = sample->time;
 out2:
         last_time = sample->time;
         return 1;
 }

 int stop(void *data, void *ctx)
 {
         printf("%17.9f\t%9.1f\n", start_time / 1000000000.0, (last_time - start_time) / 1000000.0);
         return 0;
 }

 The result shows the times roughly match the --delay option:

 $ perf script --itrace=qb --dlfilter dlfilter-show-delays.so
  Time                    Duration        Delay
   39215.302317300             9.7         20.5
   39215.332480217            30.4         40.9
   39215.403837717            49.8

Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexey Bayduraev <alexey.v.bayduraev@linux.intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: Ian Rogers <irogers@google.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: https://lore.kernel.org/r/20220824072814.16422-6-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

1 files changed, 22 insertions, 2 deletions

diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index f6204b8f8a06..df83dd436bdb 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -2502,6 +2502,10 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 		}
 	}
 
+	err = event_enable_timer__start(rec->evlist->eet);
+	if (err)
+		goto out_child;
+
 	trigger_ready(&auxtrace_snapshot_trigger);
 	trigger_ready(&switch_output_trigger);
 	perf_hooks__invoke_record_start();
@@ -2625,6 +2629,14 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
 			}
 		}
 
+		err = event_enable_timer__process(rec->evlist->eet);
+		if (err < 0)
+			goto out_child;
+		if (err) {
+			err = 0;
+			done = 1;
+		}
+
 		/*
 		 * When perf is starting the traced process, at the end events
 		 * die with the process and we wait for that. Thus no need to
@@ -2846,6 +2858,12 @@ static int perf_record_config(const char *var, const char *value, void *cb)
 	return 0;
 }
 
+static int record__parse_event_enable_time(const struct option *opt, const char *str, int unset)
+{
+	struct record *rec = (struct record *)opt->value;
+
+	return evlist__parse_event_enable_time(rec->evlist, &rec->opts, str, unset);
+}
 
 static int record__parse_affinity(const struct option *opt, const char *str, int unset)
 {
@@ -3307,8 +3325,10 @@ static struct option __record_options[] = {
 	OPT_CALLBACK('G', "cgroup", &record.evlist, "name",
 		     "monitor event in cgroup name only",
 		     parse_cgroups),
-	OPT_INTEGER('D', "delay", &record.opts.initial_delay,
-		  "ms to wait before starting measurement after program start (-1: start with events disabled)"),
+	OPT_CALLBACK('D', "delay", &record, "ms",
+		     "ms to wait before starting measurement after program start (-1: start with events disabled), "
+		     "or ranges of time to enable events e.g. '-D 10-20,30-40'",
+		     record__parse_event_enable_time),
 	OPT_BOOLEAN(0, "kcore", &record.opts.kcore, "copy /proc/kcore"),
 	OPT_STRING('u', "uid", &record.opts.target.uid_str, "user",
 		   "user to profile"),