Re: [PATCH v9 11/15] perf stat: implement control commands handling
From: Jiri Olsa
Date: Mon Jul 06 2020 - 15:34:30 EST
On Mon, Jul 06, 2020 at 05:47:54PM +0300, Alexey Budankov wrote:
>
> On 06.07.2020 15:34, Jiri Olsa wrote:
> > On Fri, Jul 03, 2020 at 10:47:22AM +0300, Alexey Budankov wrote:
> >>
> >> Implement handling of 'enable' and 'disable' control commands
> >> coming from control file descriptor. process_evlist() function
> >> checks for events on control fds and makes required operations.
> >> If poll event splits initiated timeout interval then the reminder
> >> is calculated and still waited in the following poll() syscall.
> >>
> >> Signed-off-by: Alexey Budankov <alexey.budankov@xxxxxxxxxxxxxxx>
> >> ---
> >> tools/perf/builtin-stat.c | 75 ++++++++++++++++++++++++++++-----------
> >> 1 file changed, 55 insertions(+), 20 deletions(-)
> >>
> >> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> >> index 9e4288ecf2b8..5021f7286422 100644
> >> --- a/tools/perf/builtin-stat.c
> >> +++ b/tools/perf/builtin-stat.c
> >> @@ -485,6 +485,31 @@ static bool handle_interval(unsigned int interval, int *times)
> >> return false;
> >> }
> >>
> >> +static bool process_evlist(struct evlist *evlist, unsigned int interval, int *times)
> >> +{
> >> + bool stop = false;
> >> + enum evlist_ctl_cmd cmd = EVLIST_CTL_CMD_UNSUPPORTED;
> >> +
> >> + if (evlist__ctlfd_process(evlist, &cmd) > 0) {
> >> + switch (cmd) {
> >> + case EVLIST_CTL_CMD_ENABLE:
> >> + pr_info(EVLIST_ENABLED_MSG);
> >> + stop = handle_interval(interval, times);
> >> + break;
> >> + case EVLIST_CTL_CMD_DISABLE:
> >> + stop = handle_interval(interval, times);
> >
> > I still don't understand why you call handle_interval in here
> >
> > I don't see it being necessary.. you enable events and handle_interval,
> > wil be called in the next iteration of dispatch_events, why complicate
> > this function with that?
>
> Printing event counts at the moment of command processing lets scripts
> built on top of stat output to provide more plain and accurate metrics.
> Otherwise it may get spikes in the beginning of the next time interval
> because not all counts lay inside [Events enabled, Events disable]
> If -I interval is large tail event count can be also large. Compare the
> output below with the output in the cover letter. Either way is possible
> but the latter one likely complicates the scripts I mentioned above.
>
> perf=tools/perf/perf
> ${perf} stat -D -1 -e cpu-cycles -a -I 1000 \
> --control fd:${ctl_fd},${ctl_fd_ack} \
> -- sleep 40 &
>
> Events disabled
> # time counts unit events
> 1.001100723 <not counted> cpu-cycles
> 2.003146566 <not counted> cpu-cycles
> 3.005073317 <not counted> cpu-cycles
> 4.006337062 <not counted> cpu-cycles
> Events enabled
> enable acked(ack)
> 5.011182000 54,128,692 cpu-cycles <===
> 6.012300167 3,648,804,827 cpu-cycles
> 7.013631689 590,438,536 cpu-cycles
> 8.015558583 406,935,663 cpu-cycles
> 9.017455505 407,806,862 cpu-cycles
> 10.019300780 399,351,824 cpu-cycles
> 11.021180025 404,584,417 cpu-cycles
> 12.023033661 537,787,981 cpu-cycles
> 13.024422354 699,395,364 cpu-cycles
> 14.026325749 397,871,324 cpu-cycles
> disable acked()
> Events disabled
> 15.027857981 396,956,159 cpu-cycles <===
> 16.029279264 <not counted> cpu-cycles
> 17.031131311 <not counted> cpu-cycles
> 18.033010580 <not counted> cpu-cycles
> 19.034918883 <not counted> cpu-cycles
> enable acked(ack)
> Events enabled
> 20.036758793 183,544,975 cpu-cycles <===
> 21.038163289 419,054,544 cpu-cycles
> 22.040108245 413,993,309 cpu-cycles
> 23.042042365 403,584,493 cpu-cycles
> 24.043985381 416,512,094 cpu-cycles
> 25.045925682 401,513,429 cpu-cycles
> # time counts unit events
> 26.047822238 461,205,096 cpu-cycles
> 27.049784263 414,319,162 cpu-cycles
> 28.051745360 403,706,915 cpu-cycles
> 29.053674600 416,502,883 cpu-cycles
> disable acked()
> Events disabled
> 30.054750685 414,184,409 cpu-cycles <===
ok, but we could still take handle_interval out of process_evlist
and the interval process will be more clear for me (with some
additional comments in the code) ... perhaps something like below?
thanks,
jirka
---
diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
index 5021f7286422..af83bf6b2db0 100644
--- a/tools/perf/builtin-stat.c
+++ b/tools/perf/builtin-stat.c
@@ -485,19 +485,18 @@ static bool handle_interval(unsigned int interval, int *times)
return false;
}
-static bool process_evlist(struct evlist *evlist, unsigned int interval, int *times)
+static bool process_evlist(struct evlist *evlist)
{
- bool stop = false;
enum evlist_ctl_cmd cmd = EVLIST_CTL_CMD_UNSUPPORTED;
+ bool enabled = false;
if (evlist__ctlfd_process(evlist, &cmd) > 0) {
switch (cmd) {
case EVLIST_CTL_CMD_ENABLE:
pr_info(EVLIST_ENABLED_MSG);
- stop = handle_interval(interval, times);
+ enabled = true;
break;
case EVLIST_CTL_CMD_DISABLE:
- stop = handle_interval(interval, times);
pr_info(EVLIST_DISABLED_MSG);
break;
case EVLIST_CTL_CMD_ACK:
@@ -507,7 +506,7 @@ static bool process_evlist(struct evlist *evlist, unsigned int interval, int *ti
}
}
- return stop;
+ return enabled;
}
static void enable_counters(void)
@@ -618,7 +617,8 @@ static int dispatch_events(bool forks, int timeout, int interval, int *times)
stop = handle_interval(interval, times);
time_to_sleep = sleep_time;
} else { /* fd revent */
- stop = process_evlist(evsel_list, interval, times);
+ if (process_evlist(evsel_list))
+ stop = handle_interval(interval, times);
clock_gettime(CLOCK_MONOTONIC, &time_stop);
diff_timespec(&time_diff, &time_stop, &time_start);
time_to_sleep -= time_diff.tv_sec * MSEC_PER_SEC +