JDK-8242411 : serviceability/sa/ClhsdbCDSJstackPrintAll.java fails with Test ERROR java.lang.RuntimeException: 'LingeredApp.main' missing from stdout/stderr
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 15
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2020-04-09
  • Updated: 2020-04-23
  • Resolved: 2020-04-23
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
tbdResolved
Related Reports
Duplicate :  
JDK-8243455 - Many SA tests can fail due to trying to get the stack trace of an active method
Relates :  
JDK-8200217 - SA: serviceability/sa/ClhsdbJstack.java fails with Test ERROR java.lang.RuntimeException: 'LingeredApp.main' missing from stdout/stderr
Relates :  
JDK-8240781 - serviceability/sa/ClhsdbJdis.java fails with "java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1"
Relates :  
JDK-8211923 - [Testbug] serviceability/sa/ClhsdbFindPC.java ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
Description
serviceability/sa/ClhsdbJstack.java and serviceability/sa/ClhsdbCDSJstackPrintAll.java sometimes fail with the following. Only seems to happen in windows-x64.

 LingeredApp exitValue = 0
java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'LingeredApp.main' missing from stdout/stderr 

	at ClhsdbCDSJstackPrintAll.main(ClhsdbCDSJstackPrintAll.java:117)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.base/java.lang.Thread.run(Thread.java:832)
Caused by: java.lang.RuntimeException: 'LingeredApp.main' missing from stdout/stderr 

	at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:306)
	at ClhsdbLauncher.runCmd(ClhsdbLauncher.java:163)
	at ClhsdbLauncher.run(ClhsdbLauncher.java:200)
	at ClhsdbCDSJstackPrintAll.main(ClhsdbCDSJstackPrintAll.java:113)
	... 6 more

The issue seems to be that for some reason when dumping the main thread, there is no stack trace:

"main" #1 prio=5 tid=0x000001ba6cdaa000 nid=0xfb58 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   JavaThread state: _thread_in_java

Locked ownable synchronizers:
    - None

Other threads are properly showing the full stack trace. The main thread must have been in some sort of state that made SA not try, but there's no clue in the log as to why.
Comments
This is a duplicate of JDK-8243455.
23-04-2020
It's looks like the one second sleep is what prevents this from happening frequently. I changed it to a 1ms sleep, and see this issue quite frequently. It also caused a plethora of other bugs we've seen turn up. For example: JDK-8231634 - SA stack walking fails with "illegal bci" JDK-8240781 - serviceability/sa/ClhsdbJdis.java fails with "java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1" JDK-8211923 - [Testbug] serviceability/sa/ClhsdbFindPC.java ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 JDK-8204994 - SA might fail to attach to process with "Windbg Error: WaitForEvent failed" The "illegal bci" I haven't looked into much, but is likely an SA bug due to SA having issues with (and probably making assumptions about) the state of the stack. The two ArrayIndexOutOfBoundsException are dups. They essentially fail for the same reason reported in this CR. The stack trace of the main thread is missing, and some String splitting logic in the test therefore fails and produces the ArrayIndexOutOfBoundsException.
15-04-2020
I'm not sure if it's the same bug, but I see a similar issue with serviceability/sa/ClhsdbWhere.java. It also fails because there is no stack trace for the main thread. One difference is it is using the clhsdb "where -a" command: ================= hsdb> + where -a Thread 3 Address: 0x00000231bc609000 Java Stack Trace for main Thread state = IN_JAVA ================= There are other stack traces for other threads after this one that look ok. This is what is looks like in the passing case: ================= hsdb> + where -a Thread 4 Address: 0x000002a5fcedb800 Java Stack Trace for main Thread state = BLOCKED - public static native void sleep(long) @0x00000008000f8f40 @bci = 0, pc = 0x000002a590a72ef7 (Interpreted) - public static void main(java.lang.String[]) @0x000002a5ffbb3d98 @bci = 54, line = 499, pc = 0x000002a590a6a3b3 (Interpreted) ================== Notice the thread in the working case is BLOCKED instead of IN_JAVA. I'm not sure of the significance of this w.r.t. being able to dump the thread's stack. Also the original failure described above has the thread state as _thread_in_java, and I justed checked as passing case and it has the state as _thread_blocked, so that seems consistent with the ClhsdbWhere failure. Also, the "where" command uses HTMLGenerator.genHTMLForJavaStackTrace() for the stack dump, which uses the same loop iterator code to iterate over the frames of the thread as is described above for ThreadStackTrace.dumpStack(), so it could be the same issue of having null being returned by thread.getLastJavaVFrameDbg(). for (JavaVFrame vf = thread.getLastJavaVFrameDbg(); vf != null; vf = vf.javaSender()) {
14-04-2020
JDK-8200217 at first seems to fail in the same way (same exception is thrown) but the root cause there is an exception thrown by SA. Newer versions of the test dump this exception, so it it is a bit more obvious now because you'll see the root cause as one of the reasons for the failure. However, there is one failure mentioned in JDK-8200217 that I had previously looked into that seems to be this same issue. The comment I added to JDK-8200217 is the following: ============================= "main" #1 prio=5 tid=0x00007fab2e802000 nid=0x2303 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_in_java Locked ownable synchronizers: - None ============================= Possibly there was an exception that was consumed with no message printed. SA does this in a number of places intentionally while walking the stack, because it might be facing a bad SP. It iterates through a series of potential SP's until it can validate one by walking to the entry frame with it. See for example AMD64CurrentFrameGuess.run(), and also some helpful comments in here: https://bugs.openjdk.java.net/browse/JDK-8231635?focusedCommentId=14297690&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14297690 If there is no error message and no stack for main(), then I'm guessing a valid SP was never found. In ThreadStackTrace.dumpStack() we have: for (JavaVFrame vf = thread.getLastJavaVFrameDbg(); vf != null; vf = vf.javaSender()) { StackFrameInfo frame = new StackFrameInfo(vf); frames.add(frame); depth++; if (maxDepth > 0 && depth == maxDepth) { // Skip frames if more than maxDepth break; } } If AMD64CurrentFrameGuess.run() fails to find a valid SP, it returns false, which eventually works it's way up the call chain as a null result from getLastJavaVFrameDbg(), so we just silently print no frames in this case.
09-04-2020