[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <aCoeM4qTk5YnGIsT@google.com>
Date: Sun, 18 May 2025 10:51:47 -0700
From: Namhyung Kim <namhyung@...nel.org>
To: Howard Chu <howardchu95@...il.com>
Cc: acme@...nel.org, mingo@...hat.com, mark.rutland@....com,
alexander.shishkin@...ux.intel.com, jolsa@...nel.org,
irogers@...gle.com, adrian.hunter@...el.com, peterz@...radead.org,
kan.liang@...ux.intel.com, linux-perf-users@...r.kernel.org,
linux-kernel@...r.kernel.org
Subject: Re: [PATCH v1 5/5] perf test trace BTF: Use --sort-events in BTF
general tests
On Sat, May 17, 2025 at 09:32:30AM -0700, Howard Chu wrote:
> Without the '--sort-events' flag, perf trace doesn't receive and process
> events based on their arrival time, thus PERF_RECORD_COMM event that
> assigns the correct comm to a PID, may be delivered and processed after
> regular samples, causing trace outputs not having a 'comm', e.g.
> 'mv', instead, having the default PID placeholder, e.g. ':14514'.
>
> Hopefully this answers Namhyung's question in [1].
Thanks, it makes sense. Maybe it migrated to another CPU after exec.
>
> You can simply justify the statement with this diff:
>
> ---8<---
Please do not use this in the format patch emails. This makes git treat
the following contents as commit body so it'll be added to the commit as
if it's a valid change. Maybe adding some spaces at the beginning of
each line help. But I think it's better if you publish it somewhere else
and add a link instead.
Thanks,
Namhyung
> diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
> index edab0ff60b3c..f042afed5b74 100644
> --- a/tools/perf/builtin-trace.c
> +++ b/tools/perf/builtin-trace.c
> @@ -4204,6 +4204,7 @@ static int trace__deliver_event(struct trace *trace, union perf_event *event)
> {
> int err;
>
> + printf("[debug] deliver\n");
> if (!trace->sort_events)
> return __trace__deliver_event(trace, event);
>
> diff --git a/tools/perf/util/comm.c b/tools/perf/util/comm.c
> index 8aa456d7c2cd..76df9886429e 100644
> --- a/tools/perf/util/comm.c
> +++ b/tools/perf/util/comm.c
> @@ -213,6 +213,7 @@ int comm__override(struct comm *comm, const char *str, u64 timestamp, bool exec)
> new = comm_strs__findnew(str);
> if (!new)
> return -ENOMEM;
> + printf("[OVERRIDE] old %s new %s str %s\n", old->str, new->str, str);
>
> comm_str__put(old);
> comm->comm_str = new;
> diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
> index 2531b373f2cf..5a501fe304d2 100644
> --- a/tools/perf/util/machine.c
> +++ b/tools/perf/util/machine.c
> @@ -578,6 +578,7 @@ int machine__process_comm_event(struct machine *machine, union perf_event *event
> if (dump_trace)
> perf_event__fprintf_comm(event, stdout);
>
> + printf("[debug] machine__process_comm_event\n");
> if (thread == NULL ||
> __thread__set_comm(thread, event->comm.comm, sample->time, exec)) {
> dump_printf("problem processing PERF_RECORD_COMM, skipping event.\n");
>
> Now, simply run this command multiple times:
> $ touch /tmp/file1 && sudo /tmp/perf trace -e renameat* -- mv /tmp/file1 /tmp/file2 && rm -f /tmp/file2
> And you should see two types of results:
>
> $ touch /tmp/file1 && sudo /tmp/perf trace -e renameat* -- mv /tmp/file1 /tmp/file2 && rm -f /tmp/file2
> [debug] deliver
> [debug] machine__process_comm_event
> [OVERRIDE] old :1221169 new mv str mv
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> 0.000 ( 0.013 ms): mv/1221169 renameat2(olddfd: CWD, oldname: "/tmp/file1", newdfd: CWD, newname: "/tmp/file2", flags: NOREPLACE) = 0
> [debug] deliver
>
> $ touch /tmp/file1 && sudo /tmp/perf trace -e renameat* -- mv /tmp/file1 /tmp/file2 && rm -f /tmp/file2
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> [debug] deliver
> 0.000 ( 0.014 ms): :1221398/1221398 renameat2(olddfd: CWD, oldname: "/tmp/file1", newdfd: CWD, newname: "/tmp/file2", flags: NOREPLACE) = 0
> [debug] deliver
> [debug] deliver
> [debug] machine__process_comm_event
> [OVERRIDE] old :1221398 new mv str mv
> [debug] deliver
> [debug] deliver
> [debug] deliver
>
> Anyway, use --sort-events in BTF general tests to avoid :PID, a comm is
> preferred.
>
> [1]: https://lore.kernel.org/linux-perf-users/Z_AeswETE5xLcPT8@google.com/
>
> Signed-off-by: Howard Chu <howardchu95@...il.com>
> ---
> tools/perf/tests/shell/trace_btf_general.sh | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> diff --git a/tools/perf/tests/shell/trace_btf_general.sh b/tools/perf/tests/shell/trace_btf_general.sh
> index e78e653fc8f1..a15cdb5fa309 100755
> --- a/tools/perf/tests/shell/trace_btf_general.sh
> +++ b/tools/perf/tests/shell/trace_btf_general.sh
> @@ -27,7 +27,7 @@ check_vmlinux() {
>
> trace_test_string() {
> echo "Testing perf trace's string augmentation"
> - output="$(perf trace -e renameat* --max-events=1 -- mv ${file1} ${file2} 2>&1)"
> + output="$(perf trace --sort-events -e renameat* --max-events=1 -- mv ${file1} ${file2} 2>&1)"
> if ! echo "$output" | grep -q -E "^mv/[0-9]+ renameat(2)?\(.*, \"${file1}\", .*, \"${file2}\", .*\) += +[0-9]+$"
> then
> printf "String augmentation test failed, output:\n$output"
> @@ -38,7 +38,7 @@ trace_test_string() {
> trace_test_buffer() {
> echo "Testing perf trace's buffer augmentation"
> # echo will insert a newline (\10) at the end of the buffer
> - output="$(perf trace -e write --max-events=1 -- echo "${buffer}" 2>&1)"
> + output="$(perf trace --sort-events -e write --max-events=1 -- echo "${buffer}" 2>&1)"
> if ! echo "$output" | grep -q -E "^echo/[0-9]+ write\([0-9]+, ${buffer}.*, [0-9]+\) += +[0-9]+$"
> then
> printf "Buffer augmentation test failed, output:\n$output"
> @@ -48,7 +48,7 @@ trace_test_buffer() {
>
> trace_test_struct_btf() {
> echo "Testing perf trace's struct augmentation"
> - output="$(perf trace -e clock_nanosleep --force-btf --max-events=1 -- sleep 1 2>&1)"
> + output="$(perf trace --sort-events -e clock_nanosleep --force-btf --max-events=1 -- sleep 1 2>&1)"
> if ! echo "$output" | grep -q -E "^sleep/[0-9]+ clock_nanosleep\(0, 0, \{1,\}, 0x[0-9a-f]+\) += +[0-9]+$"
> then
> printf "BTF struct augmentation test failed, output:\n$output"
> --
> 2.45.2
>
Powered by blists - more mailing lists