Re: [PATCH v9 11/15] perf stat: implement control commands handling

From: Jiri Olsa
Date: Tue Jul 07 2020 - 09:14:21 EST

On Tue, Jul 07, 2020 at 04:07:42PM +0300, Alexey Budankov wrote:
>
> On 06.07.2020 22:34, Jiri Olsa wrote:
> > 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);
>
> It will call only on enable command and lead to artificial spikes in the beginning of interval.
> May be just take handle_interval() out of process_evlist() and have it similar to record case?

it can be called also for disable case then

jirka