JDK-8251849 : jdk/jfr/startupargs/TestDumpOnExit.java failed with "exitValue = -1073741819"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jfr
  • Affected Version: 16,17
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: windows
  • CPU: x86_64
  • Submitted: 2020-08-14
  • Updated: 2025-01-20
  • Resolved: 2025-01-17
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 20
20Resolved
Related Reports
Duplicate :  
JDK-8295223 - JFR: At most one native periodic event thread at a time
Relates :  
JDK-8214685 - Passing illegal value for JFR startupargs causes SEGV or errors
Relates :  
JDK-8272474 - jdk/jfr/startupargs/TestMemoryOptions.java timed out
Relates :  
JDK-8261603 - vmTestbase/nsk/jvmti/AttachOnDemand/attach024/TestDescription.java failed with "non-zero code -1073741819"
Relates :  
JDK-8253437 - runtime/cds/appcds/jigsaw/modulepath/ModulePathAndCP_JFR.java failed with "exitValue = -1073741819"
Description
The following test failed in the JDK16 CI:

jdk/jfr/startupargs/TestDumpOnExit.java

Here's a snippet from the log file:

Hello from test main
[3.037s][trace][jfr] JFR thread sampling done in 0.0000156 secs with 0 java 0 native samples
[3.053s][trace][jfr] JFR thread sampling done in 0.0000622 secs with 0 java 1 native samples
[3.054s][trace][jfr] JFR thread sampling done in 0.0000096 secs with 0 java 0 native samples
[3.071s][trace][jfr] JFR thread sampling done in 0.0000145 secs with 0 java 0 native samples
[3.083s][trace][jfr] JFR thread sampling done in 0.0000473 secs with 0 java 1 native samples
[3.084s][trace][jfr] JFR thread sampling done in 0.0000138 secs with 0 java 0 native samples
[3.099s][trace][jfr] JFR thread sampling done in 0.0000174 secs with 0 java 0 native samples
[3.114s][trace][jfr] JFR thread sampling done in 0.0000566 secs with 0 java 1 native samples
[3.114s][trace][jfr] JFR thread sampling done in 0.0000105 secs with 0 java 0 native samples
[3.130s][trace][jfr] JFR thread sampling done in 0.0000314 secs with 0 java 0 native samples
[3.146s][trace][jfr] JFR thread sampling done in 0.0004092 secs with 0 java 1 native samples
[3.146s][trace][jfr] JFR thread sampling done in 0.0000129 secs with 0 java 0 native samples
[3.161s][debug][jfr] Recording "1" (1) added chunk T:\\testoutput\\test-support\\jtreg_open_test_jdk_tier1_part3\\tmp\\2020_08_14_19_41_44_19632\\2020_08_14_19_41_44.jfr, current size=199946
[3.161s][trace][jfr] JFR thread sampling done in 0.0000156 secs with 0 java 0 native samples
[3.176s][trace][jfr] JFR thread sampling done in 0.0000555 secs with 0 java 1 native samples
[3.177s][trace][jfr] JFR thread sampling done in 0.0003992 secs with 1 java 0 native samples
[3.179s][trace][jfr] Updated thread sampler for java: 0  ms, native 20 ms
[3.179s][trace][jfr] Disenrolling thread sampler
[3.179s][info ][jfr] Stopped recording "1" (1). Reason "Dump on exit".
[3.193s][trace][jfr] JFR thread sampling done in 0.0004228 secs with 0 java 0 native samples
[3.229s][info ][jfr] Wrote recording "1" (1) to T:\\testoutput\\test-support\\jtreg_open_test_jdk_tier1_part3\\scratch\\0\\dumped.jfr
[3.229s][debug][jfr] Recording "1" (1) removed chunk T:\\testoutput\\test-support\\jtreg_open_test_jdk_tier1_part3\\tmp\\2020_08_14_19_41_44_19632\\2020_08_14_19_41_44.jfr, current size=0
[3.230s][debug][jfr] Repository chunk T:\\testoutput\\test-support\\jtreg_open_test_jdk_tier1_part3\\tmp\\2020_08_14_19_41_44_19632\\2020_08_14_19_41_44.jfr deleted
[3.230s][info ][jfr] Closed recording "1" (1)
[3.255s][info ][jfr] Removed repository T:\\testoutput\\test-support\\jtreg_open_test_jdk_tier1_part3\\tmp\\2020_08_14_19_41_44_19632
];
 stderr: []
 exitValue = -1073741819

java.lang.RuntimeException: Expected to get exit value of [0]

	at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:457)
	at jdk.jfr.startupargs.TestDumpOnExit.testDumponExit(TestDumpOnExit.java:100)
	at jdk.jfr.startupargs.TestDumpOnExit.main(TestDumpOnExit.java:68)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
	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)

JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected to get exit value of [0]

JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected to get exit value of [0]
----------rerun:(43/5099)*----------

Since this is a Tier1 failure I would normally start this
off as a P2. However, the only changeset in the build ID
that's running in the JDK16 CI is macOS specific so I'm
starting this off as a P3.

Also, this failure mode reminds me of one of the failure
sightings in JDK-8214685, but, as far as I know, this test
is not passing bad values.
Comments
The fact we get the raw exit code of C0000005 and there is no hs_err file indicates that this is happening in code outside of the JVM and where there is no VM signal/exception handler in place.
13-08-2021
Trying to understand what this is. Have tried a few experiments, including trying to reproduce it on hosts where it has been observed, but with no luck. It is even hard to artificially reproduce, see below for an example that induce crashes in the VM at certain points. A access violation crash in code wrapped inside the VM SEH handler will return an exit code of 1, not -1073741819. This gives some support to the hypothesis that there is an access violation in code not located inside the VM's SEH, but what that is still unknown. STDOUT: Command line: [c:\ade\github\openjdk\jdk16\build\windows-x86_64-server-release\jdk\bin\java.exe -cp D:\utilities\jtreg\runtime_artifacts\work\classes\jdk\jfr\startupargs\TestStartDuration.d;C:\ade\github\openjdk\jdk16\open\test\jdk\jdk\jfr\startupargs;D:\utilities\jtreg\runtime_artifacts\work\classes\test\lib;C:\ade\github\openjdk\jdk16\open\test\lib;D:\utilities\jtreg\runtime_artifacts\work\classes\test\jdk;C:\ade\github\openjdk\jdk16\open\test\jdk;D:\utilities\jtreg\jtreg\lib\javatest.jar;D:\utilities\jtreg\jtreg\lib\jtreg.jar -XX:+ShowMessageBoxOnError -XX:StartFlightRecording=name=TestStartDuration,duration=1s jdk.jfr.startupargs.TestStartDuration$TestValues PT1S wait ] [2020-12-17T11:27:35.670185800Z] Gathering output for process 31980 [2020-12-17T11:27:40.533353600Z] Waiting for completion for process 31980 [2020-12-17T11:27:40.533353600Z] Waiting for completion finished for process 31980 Output and diagnostic info for process 31980 was saved into 'pid-31980-output.log' [2020-12-17T11:27:40.541362800Z] Waiting for completion for process 31980 [2020-12-17T11:27:40.541362800Z] Waiting for completion finished for process 31980 [2020-12-17T11:27:40.541362800Z] Waiting for completion for process 31980 [2020-12-17T11:27:40.541362800Z] Waiting for completion finished for process 31980 STDERR: stdout: [# # A fatal error has been detected by the Java Runtime Environment: # # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x00007ffa7dad9061, pid=31980, tid=33428 # # JRE version: Java(TM) SE Runtime Environment (16.0) (build 16-internal+0-2020-09-30-1724291.MGRONLUN.open) # Java VM: Java HotSpot(TM) 64-Bit Server VM (16-internal+0-2020-09-30-1724291.MGRONLUN.open, mixed mode, tiered, compressed oops, g1 gc, windows-amd64) # Problematic frame: # V [jvm.dll+0x3b9061] JfrRecorderService::start+0x161 # # No core dump will be written. Minidumps are not enabled by default on client versions of Windows # # JFR recording file will be written. hs_err_pid31980.jfr # # An error report file with more information is saved as: # D:\utilities\jtreg\runtime_artifacts\work\jdk\jfr\startupargs\TestStartDuration\hs_err_pid31980.log # # If you would like to submit a bug report, please visit: # https://bugreport.java.com/bugreport/crash.jsp # The crash happened outside the Java Virtual Machine in native code. # See problematic frame for where to report the bug. # ]; stderr: [] exitValue = 1 java.lang.RuntimeException: Expected to get exit value of [0] at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:457) at jdk.jfr.startupargs.TestStartDuration.testDurationInRange(TestStartDuration.java:63) at jdk.jfr.startupargs.TestStartDuration.main(TestStartDuration.java:89) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:831) JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected to get exit value of [0] JavaTest Message: shutting down test
17-12-2020
A possibility to get some debug information from the exiting process could be to use GFLAGS, Silent Process Exit feature: https://docs.microsoft.com/en-us/windows-hardware/drivers/debugger/registry-entries-for-silent-process-exit This would require setting GFLAGS settings on the problematic host and trying to reproduce it on that machine (to get a .mdmp file on silent exit) I have not been able to reproduce this locally.
25-09-2020
ILW = HLM = P3
18-08-2020
Exit code corresponds to: C0000005 Which seems to be an access violation, specifically (according to some web reports) a buffer overrun.
16-08-2020