LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
From: Riccardo Mancini <rickyman7@gmail.com>
To: Arnaldo Carvalho de Melo <acme@kernel.org>
Cc: Ian Rogers <irogers@google.com>,
	Namhyung Kim <namhyung@kernel.org>,
	Peter Zijlstra <peterz@infradead.org>,
	Ingo Molnar <mingo@redhat.com>,
	Mark Rutland <mark.rutland@arm.com>, Jiri Olsa <jolsa@redhat.com>,
	linux-kernel@vger.kernel.org, linux-perf-users@vger.kernel.org,
	Riccardo Mancini <rickyman7@gmail.com>
Subject: [RFC PATCH v1 37/37] perf test/evlist-open-close: add detailed output mode
Date: Sat, 21 Aug 2021 11:19:43 +0200	[thread overview]
Message-ID: <fd3d0bdaf8dfa4eedd53fbdcf8088b8211a6f191.1629490974.git.rickyman7@gmail.com> (raw)
In-Reply-To: <cover.1629490974.git.rickyman7@gmail.com>

This patch adds a detailed output mode in the perf-test
evlist-open-close. In this output mode, the time taken by each single
evlist function is computed.

Normal mode:
$ sudo ./perf bench internals evlist-open-close
  Number of workers:    1
  Number of cpus:       4
  Number of threads:    1
  Number of events:     1 (4 fds)
  Number of iterations: 100
  Average open-close took:     1199.300 usec (+-      289.699 usec)

Detailed mode:
$ sudo ./perf bench internals evlist-open-close -d
  Number of workers:    1
  Number of cpus:       4
  Number of threads:    1
  Number of events:     1 (4 fds)
  Number of iterations: 100
  Average open-close took:     1199.300 usec (+-      289.699 usec)
                init took:        0.000 usec (+-        0.000 usec)
                open took:       25.600 usec (+-        1.778 usec)
                mmap took:      532.000 usec (+-       58.133 usec)
              enable took:      337.300 usec (+-      194.160 usec)
             disable took:      181.700 usec (+-       85.307 usec)
              munmap took:       22.100 usec (+-        4.045 usec)
               close took:      100.300 usec (+-       21.329 usec)
                fini took:        0.200 usec (+-        0.133 usec)

* init and fini represent the time taken before and after the evlist
  operations (in this case the workqueue setup and teardown operations)

Signed-off-by: Riccardo Mancini <rickyman7@gmail.com>
---
 tools/perf/bench/evlist-open-close.c | 63 ++++++++++++++++++++++++++--
 1 file changed, 60 insertions(+), 3 deletions(-)

diff --git a/tools/perf/bench/evlist-open-close.c b/tools/perf/bench/evlist-open-close.c
index 00d0aef564f80d44..8ba2799c66cafb3e 100644
--- a/tools/perf/bench/evlist-open-close.c
+++ b/tools/perf/bench/evlist-open-close.c
@@ -25,12 +25,18 @@
 static int iterations = 100;
 static int nr_events = 1;
 static const char *event_string = "dummy";
+static bool detail;
 
 static inline u64 timeval2usec(struct timeval *tv)
 {
 	return tv->tv_sec * USEC_PER_SEC + tv->tv_usec;
 }
 
+struct timers {
+	struct timeval start, end, diff;
+	struct stats init, open, mmap, enable, disable, munmap, close, fini;
+};
+
 static struct record_opts opts = {
 	.sample_time	     = true,
 	.mmap_pages	     = UINT_MAX,
@@ -60,6 +66,7 @@ static const struct option options[] = {
 	OPT_STRING('u', "uid", &opts.target.uid_str, "user", "user to profile"),
 	OPT_BOOLEAN(0, "per-thread", &opts.target.per_thread, "use per-thread mmaps"),
 	OPT_UINTEGER_OPTARG('j', "threads", &opts.nr_threads, UINT_MAX, "Number of threads to use"),
+	OPT_BOOLEAN('d', "detail", &detail, "compute time taken by single functions"),
 	OPT_END()
 };
 
@@ -113,11 +120,28 @@ static struct evlist *bench__create_evlist(char *evstr)
 	return NULL;
 }
 
-static int bench__do_evlist_open_close(struct evlist *evlist)
+#define START_TIMER(timers) do { \
+	if (detail) { \
+		gettimeofday(&(timers)->start, NULL); \
+	} \
+} while (0)
+
+#define RECORD_TIMER(timers, field) do { \
+	if (detail) { \
+		gettimeofday(&(timers)->end, NULL); \
+		timersub(&(timers)->end, &(timers)->start, &(timers)->diff); \
+		update_stats(&(timers)->field, timeval2usec(&(timers)->diff)); \
+		(timers)->start = (timers)->end; \
+	} \
+} while (0)
+
+static int bench__do_evlist_open_close(struct evlist *evlist, struct timers *timers)
 {
 	char sbuf[WORKQUEUE_STRERR_BUFSIZE];
 	int err = -1, ret;
 
+	START_TIMER(timers);
+
 	if (opts.nr_threads > 1) {
 		err = setup_global_workqueue(opts.nr_threads);
 		if (err) {
@@ -130,23 +154,30 @@ static int bench__do_evlist_open_close(struct evlist *evlist)
 
 		perf_set_multithreaded();
 	}
+	RECORD_TIMER(timers, init);
 
 	err = evlist__open(evlist);
 	if (err < 0) {
 		pr_err("evlist__open: %s\n", str_error_r(errno, sbuf, sizeof(sbuf)));
 		goto out;
 	}
+	RECORD_TIMER(timers, open);
 
 	err = evlist__mmap(evlist, opts.mmap_pages);
 	if (err < 0) {
 		pr_err("evlist__mmap: %s\n", str_error_r(errno, sbuf, sizeof(sbuf)));
 		goto out;
 	}
+	RECORD_TIMER(timers, mmap);
 
 	evlist__enable(evlist);
+	RECORD_TIMER(timers, enable);
 	evlist__disable(evlist);
+	RECORD_TIMER(timers, disable);
 	evlist__munmap(evlist);
+	RECORD_TIMER(timers, munmap);
 	evlist__close(evlist);
+	RECORD_TIMER(timers, close);
 
 out:
 	if (opts.nr_threads > 1) {
@@ -159,10 +190,15 @@ static int bench__do_evlist_open_close(struct evlist *evlist)
 
 		perf_set_singlethreaded();
 	}
+	RECORD_TIMER(timers, fini);
 
 	return err;
 }
 
+#define PRINT_TIMER(timers, field) \
+	printf("%20s took: %12.3f usec (+- %12.3f usec)\n", #field, \
+		avg_stats(&(timers)->field), stddev_stats(&(timers)->field))
+
 static int bench_evlist_open_close__run(char *evstr)
 {
 	// used to print statistics only
@@ -172,10 +208,21 @@ static int bench_evlist_open_close__run(char *evstr)
 	struct stats time_stats;
 	u64 runtime_us;
 	int i, err;
+	struct timers timers;
 
 	if (!evlist)
 		return -ENOMEM;
 
+	init_stats(&time_stats);
+	init_stats(&timers.init);
+	init_stats(&timers.open);
+	init_stats(&timers.mmap);
+	init_stats(&timers.enable);
+	init_stats(&timers.disable);
+	init_stats(&timers.munmap);
+	init_stats(&timers.close);
+	init_stats(&timers.fini);
+
 	init_stats(&time_stats);
 
 	printf("  Number of workers:\t%u\n", opts.nr_threads);
@@ -194,7 +241,7 @@ static int bench_evlist_open_close__run(char *evstr)
 			return -ENOMEM;
 
 		gettimeofday(&start, NULL);
-		err = bench__do_evlist_open_close(evlist);
+		err = bench__do_evlist_open_close(evlist, &timers);
 		if (err) {
 			evlist__delete(evlist);
 			return err;
@@ -211,7 +258,17 @@ static int bench_evlist_open_close__run(char *evstr)
 
 	time_average = avg_stats(&time_stats);
 	time_stddev = stddev_stats(&time_stats);
-	printf("  Average open-close took: %.3f usec (+- %.3f usec)\n", time_average, time_stddev);
+	printf("  Average open-close took: %12.3f usec (+- %12.3f usec)\n", time_average, time_stddev);
+	if (detail) {
+		PRINT_TIMER(&timers, init);
+		PRINT_TIMER(&timers, open);
+		PRINT_TIMER(&timers, mmap);
+		PRINT_TIMER(&timers, enable);
+		PRINT_TIMER(&timers, disable);
+		PRINT_TIMER(&timers, munmap);
+		PRINT_TIMER(&timers, close);
+		PRINT_TIMER(&timers, fini);
+	}
 
 	return 0;
 }
-- 
2.31.1


      parent reply	other threads:[~2021-08-21  9:22 UTC|newest]

Thread overview: 63+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-08-21  9:19 [RFC PATCH v1 00/37] perf: use workqueue for evlist operations Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 01/37] libperf cpumap: improve idx function Riccardo Mancini
2021-08-31 18:46   ` Arnaldo Carvalho de Melo
2021-10-08 14:29   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 02/37] libperf cpumap: improve max function Riccardo Mancini
2021-08-31 18:47   ` Arnaldo Carvalho de Melo
2021-08-31 19:16     ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 03/37] perf evlist: replace evsel__cpu_iter* functions with evsel__find_cpu Riccardo Mancini
2021-10-08 14:38   ` [RFC PATCH v1 03/37] perf evlist: replace evsel__cpu_iter* functions with evsel__find_cpu() Arnaldo Carvalho de Melo
2021-12-11  0:20   ` [RFC PATCH v1 03/37] perf evlist: replace evsel__cpu_iter* functions with evsel__find_cpu Ian Rogers
2021-08-21  9:19 ` [RFC PATCH v1 04/37] perf util: add mmap_cpu_mask__duplicate function Riccardo Mancini
2021-08-31 19:21   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 05/37] perf util/mmap: add missing bitops.h header Riccardo Mancini
2021-08-31 19:22   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 06/37] perf workqueue: add affinities to threadpool Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 07/37] perf workqueue: add support for setting affinities to workers Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 08/37] perf workqueue: add method to execute work on specific CPU Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 09/37] perf python: add workqueue dependency Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 10/37] perf evlist: add multithreading helper Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 11/37] perf evlist: add multithreading to evlist__disable Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 12/37] perf evlist: add multithreading to evlist__enable Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 13/37] perf evlist: add multithreading to evlist__close Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 14/37] perf evsel: remove retry_sample_id goto label Riccardo Mancini
2021-08-31 19:25   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 15/37] perf evsel: separate open preparation from open itself Riccardo Mancini
2021-08-31 19:27   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 16/37] perf evsel: save open flags in evsel Riccardo Mancini
2021-08-31 19:31   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 17/37] perf evsel: separate missing feature disabling from evsel__open_cpu Riccardo Mancini
2021-08-31 19:35   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 18/37] perf evsel: add evsel__prepare_open function Riccardo Mancini
2021-08-31 19:36   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 19/37] perf evsel: separate missing feature detection from evsel__open_cpu Riccardo Mancini
2021-08-31 19:39   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 20/37] perf evsel: separate rlimit increase " Riccardo Mancini
2021-08-31 19:41   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 21/37] perf evsel: move ignore_missing_thread to fallback code Riccardo Mancini
2021-08-31 19:44   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 22/37] perf evsel: move test_attr__open to success path in evsel__open_cpu Riccardo Mancini
2021-08-31 19:47   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 23/37] perf evsel: move bpf_counter__install_pe " Riccardo Mancini
2021-08-31 19:50   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 24/37] perf evsel: handle precise_ip fallback " Riccardo Mancini
2021-08-31 19:52   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 25/37] perf evsel: move event open in evsel__open_cpu to separate function Riccardo Mancini
2021-08-31 19:54   ` Arnaldo Carvalho de Melo
2021-09-03 21:52     ` Riccardo Mancini
2021-09-11 19:10       ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 26/37] perf evsel: add evsel__open_per_cpu_no_fallback function Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 27/37] perf evlist: add evlist__for_each_entry_from macro Riccardo Mancini
2021-08-31 20:06   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 28/37] perf evlist: add multithreading to evlist__open Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 29/37] perf evlist: add custom fallback " Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 30/37] perf record: use evlist__open_custom Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 31/37] tools lib/subcmd: add OPT_UINTEGER_OPTARG option type Riccardo Mancini
2021-08-31 18:44   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` [RFC PATCH v1 32/37] perf record: add --threads option Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 33/37] perf record: pin threads to monitored cpus if enough threads available Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 34/37] perf record: apply multithreading in init and fini phases Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 35/37] perf test/evlist-open-close: add multithreading Riccardo Mancini
2021-08-21  9:19 ` [RFC PATCH v1 36/37] perf test/evlist-open-close: use inline func to convert timeval to usec Riccardo Mancini
2021-10-08 14:46   ` Arnaldo Carvalho de Melo
2021-08-21  9:19 ` Riccardo Mancini [this message]

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=fd3d0bdaf8dfa4eedd53fbdcf8088b8211a6f191.1629490974.git.rickyman7@gmail.com \
    --to=rickyman7@gmail.com \
    --cc=acme@kernel.org \
    --cc=irogers@google.com \
    --cc=jolsa@redhat.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-perf-users@vger.kernel.org \
    --cc=mark.rutland@arm.com \
    --cc=mingo@redhat.com \
    --cc=namhyung@kernel.org \
    --cc=peterz@infradead.org \
    --subject='Re: [RFC PATCH v1 37/37] perf test/evlist-open-close: add detailed output mode' \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).