On 07.07.2020 17:55, Alexey Budankov wrote:
>
> On 07.07.2020 17:23, Jiri Olsa wrote:
>> On Tue, Jul 07, 2020 at 04:24:28PM +0300, Alexey Budankov wrote:
>>>
>>> On 07.07.2020 16:14, Jiri Olsa wrote:
>>>> 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.budan...@linux.intel.com>
>>>>>>>>> ---
>>>>>>>>> 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
>>>
>>>
>>> Made it like this so now times counter is not affected during commands
>>> processing:
>>
>> hm, can't process list just return true
>> when the interval needs to be printed?
>
> process_evlist() now looks suboptimal since record mode code directly calls
> evlist__ctlfd_process()
> and then handles returned command specifically to the mode. So in v10 I
> replaced process_evlist()
> call with direct evlist__ctlfd_process() call and then handling the returned
> command by printing
> command msg tag and counter values in the required order. Like this:
>
> + clock_gettime(CLOCK_MONOTONIC, &time_start);
> + if (!(evlist__poll(evsel_list, time_to_sleep) > 0)) { /* poll
> timeout or EINTR */
> + if (timeout)
> + break;
> + else
> + stop = handle_interval(interval, times);
> + time_to_sleep = sleep_time;
> + } else { /* fd revent */
> + if (evlist__ctlfd_process(evsel_list, &cmd) > 0) {
> + if (interval) {
> + switch (cmd) {
> + case EVLIST_CTL_CMD_ENABLE:
> + pr_info(EVLIST_ENABLED_MSG);
> + process_interval();
> + break;
> + case EVLIST_CTL_CMD_DISABLE:
> + process_interval();
> + pr_info(EVLIST_DISABLED_MSG);
> + break;
> + case EVLIST_CTL_CMD_ACK:
> + case EVLIST_CTL_CMD_UNSUPPORTED:
> + default:
> + break;
> + }
> + }
> + }
Does this if above want to be process_evlist(struct evlist *evlist, unsigned
int interval) function?
Alexey
> + clock_gettime(CLOCK_MONOTONIC, &time_stop);
> + compute_tts(&time_start, &time_stop, &time_to_sleep);
> + }
>
> Alexey
>
>>
>> jirka
>>
>>>
>>> static void process_evlist(struct evlist *evlist, enum evlist_ctl_cmd *cmd)
>>> {
>>> if (evlist__ctlfd_process(evlist, cmd) > 0) {
>>> switch (*cmd) {
>>> case EVLIST_CTL_CMD_ENABLE:
>>> pr_info(EVLIST_ENABLED_MSG);
>>> break;
>>> case EVLIST_CTL_CMD_DISABLE:
>>> pr_info(EVLIST_DISABLED_MSG);
>>> break;
>>> case EVLIST_CTL_CMD_ACK:
>>> case EVLIST_CTL_CMD_UNSUPPORTED:
>>> default:
>>> break;
>>> }
>>> }
>>> }
>>>
>>> ...
>>>
>>> clock_gettime(CLOCK_MONOTONIC, &time_start);
>>> if (!(evlist__poll(evsel_list, time_to_sleep) > 0)) { /* poll
>>> timeout or EINTR */
>>> if (timeout)
>>> break;
>>> else
>>> stop = handle_interval(interval, times);
>>> time_to_sleep = sleep_time;
>>> } else { /* fd revent */
>>> process_evlist(evsel_list, &cmd);
>>> if (interval) {
>>> switch (cmd) {
>>> case EVLIST_CTL_CMD_ENABLE:
>>> case EVLIST_CTL_CMD_DISABLE:
>>> process_interval();
>>> case EVLIST_CTL_CMD_ACK:
>>> case EVLIST_CTL_CMD_UNSUPPORTED:
>>> default:
>>> break;
>>> }
>>> }
>>> clock_gettime(CLOCK_MONOTONIC, &time_stop);
>>> compute_tts(&time_start, &time_stop, &time_to_sleep);
>>> }
>>>
>>> Alexey
>>>
>>
