[PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED

Namhyung Kim posted 6 patches 2 months, 2 weeks ago
[PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED
Posted by Namhyung Kim 2 months, 2 weeks ago
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)

Reviewed-by: Ian Rogers <irogers@google.com>
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.rc2.455.g230fcf2819-goog
Re: [PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED
Posted by Jens Remus 1 month, 4 weeks ago
Hello Namhyung,

following is an observation from my attempt to enable unwind user fp on
s390 using s390 back chain instead of frame pointer and relaxing the
s390-specific IP validation check.

When capturing call graphs of a Java application the list of "unwound"
user space IPs may contain invalid entries, such as 0x0, 0xdeaddeaf,
and 0xffffffffffffff.  IPs that exceed PERF_CONTEXT_MAX, such as the
latter, cause perf not to display any deferred (or merged) call chain.
Note that this is not caused by your patch series.

While re-adding the s390-specific IP checks would "hide" those, I found
that the call graphs look good otherwise.  That is the back chain seems
to be intact.  It is just the user space application (e.g. Java JRE) not
correctly adhering to the ABI and saving the return address to the
specified location on the stack, causing bogus IPs to be reported.

Could perf be improved to handle those user space IPs that exceed
PERF_CONTEXT_MAX?

Is there otherwise guidance how unwind user and/or the s390
implementation should deal with such IPs?  Should it stop taking the
deferred calltrace?  Should it substitute those with e.g 0, so that
perf can display them?


Sample for IP == deaddeaf (perf displays this correctly):

java    1084    33.086790: DEFERRED CALLCHAIN [cookie: 2000001f9]
             3ff983f071c java.lang.String CryptoBench.crypt(java.lang.String)+0x89c (/tmp/perf-1082.map)
             3ff983ff894 void CryptoBench.execute()+0x94 (/tmp/perf-1082.map)
       ! -->    deaddeaf [unknown] ([unknown])
             3ff97e37900 StubRoutines (initial stubs)+0x80 (/tmp/perf-1082.map)
             3ff97e41080 Interpreter+0x3300 (/tmp/perf-1082.map)
             3ffae2d11de JavaCalls::call(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x3e (/usr/lib/jvm/.../libjvm.so)
             3ffae38df92 jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, JavaThread*) [clone .constprop.1]+0x242 (/usr/lib/jvm/.../libjvm.so)
             3ffae390e86 jni_CallStaticVoidMethod+0x116 (/usr/lib/jvm/.../libjvm.so)
             3ffaf08b07e JavaMain+0x113e (/usr/lib/jvm/.../libjli.so)
             3ffaf08e040 ThreadJavaMain+0x20 (/usr/lib/jvm/.../libjli.so)
             3ffaedabbd8 start_thread+0x198 (/usr/lib64/libc.so.6)
             3ffaee2b950 thread_start+0x10 (/usr/lib64/libc.so.6)


Sample for IP == 0 (perf displays this correctly):

java    1084    33.021987: DEFERRED CALLCHAIN [cookie: 20000017b]
             3ff983f067c java.lang.String CryptoBench.crypt(java.lang.String)+0x7fc (/tmp/perf-1082.map)
             3ff9098aa88 void CryptoBench.execute()+0x748 (/tmp/perf-1082.map)
       ! -->           0 [unknown] ([unknown])
             3ff97e37900 StubRoutines (initial stubs)+0x80 (/tmp/perf-1082.map)
             3ff97e41080 Interpreter+0x3300 (/tmp/perf-1082.map)
             3ffae2d11de JavaCalls::call(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x3e (/usr/lib/jvm/.../libjvm.so)
             3ffae38df92 jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, JavaThread*) [clone .constprop.1]+0x242 (/usr/lib/jvm/.../libjvm.so)
             3ffae390e86 jni_CallStaticVoidMethod+0x116 (/usr/lib/jvm/.../libjvm.so)
             3ffaf08b07e JavaMain+0x113e (/usr/lib/jvm/.../libjli.so)
             3ffaf08e040 ThreadJavaMain+0x20 (/usr/lib/jvm/.../libjli.so)
             3ffaedabbd8 start_thread+0x198 (/usr/lib64/libc.so.6)
             3ffaee2b950 thread_start+0x10 (/usr/lib64/libc.so.6)

Note that for the IP==0 case I am thinking about adding a common unwind
user check, to stop taking the deferred calltrace.


Sample for IP == ffffffffffffff (perf does not display any call chain):

# perf script
...
java    1084    44.004346:    1001001 task-clock:ppp:

...
[next entry]

# perf script --no-merge-callchain
...
java    1084    44.004346:    1001001 task-clock:ppp:
               400000079 (cookie) ([unknown])

java    1084    44.004348: DEFERRED CALLCHAIN [cookie: 400000079]

...
[next entry]

# perf report -D
...
44004346257 0x17718 [0x40]: PERF_RECORD_SAMPLE(IP, 0x2): 1082/1084: 0x3ffa3e413aa period: 1001001 addr: 0
... FP chain: nr:2
.....  0: fffffffffffffd80
.....  1: 0000000400000079
...... (deferred)
 ... thread: java:1084
 ...... dso: /tmp/perf-1082.map

0x17758@perf.data [0xd0]: event: 22
.
. ... raw event: size 208 bytes
.  0000:  00 00 00 16 00 02 00 d0 00 00 00 04 00 00 00 79  ...............y
.  0010:  00 00 00 00 00 00 00 15 00 00 03 ff a3 e4 13 aa  ................
.  0020:  00 00 03 ff 38 09 e2 d0 00 00 03 ff 38 09 e1 30  ....8.......8..0
.  0030:  00 00 03 ff b9 5f df 68 00 00 00 00 00 00 00 00  ....._.h........
.  0040:  00 00 03 ff b9 5f e1 28 00 00 03 ff b9 5f e1 d0  ....._.(....._..
.  0050:  00 57 80 88 8e 76 47 a5 00 00 03 ff a3 e4 37 f2  .W...vG.......7.
.  0060:  ff ff ff ff ff ff ff ff 00 00 03 ff a3 e4 a1 fc  ................
.  0070:  00 00 00 00 00 00 00 00 00 00 03 ff a3 e3 79 00  ..............y.
.  0080:  00 00 03 ff a3 e4 10 80 00 00 03 ff b9 dd 11 de  ................
.  0090:  00 00 03 ff b9 e8 df 92 00 00 03 ff b9 e9 0e 86  ................
.  00a0:  00 00 03 ff ba b8 b0 7e 00 00 03 ff ba b8 e0 40  .......~.......@
.  00b0:  00 00 03 ff ba 8a bb d8 00 00 03 ff ba 92 b9 50  ...............P
.  00c0:  00 00 04 3a 00 00 04 3c 00 00 00 0a 3e dd 13 c0  ...:...<....>...

44004348864 0x17758 [0xd0]: PERF_RECORD_CALLCHAIN_DEFERRED(IP, 0x2): 1082/1084: 0x400000079
... FP chain: nr:21
.....  0: 000003ffa3e413aa
.....  1: 000003ff3809e2d0
.....  2: 000003ff3809e130
.....  3: 000003ffb95fdf68
.....  4: 0000000000000000
.....  5: 000003ffb95fe128
.....  6: 000003ffb95fe1d0
.....  7: 005780888e7647a5
.....  8: 000003ffa3e437f2
.....  9: ffffffffffffffff <-- !
..... 10: 000003ffa3e4a1fc
..... 11: 0000000000000000
..... 12: 000003ffa3e37900
..... 13: 000003ffa3e41080
..... 14: 000003ffb9dd11de
..... 15: 000003ffb9e8df92
..... 16: 000003ffb9e90e86
..... 17: 000003ffbab8b07e
..... 18: 000003ffbab8e040
..... 19: 000003ffba8abbd8
..... 20: 000003ffba92b950
: unhandled!

...
[next entry]


On 11/21/2025 12:48 AM, Namhyung Kim 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)

> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c

> +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)
> +{

> +	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)) {

thread__resolve_callchain()
calls __thread__resolve_callchain()
calls thread__resolve_callchain_sample():

        for (i = first_call, nr_entries = 0;
             i < chain_nr && nr_entries < max_stack; i++) {
...
                ip = chain->ips[j];
                if (ip < PERF_CONTEXT_MAX)   <-- IP=ff..ff is greater than PERF_CONTEXT_MAX
                       ++nr_entries;
...
                err = add_callchain_ip(thread, cursor, parent,
                                       root_al, &cpumode, ip,
                                       false, NULL, NULL, 0, symbols);

                if (err)
                        return (err < 0) ? err : 0;

calls add_callchain_ip:

               if (ip >= PERF_CONTEXT_MAX) {
                       switch (ip) {
                       case PERF_CONTEXT_HV:
                               *cpumode = PERF_RECORD_MISC_HYPERVISOR;
                               break;
                       case PERF_CONTEXT_KERNEL:
                               *cpumode = PERF_RECORD_MISC_KERNEL;
                               break;
                       case PERF_CONTEXT_USER:
                       case PERF_CONTEXT_USER_DEFERRED:
                               *cpumode = PERF_RECORD_MISC_USER;
                               break;
                       default:
                               pr_debug("invalid callchain context: "  <-- IP=ff..ff reaches default case
                                        "%"PRId64"\n", (s64) ip);
                               /*
                                * It seems the callchain is corrupted.
                                * Discard all.
                                */
                               callchain_cursor_reset(cursor);
                               err = 1;
                               goto out;
                       }

> +				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);
> +	}
Thanks and regards,
Jens
-- 
Jens Remus
Linux on Z Development (D3303)
+49-7031-16-1128 Office
jremus@de.ibm.com

IBM

IBM Deutschland Research & Development GmbH; Vorsitzender des Aufsichtsrats: Wolfgang Wendt; Geschäftsführung: David Faller; Sitz der Gesellschaft: Böblingen; Registergericht: Amtsgericht Stuttgart, HRB 243294
IBM Data Privacy Statement: https://www.ibm.com/privacy/

Re: [PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED
Posted by Namhyung Kim 1 month, 3 weeks ago
Hello!

On Fri, Dec 12, 2025 at 01:11:38PM +0100, Jens Remus wrote:
> Hello Namhyung,
> 
> following is an observation from my attempt to enable unwind user fp on
> s390 using s390 back chain instead of frame pointer and relaxing the
> s390-specific IP validation check.
> 
> When capturing call graphs of a Java application the list of "unwound"
> user space IPs may contain invalid entries, such as 0x0, 0xdeaddeaf,
> and 0xffffffffffffff.  IPs that exceed PERF_CONTEXT_MAX, such as the
> latter, cause perf not to display any deferred (or merged) call chain.
> Note that this is not caused by your patch series.

Right, it's not a real IP so perf ABI treats them as a magic context.

> 
> While re-adding the s390-specific IP checks would "hide" those, I found
> that the call graphs look good otherwise.  That is the back chain seems
> to be intact.  It is just the user space application (e.g. Java JRE) not
> correctly adhering to the ABI and saving the return address to the
> specified location on the stack, causing bogus IPs to be reported.
> 
> Could perf be improved to handle those user space IPs that exceed
> PERF_CONTEXT_MAX?

Ideally we should not have them in the first place.  Is it a JRE issue
or your s390 unwinder issue?  Is it possible to ignore them in the
unwinder?

> 
> Is there otherwise guidance how unwind user and/or the s390
> implementation should deal with such IPs?  Should it stop taking the
> deferred calltrace?  Should it substitute those with e.g 0, so that
> perf can display them?
> 
> 
> Sample for IP == deaddeaf (perf displays this correctly):
> 
> java    1084    33.086790: DEFERRED CALLCHAIN [cookie: 2000001f9]
>              3ff983f071c java.lang.String CryptoBench.crypt(java.lang.String)+0x89c (/tmp/perf-1082.map)
>              3ff983ff894 void CryptoBench.execute()+0x94 (/tmp/perf-1082.map)
>        ! -->    deaddeaf [unknown] ([unknown])
>              3ff97e37900 StubRoutines (initial stubs)+0x80 (/tmp/perf-1082.map)
>              3ff97e41080 Interpreter+0x3300 (/tmp/perf-1082.map)
>              3ffae2d11de JavaCalls::call(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x3e (/usr/lib/jvm/.../libjvm.so)
>              3ffae38df92 jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, JavaThread*) [clone .constprop.1]+0x242 (/usr/lib/jvm/.../libjvm.so)
>              3ffae390e86 jni_CallStaticVoidMethod+0x116 (/usr/lib/jvm/.../libjvm.so)
>              3ffaf08b07e JavaMain+0x113e (/usr/lib/jvm/.../libjli.so)
>              3ffaf08e040 ThreadJavaMain+0x20 (/usr/lib/jvm/.../libjli.so)
>              3ffaedabbd8 start_thread+0x198 (/usr/lib64/libc.so.6)
>              3ffaee2b950 thread_start+0x10 (/usr/lib64/libc.so.6)
> 
> 
> Sample for IP == 0 (perf displays this correctly):
> 
> java    1084    33.021987: DEFERRED CALLCHAIN [cookie: 20000017b]
>              3ff983f067c java.lang.String CryptoBench.crypt(java.lang.String)+0x7fc (/tmp/perf-1082.map)
>              3ff9098aa88 void CryptoBench.execute()+0x748 (/tmp/perf-1082.map)
>        ! -->           0 [unknown] ([unknown])
>              3ff97e37900 StubRoutines (initial stubs)+0x80 (/tmp/perf-1082.map)
>              3ff97e41080 Interpreter+0x3300 (/tmp/perf-1082.map)
>              3ffae2d11de JavaCalls::call(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x3e (/usr/lib/jvm/.../libjvm.so)
>              3ffae38df92 jni_invoke_static(JNIEnv_*, JavaValue*, _jobject*, JNICallType, _jmethodID*, JNI_ArgumentPusher*, JavaThread*) [clone .constprop.1]+0x242 (/usr/lib/jvm/.../libjvm.so)
>              3ffae390e86 jni_CallStaticVoidMethod+0x116 (/usr/lib/jvm/.../libjvm.so)
>              3ffaf08b07e JavaMain+0x113e (/usr/lib/jvm/.../libjli.so)
>              3ffaf08e040 ThreadJavaMain+0x20 (/usr/lib/jvm/.../libjli.so)
>              3ffaedabbd8 start_thread+0x198 (/usr/lib64/libc.so.6)
>              3ffaee2b950 thread_start+0x10 (/usr/lib64/libc.so.6)
> 
> Note that for the IP==0 case I am thinking about adding a common unwind
> user check, to stop taking the deferred calltrace.
> 
> 
> Sample for IP == ffffffffffffff (perf does not display any call chain):
> 
> # perf script
> ...
> java    1084    44.004346:    1001001 task-clock:ppp:
> 
> ...
> [next entry]
> 
> # perf script --no-merge-callchain
> ...
> java    1084    44.004346:    1001001 task-clock:ppp:
>                400000079 (cookie) ([unknown])
> 
> java    1084    44.004348: DEFERRED CALLCHAIN [cookie: 400000079]
> 
> ...
> [next entry]
> 
> # perf report -D
> ...
> 44004346257 0x17718 [0x40]: PERF_RECORD_SAMPLE(IP, 0x2): 1082/1084: 0x3ffa3e413aa period: 1001001 addr: 0
> ... FP chain: nr:2
> .....  0: fffffffffffffd80
> .....  1: 0000000400000079
> ...... (deferred)
>  ... thread: java:1084
>  ...... dso: /tmp/perf-1082.map
> 
> 0x17758@perf.data [0xd0]: event: 22
> .
> . ... raw event: size 208 bytes
> .  0000:  00 00 00 16 00 02 00 d0 00 00 00 04 00 00 00 79  ...............y
> .  0010:  00 00 00 00 00 00 00 15 00 00 03 ff a3 e4 13 aa  ................
> .  0020:  00 00 03 ff 38 09 e2 d0 00 00 03 ff 38 09 e1 30  ....8.......8..0
> .  0030:  00 00 03 ff b9 5f df 68 00 00 00 00 00 00 00 00  ....._.h........
> .  0040:  00 00 03 ff b9 5f e1 28 00 00 03 ff b9 5f e1 d0  ....._.(....._..
> .  0050:  00 57 80 88 8e 76 47 a5 00 00 03 ff a3 e4 37 f2  .W...vG.......7.
> .  0060:  ff ff ff ff ff ff ff ff 00 00 03 ff a3 e4 a1 fc  ................
> .  0070:  00 00 00 00 00 00 00 00 00 00 03 ff a3 e3 79 00  ..............y.
> .  0080:  00 00 03 ff a3 e4 10 80 00 00 03 ff b9 dd 11 de  ................
> .  0090:  00 00 03 ff b9 e8 df 92 00 00 03 ff b9 e9 0e 86  ................
> .  00a0:  00 00 03 ff ba b8 b0 7e 00 00 03 ff ba b8 e0 40  .......~.......@
> .  00b0:  00 00 03 ff ba 8a bb d8 00 00 03 ff ba 92 b9 50  ...............P
> .  00c0:  00 00 04 3a 00 00 04 3c 00 00 00 0a 3e dd 13 c0  ...:...<....>...
> 
> 44004348864 0x17758 [0xd0]: PERF_RECORD_CALLCHAIN_DEFERRED(IP, 0x2): 1082/1084: 0x400000079
> ... FP chain: nr:21
> .....  0: 000003ffa3e413aa
> .....  1: 000003ff3809e2d0
> .....  2: 000003ff3809e130
> .....  3: 000003ffb95fdf68
> .....  4: 0000000000000000
> .....  5: 000003ffb95fe128
> .....  6: 000003ffb95fe1d0
> .....  7: 005780888e7647a5
> .....  8: 000003ffa3e437f2
> .....  9: ffffffffffffffff <-- !
> ..... 10: 000003ffa3e4a1fc
> ..... 11: 0000000000000000
> ..... 12: 000003ffa3e37900
> ..... 13: 000003ffa3e41080
> ..... 14: 000003ffb9dd11de
> ..... 15: 000003ffb9e8df92
> ..... 16: 000003ffb9e90e86
> ..... 17: 000003ffbab8b07e
> ..... 18: 000003ffbab8e040
> ..... 19: 000003ffba8abbd8
> ..... 20: 000003ffba92b950
> : unhandled!
> 
> ...
> [next entry]
> 
> 
> On 11/21/2025 12:48 AM, Namhyung Kim 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)
> 
> > diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> 
> > +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)
> > +{
> 
> > +	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)) {
> 
> thread__resolve_callchain()
> calls __thread__resolve_callchain()
> calls thread__resolve_callchain_sample():
> 
>         for (i = first_call, nr_entries = 0;
>              i < chain_nr && nr_entries < max_stack; i++) {
> ...
>                 ip = chain->ips[j];
>                 if (ip < PERF_CONTEXT_MAX)   <-- IP=ff..ff is greater than PERF_CONTEXT_MAX
>                        ++nr_entries;

Right.

> ...
>                 err = add_callchain_ip(thread, cursor, parent,
>                                        root_al, &cpumode, ip,
>                                        false, NULL, NULL, 0, symbols);
> 
>                 if (err)
>                         return (err < 0) ? err : 0;
> 
> calls add_callchain_ip:
> 
>                if (ip >= PERF_CONTEXT_MAX) {
>                        switch (ip) {
>                        case PERF_CONTEXT_HV:
>                                *cpumode = PERF_RECORD_MISC_HYPERVISOR;
>                                break;
>                        case PERF_CONTEXT_KERNEL:
>                                *cpumode = PERF_RECORD_MISC_KERNEL;
>                                break;
>                        case PERF_CONTEXT_USER:
>                        case PERF_CONTEXT_USER_DEFERRED:
>                                *cpumode = PERF_RECORD_MISC_USER;
>                                break;
>                        default:
>                                pr_debug("invalid callchain context: "  <-- IP=ff..ff reaches default case
>                                         "%"PRId64"\n", (s64) ip);

We may skip -1 if it's Java and *cpumode is already USER and it's s390.
But I'd like to understand the situation first.

Thanks,
Namhyung

>                                /*
>                                 * It seems the callchain is corrupted.
>                                 * Discard all.
>                                 */
>                                callchain_cursor_reset(cursor);
>                                err = 1;
>                                goto out;
>                        }
> 
> > +				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);
> > +	}
> Thanks and regards,
> Jens
> -- 
> Jens Remus
> Linux on Z Development (D3303)
> +49-7031-16-1128 Office
> jremus@de.ibm.com
> 
> IBM
> 
> IBM Deutschland Research & Development GmbH; Vorsitzender des Aufsichtsrats: Wolfgang Wendt; Geschäftsführung: David Faller; Sitz der Gesellschaft: Böblingen; Registergericht: Amtsgericht Stuttgart, HRB 243294
> IBM Data Privacy Statement: https://www.ibm.com/privacy/
> 
Re: [PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED
Posted by Jens Remus 1 month, 3 weeks ago
Hello Namhyung!

On 12/16/2025 5:48 AM, Namhyung Kim wrote:
> On Fri, Dec 12, 2025 at 01:11:38PM +0100, Jens Remus wrote:

>> following is an observation from my attempt to enable unwind user fp on
>> s390 using s390 back chain instead of frame pointer and relaxing the
>> s390-specific IP validation check.
>>
>> When capturing call graphs of a Java application the list of "unwound"
>> user space IPs may contain invalid entries, such as 0x0, 0xdeaddeaf,
>> and 0xffffffffffffff.  IPs that exceed PERF_CONTEXT_MAX, such as the
>> latter, cause perf not to display any deferred (or merged) call chain.
>> Note that this is not caused by your patch series.
> 
> Right, it's not a real IP so perf ABI treats them as a magic context.
> 
>>
>> While re-adding the s390-specific IP checks would "hide" those, I found
>> that the call graphs look good otherwise.  That is the back chain seems
>> to be intact.  It is just the user space application (e.g. Java JRE) not
>> correctly adhering to the ABI and saving the return address to the
>> specified location on the stack, causing bogus IPs to be reported.
>>
>> Could perf be improved to handle those user space IPs that exceed
>> PERF_CONTEXT_MAX?
> 
> Ideally we should not have them in the first place.  Is it a JRE issue
> or your s390 unwinder issue?  Is it possible to ignore them in the
> unwinder?

Stack tracing using frame pointer is virtually impossible on s390, as
the ABI does not designate a specific register as FP register, does not
specify a fixed register save area layout, nor does mandate a FP to be
setup early.  Compilers usually setup a FP late, that is after static
stack allocation.

An alternative is the s390-specific back chain, which is basically a
frame pointer on stack.  The ABI specifics that *(SP+0) has the pointer
to the previous frame and *(BC-48) has the return address (RA), if a
back chain is used (e.g. compiler option -mbackchain is used).  This is
why I implemented unwind user fp on s390 using back chain.  Note that
the back chain can be correctly followed, even if the saved RAs are
bogus.  That is what can be observed in case of this specific Java JRE.
Apparently it correctly maintains the back chain stack slot, but does
not correctly maintain the RA stack slot.  So the RA stack save slot may
contain any random value.

The s390-implementation of unwind user fp could check whether the return
address is a valid IP.  This is how it is implemented in the existing
stack tracer in arch/s390/kernel/stacktrace.c:

static inline bool ip_invalid(unsigned long ip)
{
	/* ABI requires IPs to be 2-byte aligned */
	if (ip & 1)
		return true;
	if (ip < mmap_min_addr)
		return true;
	if (ip >= current->mm->context.asce_limit)
		return true;
	return false;
}

It could then either stop or return some magic value
(e.g. PERF_CONTEXT_MAX - 1) to indicate that the IP is invalid and
continue.  Actually I would prefer to continue so that a user an see
that there is something odd with the stack trace.

Alternatively such a check could possibly also be implemented in the
common undwind user, if the address space limits are known in common
code, or as an architecture-specific hook.  In general I tend to at
least add a check whether the IP is zero, as this is used on several
architectures as indication for outermost frames (usually in
combination with a FP of zero).

>>
>> Is there otherwise guidance how unwind user and/or the s390
>> implementation should deal with such IPs?  Should it stop taking the
>> deferred calltrace?  Should it substitute those with e.g 0, so that
>> perf can display them?


>> Sample for IP == ffffffffffffff (perf does not display any call chain):
...
>> # perf report -D
>> ...
>> 44004346257 0x17718 [0x40]: PERF_RECORD_SAMPLE(IP, 0x2): 1082/1084: 0x3ffa3e413aa period: 1001001 addr: 0
>> ... FP chain: nr:2
>> .....  0: fffffffffffffd80
>> .....  1: 0000000400000079
>> ...... (deferred)
>>  ... thread: java:1084
>>  ...... dso: /tmp/perf-1082.map
>>
>> 0x17758@perf.data [0xd0]: event: 22
>> .
>> . ... raw event: size 208 bytes
...
>>
>> 44004348864 0x17758 [0xd0]: PERF_RECORD_CALLCHAIN_DEFERRED(IP, 0x2): 1082/1084: 0x400000079
>> ... FP chain: nr:21
>> .....  0: 000003ffa3e413aa
>> .....  1: 000003ff3809e2d0
>> .....  2: 000003ff3809e130
>> .....  3: 000003ffb95fdf68
>> .....  4: 0000000000000000
>> .....  5: 000003ffb95fe128
>> .....  6: 000003ffb95fe1d0
>> .....  7: 005780888e7647a5
>> .....  8: 000003ffa3e437f2
>> .....  9: ffffffffffffffff <-- !
>> ..... 10: 000003ffa3e4a1fc
>> ..... 11: 0000000000000000
>> ..... 12: 000003ffa3e37900
>> ..... 13: 000003ffa3e41080
>> ..... 14: 000003ffb9dd11de
>> ..... 15: 000003ffb9e8df92
>> ..... 16: 000003ffb9e90e86
>> ..... 17: 000003ffbab8b07e
>> ..... 18: 000003ffbab8e040
>> ..... 19: 000003ffba8abbd8
>> ..... 20: 000003ffba92b950
>> : unhandled!
>>
>> ...
>> [next entry]
>>
>>
>> On 11/21/2025 12:48 AM, Namhyung Kim wrote:

>>> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
>>
>>> +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)
>>> +{
>>
>>> +	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)) {
>>
>> thread__resolve_callchain()
>> calls __thread__resolve_callchain()
>> calls thread__resolve_callchain_sample():
>>
>>         for (i = first_call, nr_entries = 0;
>>              i < chain_nr && nr_entries < max_stack; i++) {
>> ...
>>                 ip = chain->ips[j];
>>                 if (ip < PERF_CONTEXT_MAX)   <-- IP=ff..ff is greater than PERF_CONTEXT_MAX
>>                        ++nr_entries;
> 
> Right.
> 
>> ...
>>                 err = add_callchain_ip(thread, cursor, parent,
>>                                        root_al, &cpumode, ip,
>>                                        false, NULL, NULL, 0, symbols);
>>
>>                 if (err)
>>                         return (err < 0) ? err : 0;
>>
>> calls add_callchain_ip:
>>
>>                if (ip >= PERF_CONTEXT_MAX) {
>>                        switch (ip) {
>>                        case PERF_CONTEXT_HV:
>>                                *cpumode = PERF_RECORD_MISC_HYPERVISOR;
>>                                break;
>>                        case PERF_CONTEXT_KERNEL:
>>                                *cpumode = PERF_RECORD_MISC_KERNEL;
>>                                break;
>>                        case PERF_CONTEXT_USER:
>>                        case PERF_CONTEXT_USER_DEFERRED:
>>                                *cpumode = PERF_RECORD_MISC_USER;
>>                                break;
>>                        default:
>>                                pr_debug("invalid callchain context: "  <-- IP=ff..ff reaches default case
>>                                         "%"PRId64"\n", (s64) ip);
> 
> We may skip -1 if it's Java and *cpumode is already USER and it's s390.
> But I'd like to understand the situation first.

Let's better not add any weird architecture-specific handling.  This is
also not limited to -1 (and 0), as Java may have used the stack save
area in any way, so it may be any random value.

>>                                /*
>>                                 * It seems the callchain is corrupted.
>>                                 * Discard all.
>>                                 */
>>                                callchain_cursor_reset(cursor);
>>                                err = 1;
>>                                goto out;
>>                        }
>>
>>> +				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);
>>> +	}

Thanks and regards,
Jens
-- 
Jens Remus
Linux on Z Development (D3303)
+49-7031-16-1128 Office
jremus@de.ibm.com

IBM

IBM Deutschland Research & Development GmbH; Vorsitzender des Aufsichtsrats: Wolfgang Wendt; Geschäftsführung: David Faller; Sitz der Gesellschaft: Böblingen; Registergericht: Amtsgericht Stuttgart, HRB 243294
IBM Data Privacy Statement: https://www.ibm.com/privacy/

Re: [PATCH v6 4/6] perf script: Display PERF_RECORD_CALLCHAIN_DEFERRED
Posted by Namhyung Kim 1 month, 3 weeks ago
Hello!

On Tue, Dec 16, 2025 at 10:29:28AM +0100, Jens Remus wrote:
> Hello Namhyung!
> 
> On 12/16/2025 5:48 AM, Namhyung Kim wrote:
> > On Fri, Dec 12, 2025 at 01:11:38PM +0100, Jens Remus wrote:
> 
> >> following is an observation from my attempt to enable unwind user fp on
> >> s390 using s390 back chain instead of frame pointer and relaxing the
> >> s390-specific IP validation check.
> >>
> >> When capturing call graphs of a Java application the list of "unwound"
> >> user space IPs may contain invalid entries, such as 0x0, 0xdeaddeaf,
> >> and 0xffffffffffffff.  IPs that exceed PERF_CONTEXT_MAX, such as the
> >> latter, cause perf not to display any deferred (or merged) call chain.
> >> Note that this is not caused by your patch series.
> > 
> > Right, it's not a real IP so perf ABI treats them as a magic context.
> > 
> >>
> >> While re-adding the s390-specific IP checks would "hide" those, I found
> >> that the call graphs look good otherwise.  That is the back chain seems
> >> to be intact.  It is just the user space application (e.g. Java JRE) not
> >> correctly adhering to the ABI and saving the return address to the
> >> specified location on the stack, causing bogus IPs to be reported.
> >>
> >> Could perf be improved to handle those user space IPs that exceed
> >> PERF_CONTEXT_MAX?
> > 
> > Ideally we should not have them in the first place.  Is it a JRE issue
> > or your s390 unwinder issue?  Is it possible to ignore them in the
> > unwinder?
> 
> Stack tracing using frame pointer is virtually impossible on s390, as
> the ABI does not designate a specific register as FP register, does not
> specify a fixed register save area layout, nor does mandate a FP to be
> setup early.  Compilers usually setup a FP late, that is after static
> stack allocation.
> 
> An alternative is the s390-specific back chain, which is basically a
> frame pointer on stack.  The ABI specifics that *(SP+0) has the pointer
> to the previous frame and *(BC-48) has the return address (RA), if a
> back chain is used (e.g. compiler option -mbackchain is used).  This is
> why I implemented unwind user fp on s390 using back chain.  Note that
> the back chain can be correctly followed, even if the saved RAs are
> bogus.  That is what can be observed in case of this specific Java JRE.
> Apparently it correctly maintains the back chain stack slot, but does
> not correctly maintain the RA stack slot.  So the RA stack save slot may
> contain any random value.

Thanks for the explanation.

> 
> The s390-implementation of unwind user fp could check whether the return
> address is a valid IP.  This is how it is implemented in the existing
> stack tracer in arch/s390/kernel/stacktrace.c:
> 
> static inline bool ip_invalid(unsigned long ip)
> {
> 	/* ABI requires IPs to be 2-byte aligned */
> 	if (ip & 1)
> 		return true;
> 	if (ip < mmap_min_addr)
> 		return true;
> 	if (ip >= current->mm->context.asce_limit)
> 		return true;
> 	return false;
> }
> 
> It could then either stop or return some magic value
> (e.g. PERF_CONTEXT_MAX - 1) to indicate that the IP is invalid and
> continue.  Actually I would prefer to continue so that a user an see
> that there is something odd with the stack trace.

Agreed.

> 
> Alternatively such a check could possibly also be implemented in the
> common undwind user, if the address space limits are known in common
> code, or as an architecture-specific hook.  In general I tend to at
> least add a check whether the IP is zero, as this is used on several
> architectures as indication for outermost frames (usually in
> combination with a FP of zero).

Not sure about the address space limits across archs.  It'd be easier if
the kernel returns any invalid value like PERF_CONTEXT_MAX - 1 or simply
0. :)

> 
> >>
> >> Is there otherwise guidance how unwind user and/or the s390
> >> implementation should deal with such IPs?  Should it stop taking the
> >> deferred calltrace?  Should it substitute those with e.g 0, so that
> >> perf can display them?
> 
> 
> >> Sample for IP == ffffffffffffff (perf does not display any call chain):
> ...
> >> # perf report -D
> >> ...
> >> 44004346257 0x17718 [0x40]: PERF_RECORD_SAMPLE(IP, 0x2): 1082/1084: 0x3ffa3e413aa period: 1001001 addr: 0
> >> ... FP chain: nr:2
> >> .....  0: fffffffffffffd80
> >> .....  1: 0000000400000079
> >> ...... (deferred)
> >>  ... thread: java:1084
> >>  ...... dso: /tmp/perf-1082.map
> >>
> >> 0x17758@perf.data [0xd0]: event: 22
> >> .
> >> . ... raw event: size 208 bytes
> ...
> >>
> >> 44004348864 0x17758 [0xd0]: PERF_RECORD_CALLCHAIN_DEFERRED(IP, 0x2): 1082/1084: 0x400000079
> >> ... FP chain: nr:21
> >> .....  0: 000003ffa3e413aa
> >> .....  1: 000003ff3809e2d0
> >> .....  2: 000003ff3809e130
> >> .....  3: 000003ffb95fdf68
> >> .....  4: 0000000000000000
> >> .....  5: 000003ffb95fe128
> >> .....  6: 000003ffb95fe1d0
> >> .....  7: 005780888e7647a5
> >> .....  8: 000003ffa3e437f2
> >> .....  9: ffffffffffffffff <-- !
> >> ..... 10: 000003ffa3e4a1fc
> >> ..... 11: 0000000000000000
> >> ..... 12: 000003ffa3e37900
> >> ..... 13: 000003ffa3e41080
> >> ..... 14: 000003ffb9dd11de
> >> ..... 15: 000003ffb9e8df92
> >> ..... 16: 000003ffb9e90e86
> >> ..... 17: 000003ffbab8b07e
> >> ..... 18: 000003ffbab8e040
> >> ..... 19: 000003ffba8abbd8
> >> ..... 20: 000003ffba92b950
> >> : unhandled!
> >>
> >> ...
> >> [next entry]
> >>
> >>
> >> On 11/21/2025 12:48 AM, Namhyung Kim wrote:
> 
> >>> diff --git a/tools/perf/builtin-script.c b/tools/perf/builtin-script.c
> >>
> >>> +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)
> >>> +{
> >>
> >>> +	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)) {
> >>
> >> thread__resolve_callchain()
> >> calls __thread__resolve_callchain()
> >> calls thread__resolve_callchain_sample():
> >>
> >>         for (i = first_call, nr_entries = 0;
> >>              i < chain_nr && nr_entries < max_stack; i++) {
> >> ...
> >>                 ip = chain->ips[j];
> >>                 if (ip < PERF_CONTEXT_MAX)   <-- IP=ff..ff is greater than PERF_CONTEXT_MAX
> >>                        ++nr_entries;
> > 
> > Right.
> > 
> >> ...
> >>                 err = add_callchain_ip(thread, cursor, parent,
> >>                                        root_al, &cpumode, ip,
> >>                                        false, NULL, NULL, 0, symbols);
> >>
> >>                 if (err)
> >>                         return (err < 0) ? err : 0;
> >>
> >> calls add_callchain_ip:
> >>
> >>                if (ip >= PERF_CONTEXT_MAX) {
> >>                        switch (ip) {
> >>                        case PERF_CONTEXT_HV:
> >>                                *cpumode = PERF_RECORD_MISC_HYPERVISOR;
> >>                                break;
> >>                        case PERF_CONTEXT_KERNEL:
> >>                                *cpumode = PERF_RECORD_MISC_KERNEL;
> >>                                break;
> >>                        case PERF_CONTEXT_USER:
> >>                        case PERF_CONTEXT_USER_DEFERRED:
> >>                                *cpumode = PERF_RECORD_MISC_USER;
> >>                                break;
> >>                        default:
> >>                                pr_debug("invalid callchain context: "  <-- IP=ff..ff reaches default case
> >>                                         "%"PRId64"\n", (s64) ip);
> > 
> > We may skip -1 if it's Java and *cpumode is already USER and it's s390.
> > But I'd like to understand the situation first.
> 
> Let's better not add any weird architecture-specific handling.  This is
> also not limited to -1 (and 0), as Java may have used the stack save
> area in any way, so it may be any random value.

I see.  Thanks again for your explanation.

Namhyung

> 
> >>                                /*
> >>                                 * It seems the callchain is corrupted.
> >>                                 * Discard all.
> >>                                 */
> >>                                callchain_cursor_reset(cursor);
> >>                                err = 1;
> >>                                goto out;
> >>                        }
> >>
> >>> +				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);
> >>> +	}
> 
> Thanks and regards,
> Jens
> -- 
> Jens Remus
> Linux on Z Development (D3303)
> +49-7031-16-1128 Office
> jremus@de.ibm.com
> 
> IBM
> 
> IBM Deutschland Research & Development GmbH; Vorsitzender des Aufsichtsrats: Wolfgang Wendt; Geschäftsführung: David Faller; Sitz der Gesellschaft: Böblingen; Registergericht: Amtsgericht Stuttgart, HRB 243294
> IBM Data Privacy Statement: https://www.ibm.com/privacy/
>