Re: [PATCH 1/2] perf trace: do not lose last events in a race

From: Howard Chu
Date: Thu Nov 07 2024 - 16:46:39 EST


Hello Benjamin,

Without your patch (no output):
perf $ ./perf trace -e syscalls:sys_enter_exit_group true
perf $

With your patch:

perf $ ./perf trace -e syscalls:sys_enter_exit_group true
0.000 true/1530009 syscalls:sys_enter_exit_group()

The result looks good.

Tested-by: Howard Chu <howardchu95@xxxxxxxxx>

Thanks,
Howard

On Wed, Nov 6, 2024 at 3:45 PM Benjamin Peterson <benjamin@xxxxxxxxxxx> wrote:
>
> If a perf trace event selector specifies a maximum number of events to output
> (i.e., "/nr=N/" syntax), the event printing handler, trace__event_handler,
> disables the event selector after the maximum number events are
> printed. Furthermore, trace__event_handler checked if the event selector was
> disabled before doing any work. This avoided exceeding the maximum number of
> events to print if more events were in the buffer before the selector was
> disabled. However, the event selector can be disabled for reasons other than
> exceeding the maximum number of events. In particular, when the traced
> subprocess exits, the main loop disables all event selectors. This meant the
> last events of a traced subprocess might be lost to the printing handler's
> short-circuiting logic.
>
> This nondeterministic problem could be seen by running the following many times:
>
> $ perf trace -e syscalls:sys_enter_exit_group true
>
> trace__event_handler should simply check for exceeding the maximum number of
> events to print rather than the state of the event selector.
>
> Fixes: a9c5e6c1e9bff ("perf trace: Introduce per-event maximum number of events property")
> Signed-off-by: Benjamin Peterson <benjamin@xxxxxxxxxxx>
> ---
> tools/perf/builtin-trace.c | 9 ++-------
> 1 file changed, 2 insertions(+), 7 deletions(-)
>
> diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
> index d3f11b90d025..f6179b13b8b4 100644
> --- a/tools/perf/builtin-trace.c
> +++ b/tools/perf/builtin-trace.c
> @@ -3096,13 +3096,8 @@ static int trace__event_handler(struct trace *trace, struct evsel *evsel,
> {
> struct thread *thread;
> int callchain_ret = 0;
> - /*
> - * Check if we called perf_evsel__disable(evsel) due to, for instance,
> - * this event's max_events having been hit and this is an entry coming
> - * from the ring buffer that we should discard, since the max events
> - * have already been considered/printed.
> - */
> - if (evsel->disabled)
> +
> + if (evsel->nr_events_printed >= evsel->max_events)
> return 0;
>
> thread = machine__findnew_thread(trace->host, sample->pid, sample->tid);
> --
> 2.39.5
>
>