From: Namhyung Kim <namhyung@kernel.org>
Handle the deferred callchains in the script output.
$ perf script
perf 801 [000] 18.031793: 1 cycles:P:
ffffffff91a14c36 __intel_pmu_enable_all.isra.0+0x56 ([kernel.kallsyms])
ffffffff91d373e9 perf_ctx_enable+0x39 ([kernel.kallsyms])
ffffffff91d36af7 event_function+0xd7 ([kernel.kallsyms])
ffffffff91d34222 remote_function+0x42 ([kernel.kallsyms])
ffffffff91c1ebe1 generic_exec_single+0x61 ([kernel.kallsyms])
ffffffff91c1edac smp_call_function_single+0xec ([kernel.kallsyms])
ffffffff91d37a9d event_function_call+0x10d ([kernel.kallsyms])
ffffffff91d33557 perf_event_for_each_child+0x37 ([kernel.kallsyms])
ffffffff91d47324 _perf_ioctl+0x204 ([kernel.kallsyms])
ffffffff91d47c43 perf_ioctl+0x33 ([kernel.kallsyms])
ffffffff91e2f216 __x64_sys_ioctl+0x96 ([kernel.kallsyms])
ffffffff9265f1ae do_syscall_64+0x9e ([kernel.kallsyms])
ffffffff92800130 entry_SYSCALL_64+0xb0 ([kernel.kallsyms])
perf 801 [000] 18.031814: DEFERRED CALLCHAIN
7fb5fc22034b __GI___ioctl+0x3b (/usr/lib/x86_64-linux-gnu/libc.so.6)
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Signed-off-by: Josh Poimboeuf <jpoimboe@kernel.org>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
tools/perf/builtin-script.c | 89 +++++++++++++++++++++++++++++++++++++
1 file changed, 89 insertions(+)
diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
index d9fbdcf72f25..d17e0a3d8567 100644
--- a/tools/perf/builtin-script.c
+++ b/tools/perf/builtin-script.c
@@ -2484,6 +2484,93 @@ 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");
+
+ 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;
@@ -4080,6 +4167,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;
@@ -4106,6 +4194,7 @@ int cmd_script(int argc, const char **argv)
script.tool.throttle = process_throttle_event;
script.tool.unthrottle = process_throttle_event;
script.tool.ordering_requires_timestamps = true;
+ script.tool.merge_deferred_callchains = false;
session = perf_session__new(&data, &script.tool);
if (IS_ERR(session))
return PTR_ERR(session);
--
2.50.1Hi Steven,
On Mon, Aug 25, 2025 at 02:06:45PM -0400, Steven Rostedt wrote:
> From: Namhyung Kim <namhyung@kernel.org>
>
> Handle the deferred callchains in the script output.
>
> $ perf script
> perf 801 [000] 18.031793: 1 cycles:P:
> ffffffff91a14c36 __intel_pmu_enable_all.isra.0+0x56 ([kernel.kallsyms])
> ffffffff91d373e9 perf_ctx_enable+0x39 ([kernel.kallsyms])
> ffffffff91d36af7 event_function+0xd7 ([kernel.kallsyms])
> ffffffff91d34222 remote_function+0x42 ([kernel.kallsyms])
> ffffffff91c1ebe1 generic_exec_single+0x61 ([kernel.kallsyms])
> ffffffff91c1edac smp_call_function_single+0xec ([kernel.kallsyms])
> ffffffff91d37a9d event_function_call+0x10d ([kernel.kallsyms])
> ffffffff91d33557 perf_event_for_each_child+0x37 ([kernel.kallsyms])
> ffffffff91d47324 _perf_ioctl+0x204 ([kernel.kallsyms])
> ffffffff91d47c43 perf_ioctl+0x33 ([kernel.kallsyms])
> ffffffff91e2f216 __x64_sys_ioctl+0x96 ([kernel.kallsyms])
> ffffffff9265f1ae do_syscall_64+0x9e ([kernel.kallsyms])
> ffffffff92800130 entry_SYSCALL_64+0xb0 ([kernel.kallsyms])
>
> perf 801 [000] 18.031814: DEFERRED CALLCHAIN
> 7fb5fc22034b __GI___ioctl+0x3b (/usr/lib/x86_64-linux-gnu/libc.so.6)
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> Signed-off-by: Josh Poimboeuf <jpoimboe@kernel.org>
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
> tools/perf/builtin-script.c | 89 +++++++++++++++++++++++++++++++++++++
> 1 file changed, 89 insertions(+)
>
> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> index d9fbdcf72f25..d17e0a3d8567 100644
> --- a/tools/perf/builtin-script.c
> +++ b/tools/perf/builtin-script.c
> @@ -2484,6 +2484,93 @@ 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");
> +
> + 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;
>
> @@ -4080,6 +4167,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;
> @@ -4106,6 +4194,7 @@ int cmd_script(int argc, const char **argv)
> script.tool.throttle = process_throttle_event;
> script.tool.unthrottle = process_throttle_event;
> script.tool.ordering_requires_timestamps = true;
> + script.tool.merge_deferred_callchains = false;
Oops, this chunk should belong to the next patch which introduces this
field. Sorry about that.
Thanks,
Namhyung
> session = perf_session__new(&data, &script.tool);
> if (IS_ERR(session))
> return PTR_ERR(session);
> --
> 2.50.1
>
>
© 2016 - 2025 Red Hat, Inc.