Bug ID: JDK-8303168 AsyncGetCallTrace/MyPackage/ASGCTBaseTest.java failed with "GetStackTrace and AsyncGetCallTrace return different number of frames"

JDK-8303168 : AsyncGetCallTrace/MyPackage/ASGCTBaseTest.java failed with "GetStackTrace and AsyncGetCallTrace return different number of frames"

Type: Bug
Component: hotspot
Sub-Component: svc
Affected Version: 17,21,22

Priority: P4
Status: In Progress
Resolution: Unresolved
OS: linux
CPU: x86_64,aarch64

Submitted: 2023-02-24
Updated: 2024-05-09

Versions (Unresolved/Resolved/Fixed)

The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.

Other
tbdUnresolved

Related Reports

Relates :

JDK-8302320 - AsyncGetCallTrace obtains too few frames in sanity test

Sub Tasks

JDK-8304005 :	ProblemList serviceability/AsyncGetCallTrace/MyPackage/ASGCTBaseTest.java on linux-x64 in Xcomp mode - Resolved
JDK-8319067 :	ProblemList serviceability/AsyncGetCallTrace/MyPackage/ASGCTBaseTest.java on linux-aarch64 in Xcomp mode - Resolved

Description

The following test failed in the JDK21 CI:

serviceability/AsyncGetCallTrace/MyPackage/ASGCTBaseTest.java

Here's a log file snippet:

#section:main
----------messages:(6/325)----------
command: main -agentlib:AsyncGetCallTraceTest MyPackage.ASGCTBaseTest
reason: User specified action: run main/othervm/native -agentlib:AsyncGetCallTraceTest MyPackage.ASGCTBaseTest 
started: Fri Feb 24 11:27:44 UTC 2023
Mode: othervm [/othervm specified]
finished: Fri Feb 24 11:28:11 UTC 2023
elapsed time (seconds): 27.859
----------configuration:(0/0)----------
----------System.out:(0/0)----------
----------System.err:(93/4343)----------
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetJMethodIDs: Error in GetClassMethods: 22
GetStackTrace and AsyncGetCallTrace return different number of frames: 11 vs 5)java.lang.RuntimeException: AsyncGetCallTrace call failed.
	at MyPackage.ASGCTBaseTest.main(ASGCTBaseTest.java:52)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:578)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:125)
	at java.base/java.lang.Thread.run(Thread.java:1623)

JavaTest Message: Test threw exception: java.lang.RuntimeException: AsyncGetCallTrace call failed.
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.RuntimeException: AsyncGetCallTrace call failed.
----------rerun:(46/6853)*----------

Comments

I totally forgot about the issue, but I'm happy to answer any questions if I can help.
09-05-2024
> Is that the same thing? No. I'm going to look into it / ask people that are more knowledgeable.
08-03-2023
> Interestingly: No, `sender_blob->is_deoptimization_stub()` returns false. Is that the same thing? If it is not a deopt entry then how can removing the "nm->is_deopt_entry(sender_pc)" affect the control flow?
08-03-2023
> So the code is a deopt entry? Interestingly: No, `sender_blob->is_deoptimization_stub()` returns false. > Are deopt entries generally "safe for sender"? The code used to walk over this frame (`frame::sender_raw`) does not seem to handle deoptimization stubs differently from other compiled frames/stubs.
08-03-2023
So the code is a deopt entry? Are deopt entries generally "safe for sender"?
08-03-2023
The reason for this bug lies (again) in the `frame::safe_for_sender` method: The relevant code starts at line 216 [0]: ``` CompiledMethod* nm = sender_blob->as_compiled_method_or_null(); if (nm != NULL) { if (nm->is_deopt_mh_entry(sender_pc) \|\| nm->is_deopt_entry(sender_pc) \|\| nm->method()->is_method_handle_intrinsic()) { return false; } } ``` The test case succeeds when removing the middle check `nm->is_deopt_entry(sender_pc)`: ``` CompiledMethod* nm = sender_blob->as_compiled_method_or_null(); if (nm != NULL) { if (nm->is_deopt_mh_entry(sender_pc)\|\| nm->method()->is_method_handle_intrinsic()) { return false; } } ``` Running the code with my jdk-profiling-tester did not find any crashes due to this. The code that uses the `safe_for_sender` method seems to be able to handle deopts. I found this broken condition also affected the normal runs during my trace_validation tests. I can add a PR that fixes the issue as described. [0] https://github.com/openjdk/jdk/blob/db483a38a815f85bd9668749674b5f0f6e4b27b4/src/hotspot/cpu/x86/frame_x86.cpp#L216
08-03-2023
I can reproduce the issue.
08-03-2023
Oh, sorry. I work on it this morning.
08-03-2023
[~jbechberger] are you looking into this? This is causing some noise in our CI so if it isn't going to be fixed I will get the test ProblemListed. Thanks.
07-03-2023
Thanks, this makes far more sense now. I'm looking into ASGCT segfaults and errors today anyway, so I'm going to take a look. (I'm working on https://github.com/parttimenerd/trace_validation which should help to discover some bugs by comparing ASGCT with GST).
01-03-2023
[~jbechberger] The test is failing in our tier 7 CI run when executed with the following flags: -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:+TieredCompilation -XX:+DeoptimizeALot Most likely -Xcomp is sufficient to show the problem. With -Xcomp all Java code is compiled in advance and so many frames can be inlined resulting in different stacktraces. It may suffice to just mark the test as not being runnable in Xcomp mode: @requires vm.compMode != "Xcomp"
28-02-2023
[~dholmes] could you clarify what this means for the bug? I'm slightly confused.
28-02-2023
Looks like it is an Xcomp issue: -J-Dtest.java.opts='-Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:+TieredCompilation -XX:+DeoptimizeALot'
27-02-2023
[~jbechberger] it seems this test is still broken.
26-02-2023
This issue was recently fixed: JDK-8302320 AsyncGetCallTrace obtains too few frames in sanity test That fix was integrated in jdk-21+11-869 and these failures happened in jdk-21+11-906.
24-02-2023