Re: [PATCH] perf: fix counting when initial delay configured

[Namhyung Kim]

On Thu, Feb 23, 2023 at 11:25 PM Changbin Du <changbin.du@xxxxxxxxxx> wrote:
>
> On Thu, Feb 23, 2023 at 02:48:26PM -0800, Namhyung Kim wrote:
> > Hello,
> >
> > On Thu, Feb 23, 2023 at 5:45 AM Arnaldo Carvalho de Melo
> > <acme@xxxxxxxxxx> wrote:
> > >
> > > Em Thu, Feb 23, 2023 at 03:58:00PM +0800, Changbin Du escreveu:
> > > > When creating counters with initial delay configured, the enable_on_exec
> > > > field is not set. So we need to enable the counters later. The problem
> > > > is, when a workload is specified the target__none() is still true. So
> > > > we also need to check stat_config.initial_delay.
> > > >
> > > > Before this fix the event is not counted:
> > > > $ ./perf stat -e instructions -D 100 sleep 2
> > > > Events disabled
> > > > Events enabled
> > > >
> > > >  Performance counter stats for 'sleep 2':
> > > >
> > > >      <not counted>      instructions
> > > >
> > > >        1.901661124 seconds time elapsed
> > > >
> > > >        0.001602000 seconds user
> > > >        0.000000000 seconds sys
> > > >
> > > > After fix it works:
> > > > $ ./perf stat -e instructions -D 100 sleep 2
> > > > Events disabled
> > > > Events enabled
> > > >
> > > >  Performance counter stats for 'sleep 2':
> > > >
> > > >            404,214      instructions
> > > >
> > > >        1.901743475 seconds time elapsed
> > > >
> > > >        0.001617000 seconds user
> > > >        0.000000000 seconds sys
> > > >
> > > > Fixes: c587e77e100f ("perf stat: Do not delay the workload with --delay")
> > >
> > > Yeap, even the comment states that we need to enable when initial_delay
> > > is set :-)
> >
> > Right, but the logic that checks the initial_delay is placed
> > out of the function.  Just checking the initial_delay value
> > can be confusing as it can have a negative value.
> >
> > Maybe we can add an argument (bool force?) to the
> > enable_counters() function.
> >
> Yes, it could be done.
>
> Maybe we can fold the 'initial_delay' into 'struct target', and provide
> consistent behaviour for all subcommands. Here I add a
> target__enable_counter_on_exec() to determine whether enable_on_exec should
> set for all counters.

Maybe just target__enable_on_exec() ?  Note that we have
similar logic in the perf record.  Otherwise looks good.

Thanks,
Namhyung

>
> $ git diff -U1
> diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> index c71d85577de6..e807be2214c7 100644
> --- a/tools/perf/builtin-stat.c
> +++ b/tools/perf/builtin-stat.c
> @@ -541,8 +541,3 @@ static int enable_counters(void)
>
> -       /*
> -        * We need to enable counters only if:
> -        * - we don't have tracee (attaching to task or cpu)
> -        * - we have initial delay configured
> -        */
> -       if (!target__none(&target) || stat_config.initial_delay) {
> +       if (!target__enable_counter_on_exec(&target)) {
>                 if (!all_counters_use_bpf)
> @@ -916,3 +911,3 @@ static int __run_perf_stat(int argc, const char **argv, int run_idx)
>
> -       if (stat_config.initial_delay) {
> +       if (target.initial_delay) {
>                 pr_info(EVLIST_DISABLED_MSG);
> @@ -928,4 +923,4 @@ static int __run_perf_stat(int argc, const char **argv, int run_idx)
>
> -       if (stat_config.initial_delay > 0) {
> -               usleep(stat_config.initial_delay * USEC_PER_MSEC);
> +       if (target.initial_delay > 0) {
> +               usleep(target.initial_delay * USEC_PER_MSEC);
>                 err = enable_counters();
> @@ -1250,3 +1245,3 @@ static struct option stat_options[] = {
>                      "aggregate counts per numa node", AGGR_NODE),
> -       OPT_INTEGER('D', "delay", &stat_config.initial_delay,
> +       OPT_INTEGER('D', "delay", &target.initial_delay,
>                     "ms to wait before starting measurement after program start (-1: start with events disabled)"),
> diff --git a/tools/perf/util/stat.c b/tools/perf/util/stat.c
> index 534d36d26fc3..40984d124db1 100644
> --- a/tools/perf/util/stat.c
> +++ b/tools/perf/util/stat.c
> @@ -848,3 +848,3 @@ int create_perf_stat_counter(struct evsel *evsel,
>                  */
> -               if (target__none(target) && !config->initial_delay)
> +               if (target__enable_counter_on_exec(target))
>                         attr->enable_on_exec = 1;
> diff --git a/tools/perf/util/target.h b/tools/perf/util/target.h
> index daec6cba500d..a6721b644bfb 100644
> --- a/tools/perf/util/target.h
> +++ b/tools/perf/util/target.h
> @@ -20,2 +20,3 @@ struct target {
>         bool         hybrid;
> +       int          initial_delay;
>         const char   *attr_map;
> @@ -74,2 +75,7 @@ static inline bool target__none(struct target *target)
>
> +static inline bool target__enable_counter_on_exec(struct target *target)
> +{
> +       return target__none(target) && !target->initial_delay;
> +}
> +
>
> > Thanks,
> > Namhyung
> >
> >
> > >
> > > I added the additional test output below.
> > >
> > > Namhyung, can you please ack it?
> > >
> > > - Arnaldo
> > >
> > > Committer testing:
> > >
> > > Before:
> > >
> > > Lets use stress-ng so that we have lots of samples using a CPU stressor
> > > and also intermingle the workload output with the messages about when
> > > the events get enabled (i.e. later on in the workload):
> > >
> > >   $ perf stat -e instructions -D 100 stress-ng -c 32 -t 1
> > >   Events disabled
> > >   stress-ng: info:  [38361] setting to a 1 second run per stressor
> > >   stress-ng: info:  [38361] dispatching hogs: 32 cpu
> > >   Events enabled
> > >   stress-ng: info:  [38361] successful run completed in 1.01s
> > >
> > >    Performance counter stats for 'stress-ng -c 32 -t 1':
> > >
> > >        <not counted>      instructions:u
> > >
> > >          0.916479141 seconds time elapsed
> > >
> > >         30.868003000 seconds user
> > >          0.049851000 seconds sys
> > >
> > >
> > >   Some events weren't counted. Try disabling the NMI watchdog:
> > >         echo 0 > /proc/sys/kernel/nmi_watchdog
> > >         perf stat ...
> > >         echo 1 > /proc/sys/kernel/nmi_watchdog
> > >   $
> > >
> > > After the fix:
> > >
> > >   $ perf stat -e instructions -D 100 stress-ng -c 32 -t 1
> > >   Events disabled
> > >   stress-ng: info:  [40429] setting to a 1 second run per stressor
> > >   stress-ng: info:  [40429] dispatching hogs: 32 cpu
> > >   Events enabled
> > >   stress-ng: info:  [40429] successful run completed in 1.01s
> > >
> > >    Performance counter stats for 'stress-ng -c 32 -t 1':
> > >
> > >         154117865145      instructions:u
> > >
> > >          0.920827644 seconds time elapsed
> > >
> > >         30.864753000 seconds user
> > >          0.073862000 seconds sys
> > >
> > >
> > >   $
> > >
> > > > Signed-off-by: Changbin Du <changbin.du@xxxxxxxxxx>
> > > > ---
> > > >  tools/perf/builtin-stat.c | 2 +-
> > > >  1 file changed, 1 insertion(+), 1 deletion(-)
> > > >
> > > > diff --git a/tools/perf/builtin-stat.c b/tools/perf/builtin-stat.c
> > > > index 9f3e4b257516..c71d85577de6 100644
> > > > --- a/tools/perf/builtin-stat.c
> > > > +++ b/tools/perf/builtin-stat.c
> > > > @@ -544,7 +544,7 @@ static int enable_counters(void)
> > > >        * - we don't have tracee (attaching to task or cpu)
> > > >        * - we have initial delay configured
> > > >        */
> > > > -     if (!target__none(&target)) {
> > > > +     if (!target__none(&target) || stat_config.initial_delay) {
> > > >               if (!all_counters_use_bpf)
> > > >                       evlist__enable(evsel_list);
> > > >       }
> > > > --
> > > > 2.25.1
> > > >
> > >
> > > --
> > >
> > > - Arnaldo
> >
>
> --
> Cheers,
> Changbin Du