JDK-8269556 : sun/tools/jhsdb/JShellHeapDumpTest.java fails with RuntimeException 'JShellToolProvider' missing from stdout/stderr
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 17,18,19
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2021-06-29
  • Updated: 2022-08-01
  • Resolved: 2021-12-13
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.
JDK 17 JDK 19
17.0.5-oracleFixed 19 b02Fixed
Related Reports
Relates :  
Description
Test sun/tools/jhsdb/JShellHeapDumpTest.java still fails with RuntimeException 'JShellToolProvider' missing from stdout/stderr

The log is:

Starting Jshell
[JShell]:c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk\\jdk-17\\fastdebug\\bin\\jshell.exe
[JShell] |  Welcome to JShell -- Version 17-ea
[JShell] |  For an introduction type: /help intro
Jshell Started in 6294ms
Starting jmap against 3536
[2021-06-22T04:05:55.686558Z] Gathering output for process 9220
[2021-06-22T04:07:41.159886400Z] Waiting for completion for process 9220
[2021-06-22T04:07:41.175476500Z] Waiting for completion finished for process 9220
Output and diagnostic info for process 9220 was saved into 'pid-9220-output.log'
jhsdb jmap stdout:
Attaching to process ID 3536, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 17-ea+26-LTS-2439
heap written to T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\scratch\\0\\jhsdb.jmap.heap.1624334741094.hprof

jhsdb jmap stderr:

###### End of all output:
[2021-06-22T04:07:41.894334400Z] Waiting for completion for process 9220
[2021-06-22T04:07:41.894334400Z] Waiting for completion finished for process 9220
Destroying jshell
Jshell destroyed
Dump file created Tue Jun 22 04:05:56 UTC 2021
SerialNo 14
  java.io.FileInputStream.read0()I (FileInputStream.java:(native method))
  java.io.FileInputStream.read()I (FileInputStream.java:228)
  jdk.internal.org.jline.utils.NonBlockingInputStreamImpl.run()V (NonBlockingInputStreamImpl.java:216)
  jdk.internal.org.jline.utils.NonBlockingInputStreamImpl$$Lambda$529+0x0000000801206b88.run()V (:(unknown))
  java.lang.Thread.run()V (Thread.java:833)
SerialNo 13
  jdk.internal.misc.Unsafe.park(ZJ)V (Unsafe.java:(native method))
  java.util.concurrent.locks.LockSupport.park()V (LockSupport.java:341)
  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block()Z (AbstractQueuedSynchronizer.java:506)
  java.util.concurrent.ForkJoinPool.unmanagedBlock(Ljava/util/concurrent/ForkJoinPool$ManagedBlocker;)V (ForkJoinPool.java:3463)
  java.util.concurrent.ForkJoinPool.managedBlock(Ljava/util/concurrent/ForkJoinPool$ManagedBlocker;)V (ForkJoinPool.java:3434)
  java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await()V (AbstractQueuedSynchronizer.java:1623)
  java.util.concurrent.LinkedBlockingQueue.take()Ljava/lang/Object; (LinkedBlockingQueue.java:435)
  java.util.concurrent.ThreadPoolExecutor.getTask()Ljava/lang/Runnable; (ThreadPoolExecutor.java:1062)
  java.util.concurrent.ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V (ThreadPoolExecutor.java:1122)
  java.util.concurrent.ThreadPoolExecutor$Worker.run()V (ThreadPoolExecutor.java:635)
  java.lang.Thread.run()V (Thread.java:833)
SerialNo 12
  sun.nio.ch.SocketDispatcher.read0(Ljava/io/FileDescriptor;JI)I (SocketDispatcher.java:(native method))
  sun.nio.ch.SocketDispatcher.read(Ljava/io/FileDescriptor;JI)I (SocketDispatcher.java:46)
  sun.nio.ch.NioSocketImpl.tryRead(Ljava/io/FileDescriptor;[BII)I (NioSocketImpl.java:261)
  sun.nio.ch.NioSocketImpl.implRead([BII)I (NioSocketImpl.java:312)
  sun.nio.ch.NioSocketImpl.read([BII)I (NioSocketImpl.java:350)
  sun.nio.ch.NioSocketImpl$1.read([BII)I (NioSocketImpl.java:803)
  java.net.Socket$SocketInputStream.read([BII)I (Socket.java:966)
  java.net.Socket$SocketInputStream.read()I (Socket.java:961)
  java.io.FilterInputStream.read()I (FilterInputStream.java:82)
  jdk.jshell.execution.DemultiplexInput.run()V (DemultiplexInput.java:58)
SerialNo 11
  java.lang.Object.wait(J)V (Object.java:(native method))
  java.lang.Object.wait()V (Object.java:338)
  com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(J)Lcom/sun/tools/jdi/EventSetImpl; (EventQueueImpl.java:190)
  com.sun.tools.jdi.EventQueueImpl.remove(J)Lcom/sun/jdi/event/EventSet; (EventQueueImpl.java:97)
  com.sun.tools.jdi.EventQueueImpl.remove()Lcom/sun/jdi/event/EventSet; (EventQueueImpl.java:83)
  jdk.jshell.execution.JdiEventHandler.run()V (JdiEventHandler.java:79)
  java.lang.Thread.run()V (Thread.java:833)
SerialNo 10
  sun.nio.ch.SocketDispatcher.read0(Ljava/io/FileDescriptor;JI)I (SocketDispatcher.java:(native method))
  sun.nio.ch.SocketDispatcher.read(Ljava/io/FileDescriptor;JI)I (SocketDispatcher.java:46)
  sun.nio.ch.NioSocketImpl.tryRead(Ljava/io/FileDescriptor;[BII)I (NioSocketImpl.java:261)
  sun.nio.ch.NioSocketImpl.implRead([BII)I (NioSocketImpl.java:312)
  sun.nio.ch.NioSocketImpl.read([BII)I (NioSocketImpl.java:350)
  sun.nio.ch.NioSocketImpl$1.read([BII)I (NioSocketImpl.java:803)
  java.net.Socket$SocketInputStream.read([BII)I (Socket.java:966)
  java.net.Socket$SocketInputStream.read()I (Socket.java:961)
  com.sun.tools.jdi.SocketConnection.readPacket()[B (SocketConnection.java:82)
  com.sun.tools.jdi.TargetVM.run()V (TargetVM.java:124)
  java.lang.Thread.run()V (Thread.java:833)
SerialNo 9
  java.lang.Object.wait(J)V (Object.java:(native method))
  java.lang.Object.wait()V (Object.java:338)
  com.sun.tools.jdi.EventQueueImpl.removeUnfiltered(J)Lcom/sun/tools/jdi/EventSetImpl; (EventQueueImpl.java:190)
  com.sun.tools.jdi.EventQueueImpl.removeInternal()Lcom/sun/jdi/event/EventSet; (EventQueueImpl.java:125)
  com.sun.tools.jdi.InternalEventHandler.run()V (InternalEventHandler.java:61)
  java.lang.Thread.run()V (Thread.java:833)
SerialNo 8
  java.lang.Object.wait(J)V (Object.java:(native method))
  java.lang.ref.ReferenceQueue.remove(J)Ljava/lang/ref/Reference; (ReferenceQueue.java:155)
  jdk.internal.ref.CleanerImpl.run()V (CleanerImpl.java:140)
  java.lang.Thread.run()V (Thread.java:833)
  jdk.internal.misc.InnocuousThread.run()V (InnocuousThread.java:162)
SerialNo 7
SerialNo 6
SerialNo 5
SerialNo 4
  java.lang.Object.wait(J)V (Object.java:(native method))
  java.lang.ref.ReferenceQueue.remove(J)Ljava/lang/ref/Reference; (ReferenceQueue.java:155)
  java.lang.ref.ReferenceQueue.remove()Ljava/lang/ref/Reference; (ReferenceQueue.java:176)
  java.lang.ref.Finalizer$FinalizerThread.run()V (Finalizer.java:172)
SerialNo 3
  java.lang.ref.Reference.waitForReferencePendingList()V (Reference.java:(native method))
  java.lang.ref.Reference.processPendingReferences()V (Reference.java:253)
  java.lang.ref.Reference$ReferenceHandler.run()V (Reference.java:215)
SerialNo 2
SerialNo 1

----------System.err:(18/1331)----------
java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr
	at JShellHeapDumpTest.printStackTraces(JShellHeapDumpTest.java:110)
	at JShellHeapDumpTest.testHeapDump(JShellHeapDumpTest.java:127)
	at JShellHeapDumpTest.main(JShellHeapDumpTest.java:169)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr
	at JShellHeapDumpTest.printStackTraces(JShellHeapDumpTest.java:107)
	... 8 more

JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr
----------rerun:(49/5757)*----------
cd 'T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\scratch\\0' && \\
JDK8_HOME='c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk\\16\\36\\bundles\\windows-x64\\jdk-16_windows-x64_bin.zip\\jdk-16' \\
JIB_DATA_DIR=C:/ade/mesos/work_dir/jib-master \\
JIB_HOME='c:\\ade\\mesos\\work_dir\\jib-master\\install\\com\\oracle\\java\\jib\\jib\\3.0-SNAPSHOT\\jib-3.0-20210618.184637-471-distribution.zip\\jib-3.0-SNAPSHOT-distribution' \\
JTREG_EXTRA_PROBLEM_LISTS=ProblemList-Xcomp.txt \\
JTREG_KEYWORDS='"!jfr & !headful"' \\
JTREG_TIMEOUT_FACTOR=10 \\
JTREG_VERBOSE=fail,error,time \\
PATH='C:\\ade\\mesos\\work_dir\\jib-master\\install\\jpg\\infra\\builddeps\\wix\\3.11.1+1.0\\wix-3.11.1+1.0.zip;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\6\\1\\bundles\\jtreg-6+1.zip\\jtreg\\bin;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jpg\\infra\\builddeps\\gnumake-cygwin_x64\\4.0+1.0\\gnumake-cygwin_x64-4.0+1.0.tar.gz\\cygwin\\bin;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk\\16\\36\\bundles\\windows-x64\\jdk-16_windows-x64_bin.zip\\jdk-16\\bin;C:\\cygwin\\usr\\local\\bin;C:\\cygwin\\bin;C:\\cygwin\\bin;C:\\cygwin\\bin;C:\\WINDOWS\\system32;C:\\WINDOWS;C:\\WINDOWS\\System32\\Wbem;C:\\WINDOWS\\System32\\WindowsPowerShell\\v1.0;C:\\WINDOWS\\System32\\OpenSSH;C:\\cygwin\\bin;C:\\Users\\cyg_server\\AppData\\Local\\Microsoft\\WindowsApps' \\
SystemDrive=C: \\
SystemRoot='C:\\WINDOWS' \\
TEMP='C:\\cygwin\\tmp' \\
TEST_IMAGE_DIR='c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.test' \\
TMP='C:\\cygwin\\tmp' \\
TZ=Etc/GMT \\
_NT_SYMBOL_PATH=' c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk_symbols\\jdk-17\\fastdebug\\bin;c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk_symbols\\jdk-17\\fastdebug\\bin\\server' \\
windir='C:\\WINDOWS' \\
CLASSPATH='T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\sun\\tools\\jhsdb\\JShellHeapDumpTest.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk\\sun\\tools\\jhsdb;T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\6\\1\\bundles\\jtreg-6+1.zip\\jtreg\\lib\\javatest.jar;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\6\\1\\bundles\\jtreg-6+1.zip\\jtreg\\lib\\jtreg.jar' \\
    'c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk\\jdk-17\\fastdebug\\bin\\java' \\
        -Dtest.vm.opts='-Xmx768m -XX:MaxRAMPercentage=4.16667 -Djava.io.tmpdir=t:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\tmp -ea -esa' \\
        -Dtest.tool.vm.opts='-J-Xmx768m -J-XX:MaxRAMPercentage=4.16667 -J-Djava.io.tmpdir=t:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\tmp -J-ea -J-esa' \\
        -Dtest.compiler.opts= \\
        -Dtest.java.opts='-XX:+CreateCoredumpOnCrash -XX:+IgnoreUnrecognizedVMOptions -XX:+UseParallelGC -Xcomp -XX:-TieredCompilation' \\
        -Dtest.jdk='c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk\\jdk-17\\fastdebug' \\
        -Dcompile.jdk='c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.jdk\\jdk-17\\fastdebug' \\
        -Dtest.timeout.factor=10.0 \\
        -Dtest.nativepath='c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.test\\jdk\\jtreg\\native' \\
        -Dtest.root='C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk' \\
        -Dtest.name=sun/tools/jhsdb/JShellHeapDumpTest.java \\
        -Dtest.file='C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk\\sun\\tools\\jhsdb\\JShellHeapDumpTest.java' \\
        -Dtest.src='C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk\\sun\\tools\\jhsdb' \\
        -Dtest.src.path='C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk\\sun\\tools\\jhsdb;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\lib' \\
        -Dtest.classes='T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\sun\\tools\\jhsdb\\JShellHeapDumpTest.d' \\
        -Dtest.class.path='T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\sun\\tools\\jhsdb\\JShellHeapDumpTest.d;T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\test\\lib' \\
        -Dtest.class.path.prefix='T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\sun\\tools\\jhsdb\\JShellHeapDumpTest.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\src.full\\open\\test\\jdk\\sun\\tools\\jhsdb;T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\classes\\0\\test\\lib' \\
        -Dtest.modules='jdk.hotspot.agent java.management' \\
        --add-modules jdk.hotspot.agent,java.management \\
        -Xmx768m \\
        -XX:MaxRAMPercentage=4.16667 \\
        '-Djava.io.tmpdir=t:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\tmp' \\
        -ea \\
        -esa \\
        -XX:+CreateCoredumpOnCrash \\
        -XX:+IgnoreUnrecognizedVMOptions \\
        -XX:+UseParallelGC \\
        -Xcomp \\
        -XX:-TieredCompilation \\
        '-Djava.library.path=c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-17+26-2439\\windows-x64-debug.test\\jdk\\jtreg\\native' \\
        com.sun.javatest.regtest.agent.MainWrapper 'T:\\testoutput\\test-support\\jtreg_open_test_jdk_jdk_svc\\sun\\tools\\jhsdb\\JShellHeapDumpTest.d\\main.0.jta'
result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr


test result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: 'JShellToolProvider' missing from stdout/stderr
Comments
Fix request [17u] I backport this for parity with 17.0.5-oracle. No risk, only a test change. Clean backport. Test passes. SAP nightly testing passed.
31-07-2022

A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/607 Date: 2022-07-29 15:14:17 +0000
29-07-2022

Changeset: db502d30 Author: Chris Plummer <cjplummer@openjdk.org> Date: 2021-12-13 19:02:12 +0000 URL: https://git.openjdk.java.net/jdk/commit/db502d30a42847f69273f48378f230d9d55eb8d6
13-12-2021

In the previous comment I show how once the main thread has stabilized, it should be blocked on java.lang.Object.wait(). I thought this wait was untimed, but it is timed for 100ms. That means every 100ms this thread wakes up for a bit before waiting again. When a thread is awak, it's possible that there might be times where SA cannot get its stack trace (this is always true of active threads, especially when calling out to native). So that means no matter how long the test delays doing the heap dump (which is how the stack trace is produced), it still might not be able to get the stack trace of the main thread, thus reproducing this CR. I showed that it seems to be failing just as much when delaying 20 seconds as it does with the current delay of 2 seconds, although fails very rarely, and only when adding an extra check for NonBlockingInputStreamImpl.read. I think the simplest fix here is to just retry the heap dump after one failure. This failure is so rare, that should be enough to make it extremely unlikely that we ever see it again.
06-12-2021

The main thread is missing from the stack dump. This is the same issue we saw with JDK-8228625. In that case the stack dump was being requested before the main thread could start up. It was fixed by first waiting for the jshell prompt, and then waiting another 2 seconds. I think the issue in this CR is that waiting 2 seconds isn't always enough to get the main thread fully started and blocked waiting for input. It is important that it is blocked, because on rare occasions SA cannot get the stack trace for an active thread. I looked at a few passing test cases. Most of them have the following stack trace for the main thread: java.lang.Object.wait(J)V (Object.java:(native method)) jdk.internal.org.jline.utils.NonBlockingInputStreamImpl.read(JZ)I (NonBlockingInputStreamImpl.java:139) jdk.internal.org.jline.terminal.impl.DumbTerminal$1.read(JZ)I (DumbTerminal.java:49) jdk.internal.org.jline.utils.NonBlockingInputStream.read(J)I (NonBlockingInputStream.java:62) jdk.internal.org.jline.utils.NonBlocking$NonBlockingInputStreamReader.read(JZ)I (NonBlocking.java:168) jdk.internal.org.jline.utils.NonBlockingReader.read(J)I (NonBlockingReader.java:57) jdk.internal.org.jline.keymap.BindingReader.readCharacter()I (BindingReader.java:160) jdk.internal.org.jline.keymap.BindingReader.readBinding(Ljdk/internal/org/jline/keymap/KeyMap;Ljdk/internal/org/jline/keymap/KeyMap;Z)Ljava/lang/Object; (BindingReader.java:110) jdk.internal.org.jline.keymap.BindingReader.readBinding(Ljdk/internal/org/jline/keymap/KeyMap;Ljdk/internal/org/jline/keymap/KeyMap;)Ljava/lang/Object; (BindingReader.java:61) jdk.internal.org.jline.reader.impl.LineReaderImpl.doReadBinding(Ljdk/internal/org/jline/keymap/KeyMap;Ljdk/internal/org/jline/keymap/KeyMap;)Ljava/lang/Object; (LineReaderImpl.java:913) jdk.internal.org.jline.reader.impl.LineReaderImpl.readBinding(Ljdk/internal/org/jline/keymap/KeyMap;Ljdk/internal/org/jline/keymap/KeyMap;)Ljdk/internal/org/jline/reader/Binding; (LineReaderImpl.java:946) jdk.internal.jshell.tool.ConsoleIOContext$2.readBinding(Ljdk/internal/org/jline/keymap/KeyMap;Ljdk/internal/org/jline/keymap/KeyMap;)Ljdk/internal/org/jline/reader/Binding; (ConsoleIOContext.java:172) jdk.internal.org.jline.reader.impl.LineReaderImpl.readLine(Ljava/lang/String;Ljava/lang/String;Ljdk/internal/org/jline/reader/MaskingCallback;Ljava/lang/String;)Ljava/lang/String; (LineReaderImpl.java:637) jdk.internal.org.jline.reader.impl.LineReaderImpl.readLine(Ljava/lang/String;)Ljava/lang/String; (LineReaderImpl.java:454) jdk.internal.jshell.tool.ConsoleIOContext.readLine(Ljava/lang/String;Ljava/lang/String;ZLjava/lang/String;)Ljava/lang/String; (ConsoleIOContext.java:248) jdk.internal.jshell.tool.JShellTool.getInput(Ljava/lang/String;)Ljava/lang/String; (JShellTool.java:1275) jdk.internal.jshell.tool.JShellTool.run(Ljdk/internal/jshell/tool/IOContext;)Z (JShellTool.java:1209) jdk.internal.jshell.tool.JShellTool.start([Ljava/lang/String;)I (JShellTool.java:995) jdk.internal.jshell.tool.JShellToolBuilder.start([Ljava/lang/String;)I (JShellToolBuilder.java:261) jdk.internal.jshell.tool.JShellToolProvider.main([Ljava/lang/String;)V (JShellToolProvider.java:120) However, I did spot one that looked like: java.lang.invoke.LambdaProxyClassArchive.find(Ljava/lang/Class;Ljava/lang/String;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodHandle;Ljava/lang/invoke/MethodType;Z[Ljava/lang/Class;[Ljava/lang/invoke/MethodType;)Ljava/lang/Class; (LambdaProxyClassArchive.java:112) java.lang.invoke.InnerClassLambdaMetafactory.spinInnerClass()Ljava/lang/Class; (InnerClassLambdaMetafactory.java:304) java.lang.invoke.InnerClassLambdaMetafactory.buildCallSite()Ljava/lang/invoke/CallSite; (InnerClassLambdaMetafactory.java:228) java.lang.invoke.LambdaMetafactory.metafactory(Ljava/lang/invoke/MethodHandles$Lookup;Ljava/lang/String;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodType;Ljava/lang/invoke/MethodHandle;Ljava/lang/invoke/MethodType;)Ljava/lang/invoke/CallSite; (LambdaMetafactory.java:341) java.lang.invoke.LambdaForm$DMH+0x0000000801108000.invokeStatic(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (LambdaForm$DMH:(unknown)) java.lang.invoke.Invokers$Holder.invokeExact_MT(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; (Invokers$Holder:(unknown)) java.lang.invoke.BootstrapMethodInvoker.invoke(Ljava/lang/Class;Ljava/lang/invoke/MethodHandle;Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Class;)Ljava/lang/Object; (BootstrapMethodInvoker.java:134) java.lang.invoke.CallSite.makeSite(Ljava/lang/invoke/MethodHandle;Ljava/lang/String;Ljava/lang/invoke/MethodType;Ljava/lang/Object;Ljava/lang/Class;)Ljava/lang/invoke/CallSite; (CallSite.java:315) java.lang.invoke.MethodHandleNatives.linkCallSiteImpl(Ljava/lang/Class;Ljava/lang/invoke/MethodHandle;Ljava/lang/String;Ljava/lang/invoke/MethodType;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/invoke/MemberName; (MethodHandleNatives.java:281) java.lang.invoke.MethodHandleNatives.linkCallSite(Ljava/lang/Object;ILjava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/invoke/MemberName; (MethodHandleNatives.java:271) jdk.internal.jshell.tool.ConsoleIOContext.<init>(Ljdk/internal/jshell/tool/JShellTool;Ljava/io/InputStream;Ljava/io/PrintStream;Z)V (ConsoleIOContext.java:217) jdk.internal.jshell.tool.JShellTool.start([Ljava/lang/String;)I (JShellTool.java:982) jdk.internal.jshell.tool.JShellToolBuilder.start([Ljava/lang/String;)I (JShellToolBuilder.java:261) jdk.internal.jshell.tool.JShellToolProvider.main([Ljava/lang/String;)V (JShellToolProvider.java:120) So in this case the main thread is still starting up. Since we got the stack trace, the test passed, but when getting the stack trace of an active method like this, sometimes SA will fail, and then this test will fail. I think the fix is to just add a longer delay to the startup. While working on the fix, I'll temporarily add a check for NonBlockingInputStreamImpl.read just to make sure we are consistently waiting long enough.
29-06-2021