Handle the deferred callchains in the script output.
$ perf script
...
pwd 2312 121.163435: 249113 cpu/cycles/P:
ffffffff845b78d8 __build_id_parse.isra.0+0x218 ([kernel.kallsyms])
ffffffff83bb5bf6 perf_event_mmap+0x2e6 ([kernel.kallsyms])
ffffffff83c31959 mprotect_fixup+0x1e9 ([kernel.kallsyms])
ffffffff83c31dc5 do_mprotect_pkey+0x2b5 ([kernel.kallsyms])
ffffffff83c3206f __x64_sys_mprotect+0x1f ([kernel.kallsyms])
ffffffff845e6692 do_syscall_64+0x62 ([kernel.kallsyms])
ffffffff8360012f entry_SYSCALL_64_after_hwframe+0x76 ([kernel.kallsyms])
b00000006 (cookie) ([unknown])
pwd 2312 121.163447: DEFERRED CALLCHAIN [cookie: b00000006]
7f18fe337fa7 mprotect+0x7 (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
7f18fe330e0f _dl_sysdep_start+0x7f (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
7f18fe331448 _dl_start_user+0x0 (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
tools/perf/builtin-script.c | 89 +++++++++++++++++++++++++++++++++
tools/perf/util/evsel_fprintf.c | 5 +-
2 files changed, 93 insertions(+), 1 deletion(-)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index 011962e1ee0f6898..85b42205a71b3993 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -2706,6 +2706,94 @@ static int process_sample_event(const struct perf_tool *tool,
return ret;
}
+static int process_deferred_sample_event(const struct perf_tool *tool,
+ union perf_event *event,
+ struct perf_sample *sample,
+ struct evsel *evsel,
+ struct machine *machine)
+{
+ struct perf_script *scr = container_of(tool, struct perf_script, tool);
+ struct perf_event_attr *attr = &evsel->core.attr;
+ struct evsel_script *es = evsel->priv;
+ unsigned int type = output_type(attr->type);
+ struct addr_location al;
+ FILE *fp = es->fp;
+ int ret = 0;
+
+ if (output[type].fields == 0)
+ return 0;
+
+ /* Set thread to NULL to indicate addr_al and al are not initialized */
+ addr_location__init(&al);
+
+ if (perf_time__ranges_skip_sample(scr->ptime_range, scr->range_num,
+ sample->time)) {
+ goto out_put;
+ }
+
+ if (debug_mode) {
+ if (sample->time < last_timestamp) {
+ pr_err("Samples misordered, previous: %" PRIu64
+ " this: %" PRIu64 "\n", last_timestamp,
+ sample->time);
+ nr_unordered++;
+ }
+ last_timestamp = sample->time;
+ goto out_put;
+ }
+
+ if (filter_cpu(sample))
+ goto out_put;
+
+ if (machine__resolve(machine, &al, sample) < 0) {
+ pr_err("problem processing %d event, skipping it.\n",
+ event->header.type);
+ ret = -1;
+ goto out_put;
+ }
+
+ if (al.filtered)
+ goto out_put;
+
+ if (!show_event(sample, evsel, al.thread, &al, NULL))
+ goto out_put;
+
+ if (evswitch__discard(&scr->evswitch, evsel))
+ goto out_put;
+
+ perf_sample__fprintf_start(scr, sample, al.thread, evsel,
+ PERF_RECORD_CALLCHAIN_DEFERRED, fp);
+ fprintf(fp, "DEFERRED CALLCHAIN [cookie: %llx]",
+ (unsigned long long)event->callchain_deferred.cookie);
+
+ if (PRINT_FIELD(IP)) {
+ struct callchain_cursor *cursor = NULL;
+
+ if (symbol_conf.use_callchain && sample->callchain) {
+ cursor = get_tls_callchain_cursor();
+ if (thread__resolve_callchain(al.thread, cursor, evsel,
+ sample, NULL, NULL,
+ scripting_max_stack)) {
+ pr_info("cannot resolve deferred callchains\n");
+ cursor = NULL;
+ }
+ }
+
+ fputc(cursor ? '\n' : ' ', fp);
+ sample__fprintf_sym(sample, &al, 0, output[type].print_ip_opts,
+ cursor, symbol_conf.bt_stop_list, fp);
+ }
+
+ fprintf(fp, "\n");
+
+ if (verbose > 0)
+ fflush(fp);
+
+out_put:
+ addr_location__exit(&al);
+ return ret;
+}
+
// Used when scr->per_event_dump is not set
static struct evsel_script es_stdout;
@@ -4303,6 +4391,7 @@ int cmd_script(int argc, const char **argv)
perf_tool__init(&script.tool, !unsorted_dump);
script.tool.sample = process_sample_event;
+ script.tool.callchain_deferred = process_deferred_sample_event;
script.tool.mmap = perf_event__process_mmap;
script.tool.mmap2 = perf_event__process_mmap2;
script.tool.comm = perf_event__process_comm;
diff --git a/tools/perf/util/evsel_fprintf.c b/tools/perf/util/evsel_fprintf.c
index 103984b29b1e10ae..10f1a03c28601e36 100644
--- a/tools/perf/util/evsel_fprintf.c
+++ b/tools/perf/util/evsel_fprintf.c
@@ -168,7 +168,10 @@ int sample__fprintf_callchain(struct perf_sample *sample, int left_alignment,
node_al.addr = addr;
node_al.map = map__get(map);
- if (print_symoffset) {
+ if (sample->deferred_callchain &&
+ sample->deferred_cookie == node->ip) {
+ printed += fprintf(fp, "(cookie)");
+ } else if (print_symoffset) {
printed += __symbol__fprintf_symname_offs(sym, &node_al,
print_unknown_as_addr,
true, fp);
--
2.52.0.rc1.455.g30608eb744-googOn Sat, Nov 15, 2025 at 3:41 PM Namhyung Kim <namhyung@kernel.org> wrote:
>
> Handle the deferred callchains in the script output.
>
> $ perf script
> ...
> pwd 2312 121.163435: 249113 cpu/cycles/P:
> ffffffff845b78d8 __build_id_parse.isra.0+0x218 ([kernel.kallsyms])
> ffffffff83bb5bf6 perf_event_mmap+0x2e6 ([kernel.kallsyms])
> ffffffff83c31959 mprotect_fixup+0x1e9 ([kernel.kallsyms])
> ffffffff83c31dc5 do_mprotect_pkey+0x2b5 ([kernel.kallsyms])
> ffffffff83c3206f __x64_sys_mprotect+0x1f ([kernel.kallsyms])
> ffffffff845e6692 do_syscall_64+0x62 ([kernel.kallsyms])
> ffffffff8360012f entry_SYSCALL_64_after_hwframe+0x76 ([kernel.kallsyms])
> b00000006 (cookie) ([unknown])
>
> pwd 2312 121.163447: DEFERRED CALLCHAIN [cookie: b00000006]
> 7f18fe337fa7 mprotect+0x7 (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
> 7f18fe330e0f _dl_sysdep_start+0x7f (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
> 7f18fe331448 _dl_start_user+0x0 (/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2)
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Reviewed-by: Ian Rogers <irogers@google.com>
Thanks,
Ian
> ---
> tools/perf/builtin-script.c | 89 +++++++++++++++++++++++++++++++++
> tools/perf/util/evsel_fprintf.c | 5 +-
> 2 files changed, 93 insertions(+), 1 deletion(-)
>
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index 011962e1ee0f6898..85b42205a71b3993 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -2706,6 +2706,94 @@ static int process_sample_event(const struct perf_tool *tool,
> return ret;
> }
>
> +static int process_deferred_sample_event(const struct perf_tool *tool,
> + union perf_event *event,
> + struct perf_sample *sample,
> + struct evsel *evsel,
> + struct machine *machine)
> +{
> + struct perf_script *scr = container_of(tool, struct perf_script, tool);
> + struct perf_event_attr *attr = &evsel->core.attr;
> + struct evsel_script *es = evsel->priv;
> + unsigned int type = output_type(attr->type);
> + struct addr_location al;
> + FILE *fp = es->fp;
> + int ret = 0;
> +
> + if (output[type].fields == 0)
> + return 0;
> +
> + /* Set thread to NULL to indicate addr_al and al are not initialized */
> + addr_location__init(&al);
> +
> + if (perf_time__ranges_skip_sample(scr->ptime_range, scr->range_num,
> + sample->time)) {
> + goto out_put;
> + }
> +
> + if (debug_mode) {
> + if (sample->time < last_timestamp) {
> + pr_err("Samples misordered, previous: %" PRIu64
> + " this: %" PRIu64 "\n", last_timestamp,
> + sample->time);
> + nr_unordered++;
> + }
> + last_timestamp = sample->time;
> + goto out_put;
> + }
> +
> + if (filter_cpu(sample))
> + goto out_put;
> +
> + if (machine__resolve(machine, &al, sample) < 0) {
> + pr_err("problem processing %d event, skipping it.\n",
> + event->header.type);
> + ret = -1;
> + goto out_put;
> + }
> +
> + if (al.filtered)
> + goto out_put;
> +
> + if (!show_event(sample, evsel, al.thread, &al, NULL))
> + goto out_put;
> +
> + if (evswitch__discard(&scr->evswitch, evsel))
> + goto out_put;
> +
> + perf_sample__fprintf_start(scr, sample, al.thread, evsel,
> + PERF_RECORD_CALLCHAIN_DEFERRED, fp);
> + fprintf(fp, "DEFERRED CALLCHAIN [cookie: %llx]",
> + (unsigned long long)event->callchain_deferred.cookie);
> +
> + if (PRINT_FIELD(IP)) {
> + struct callchain_cursor *cursor = NULL;
> +
> + if (symbol_conf.use_callchain && sample->callchain) {
> + cursor = get_tls_callchain_cursor();
> + if (thread__resolve_callchain(al.thread, cursor, evsel,
> + sample, NULL, NULL,
> + scripting_max_stack)) {
> + pr_info("cannot resolve deferred callchains\n");
> + cursor = NULL;
> + }
> + }
> +
> + fputc(cursor ? '\n' : ' ', fp);
> + sample__fprintf_sym(sample, &al, 0, output[type].print_ip_opts,
> + cursor, symbol_conf.bt_stop_list, fp);
> + }
> +
> + fprintf(fp, "\n");
> +
> + if (verbose > 0)
> + fflush(fp);
> +
> +out_put:
> + addr_location__exit(&al);
> + return ret;
> +}
> +
> // Used when scr->per_event_dump is not set
> static struct evsel_script es_stdout;
>
> @@ -4303,6 +4391,7 @@ int cmd_script(int argc, const char **argv)
>
> perf_tool__init(&script.tool, !unsorted_dump);
> script.tool.sample = process_sample_event;
> + script.tool.callchain_deferred = process_deferred_sample_event;
> script.tool.mmap = perf_event__process_mmap;
> script.tool.mmap2 = perf_event__process_mmap2;
> script.tool.comm = perf_event__process_comm;
> diff --git a/tools/perf/util/evsel_fprintf.c b/tools/perf/util/evsel_fprintf.c
> index 103984b29b1e10ae..10f1a03c28601e36 100644
> --- a/tools/perf/util/evsel_fprintf.c
> +++ b/tools/perf/util/evsel_fprintf.c
> @@ -168,7 +168,10 @@ int sample__fprintf_callchain(struct perf_sample *sample, int left_alignment,
> node_al.addr = addr;
> node_al.map = map__get(map);
>
> - if (print_symoffset) {
> + if (sample->deferred_callchain &&
> + sample->deferred_cookie == node->ip) {
> + printed += fprintf(fp, "(cookie)");
> + } else if (print_symoffset) {
> printed += __symbol__fprintf_symname_offs(sym, &node_al,
> print_unknown_as_addr,
> true, fp);
> --
> 2.52.0.rc1.455.g30608eb744-goog
>
© 2016 - 2026 Red Hat, Inc.