Messages in this thread Patch in this message | | | From | Riccardo Mancini <> | Subject | [RFC PATCH v1 37/37] perf test/evlist-open-close: add detailed output mode | Date | Sat, 21 Aug 2021 11:19:43 +0200 |
| |
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
| |