JDK-8327169 : serviceability/dcmd/vm/SystemMapTest.java and SystemDumpMapTest.java may fail after JDK-8326586
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 23
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: linux
  • CPU: x86_64
  • Submitted: 2024-03-02
  • Updated: 2024-03-28
  • Resolved: 2024-03-21
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 23
23 b16Fixed
Related Reports
Relates :  
JDK-8326586 - Improve Speed of System.map
Relates :  
JDK-8327475 - Add analysis code for JDK-8327169
Sub Tasks
JDK-8327475 :  
Add analysis code for JDK-8327169 - Resolved
Description
The following test failed in the JDK23 CI:

serviceability/dcmd/vm/SystemMapTest.java

Here's a snippet from the log file:

---------------- stderr ----------------

----------------------------------------

test SystemMapTest.jmx(): failure
java.lang.RuntimeException: '.*0x\\p{XDigit}+ - 0x\\p{XDigit}+ +\\d+.*JAVAHEAP.*' missing from stdout/stderr
	at jdk.test.lib.process.OutputAnalyzer.shouldMatch(OutputAnalyzer.java:371)
	at SystemMapTest.run(SystemMapTest.java:57)
	at SystemMapTest.jmx(SystemMapTest.java:66)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
	at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
	at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
	at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46)
	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
	at org.testng.TestRunner.privateRun(TestRunner.java:764)
	at org.testng.TestRunner.run(TestRunner.java:585)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
	at org.testng.TestNG.runSuites(TestNG.java:1069)
	at org.testng.TestNG.run(TestNG.java:1037)
	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
	at java.base/java.lang.VirtualThread.run(VirtualThread.java:329)

===============================================
serviceability/dcmd/vm/SystemMapTest.java
Total tests run: 1, Passes: 0, Failures: 1, Skips: 0
===============================================

----------System.err:(774/73858)----------


The test task's JVM args for this run are:

-Duse.JTREG_TEST_THREAD_FACTORY=Virtual -XX:+UseZGC -XX:+ZGenerational -XX:-VerifyContinuations

This failure first showed up in jdk-23+13-925-tier5 which only contains the fix for:

JDK-8326586 Improve Speed of System.map

so I've tagged this bug as a regression.
Comments
The fix for this bug is integrated in jdk-23+15-1189.
21-03-2024
Changeset: c434b79c Author: Thomas Stuefe <stuefe@openjdk.org> Date: 2024-03-21 12:13:10 +0000 URL: https://git.openjdk.org/jdk/commit/c434b79cff33e08e4518e92ddddae996dffefe29
21-03-2024
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/18392 Date: 2024-03-20 08:28:45 +0000
20-03-2024
Finally found the reason. I keep a record of the last printed NMT region index in a function-scope-static variable inside the lookup function, to speed up the next lookup. That makes lookup very fast, oftentimes O(1), since the input entries are sorted. However, after a dump is finished, that variable is not rest. If one takes two dumps, and the second dump has fewer NMT mappings, the saved index will point beyond the now-smaller NMT region area list. This does not result in any crash, since the result is that we don't even start working - we never enter the loop inside CachedNMTInformation::lookup() since the start index of that loop is larger than the current number of NMT regions. But it messes up printing, since no NMT regions are found, so none are printed.
20-03-2024
[~stuefe] - Sorry for the delay in getting back this bug... > I added debug output with JDk-8327475. If that error has the analysis patch, could you please append the jtr? The fix for JDK-8327475 was included in jdk-23+14-1061 and the sighting of serviceability/dcmd/vm/SystemDumpMapTest.java that I added above happened in the jdk-23+15-1101-tier5 CI job set. I'm attaching mach5-one-jdk-23+15-1101-tier5-20240315-1218-7841959-tier5-svc-generational-zgc-virtual-serviceability_ttf_virtual-any-nix-x64-debug-788-1710506942-37.log which was executed on a machine running Ubuntu 22.04.
16-03-2024
[~dcubed] I added debug output with JDk-8327475. If that error has the analysis patch, could you please append the jtr?
15-03-2024
Here's a log file snippet from the jdk-23+15-1101-tier5 sighing: serviceability/dcmd/vm/SystemDumpMapTest.java #section:testng ----------messages:(8/351)---------- command: testng SystemDumpMapTest reason: User specified action: run testng SystemDumpMapTest started: Fri Mar 15 12:46:17 UTC 2024 Mode: agentvm Agent id: 18 Additional exports to unnamed modules from @modules: java.base/jdk.internal.misc jdk.internal.jvmstat/sun.jvmstat.monitor finished: Fri Mar 15 12:46:17 UTC 2024 elapsed time (seconds): 0.447 ----------configuration:(16/2094)---------- <snip> ----------System.out:(63/3877)*---------- Running DCMD 'System.dump_map -F=test-map.txt' through 'JMXExecutor' ---------------- stdout ---------------- Memory map dumped to "/opt/mach5/mesos/work_dir/slaves/73e57426-9086-438c-bf1c-51bfaf1790ad-S49928/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/012267fd-4c86-41c5-a57a-7b9d29bb4170/runs/a8317004-49b9-4713-80ee-35b449843312/testoutput/test-support/jtreg_open_test_hotspot_jtreg_serviceability_ttf_virtual/scratch/2/test-map.txt". ---------------- stderr ---------------- ---------------------------------------- Running DCMD 'System.dump_map ' through 'JMXExecutor' ---------------- stdout ---------------- Memory map dumped to "/opt/mach5/mesos/work_dir/slaves/73e57426-9086-438c-bf1c-51bfaf1790ad-S49928/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/012267fd-4c86-41c5-a57a-7b9d29bb4170/runs/a8317004-49b9-4713-80ee-35b449843312/testoutput/test-support/jtreg_open_test_hotspot_jtreg_serviceability_ttf_virtual/scratch/2/vm_memory_map_1878244.txt". ---------------- stderr ---------------- ---------------------------------------- Missing patterns in dump: .*0x\\p{XDigit}+ - 0x\\p{XDigit}+ +\\d+.*JAVAHEAP.* .*0x\\p{XDigit}+ - 0x\\p{XDigit}+ +\\d+.*META.* .*0x\\p{XDigit}+ - 0x\\p{XDigit}+ +\\d+.*CODE.* .*0x\\p{XDigit}+ - 0x\\p{XDigit}+ +\\d+.*STACK.*main.* test SystemDumpMapTest.jmx(): failure java.lang.RuntimeException: java.lang.RuntimeException: Missing patterns at SystemDumpMapTest.run_test(SystemDumpMapTest.java:97) at SystemDumpMapTest.run(SystemDumpMapTest.java:104) at SystemDumpMapTest.jmx(SystemDumpMapTest.java:109) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132) at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599) at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174) at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822) at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147) at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) at java.base/java.util.ArrayList.forEach(ArrayList.java:1597) at org.testng.TestRunner.privateRun(TestRunner.java:764) at org.testng.TestRunner.run(TestRunner.java:585) at org.testng.SuiteRunner.runTest(SuiteRunner.java:384) at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337) at org.testng.SuiteRunner.run(SuiteRunner.java:286) at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218) at org.testng.TestNG.runSuitesLocally(TestNG.java:1140) at org.testng.TestNG.runSuites(TestNG.java:1069) at org.testng.TestNG.run(TestNG.java:1037) at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:102) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333) at java.base/java.lang.VirtualThread.run(VirtualThread.java:329) Caused by: java.lang.RuntimeException: Missing patterns at SystemDumpMapTest.run_test(SystemDumpMapTest.java:93) ... 30 more =============================================== serviceability/dcmd/vm/SystemDumpMapTest.java Total tests run: 1, Passes: 0, Failures: 1, Skips: 0 =============================================== ----------System.err:(20/1333)---------- stdout: [Memory map dumped to "/opt/mach5/mesos/work_dir/slaves/73e57426-9086-438c-bf1c-51bfaf1790ad-S49928/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/012267fd-4c86-41c5-a57a-7b9d29bb4170/runs/a8317004-49b9-4713-80ee-35b449843312/testoutput/test-support/jtreg_open_test_hotspot_jtreg_serviceability_ttf_virtual/scratch/2/test-map.txt". ]; stderr: [] exitValue = -1 stdout: [Memory map dumped to "/opt/mach5/mesos/work_dir/slaves/73e57426-9086-438c-bf1c-51bfaf1790ad-S49928/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/012267fd-4c86-41c5-a57a-7b9d29bb4170/runs/a8317004-49b9-4713-80ee-35b449843312/testoutput/test-support/jtreg_open_test_hotspot_jtreg_serviceability_ttf_virtual/scratch/2/vm_memory_map_1878244.txt". ]; stderr: [] exitValue = -1 java.lang.Exception: failures: 1 at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:104) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) at java.base/java.lang.reflect.Method.invoke(Method.java:580) at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333) at java.base/java.lang.VirtualThread.run(VirtualThread.java:329) JavaTest Message: Test threw exception: java.lang.Exception JavaTest Message: shutting down test result: Failed. Execution failed: `main' threw exception: java.lang.Exception: failures: 1
15-03-2024
[~stuefe] I note that in the failing cases none of these "tags" Memory mappings: CARDTBL GC Card table CDS CDS archives CLASS Class Space CODE Code Heap GC GC support data (e.g. bitmaps) INTERN Internal JAVAHEAP Java Heap JDK allocated by JDK libraries other than VM META Metaspace nodes (non-class) POLL Polling pages STACK (known) Thread Stack TEST JVM internal test mappings are present in the mapping, so whatever mechanism is trying to match memory areas to memory types is simply not working. But I see nothing odd about the map in the failing case.
06-03-2024
[~stuefe] > Was the jtr file attached from a run with ZGC? No. The first failure we saw was with ZGC but not the second for which I attached the jtr file. > Is the error intermittent? Yes > On what platforms does the error happen? Seen on Linux x64 and Aarch64. > What are the configure arguments the failing VM was built with? Hmmm not sure how to map back to that ... I think this is the right one for the Aarch64 failure: [2024-03-05T02:42:16,537Z] ==================================================== [2024-03-05T02:42:16,537Z] A new configuration has been successfully created in [2024-03-05T02:42:16,537Z] /opt/mach5/mesos/work_dir/slaves/0db9c48f-6638-40d0-9a4b-bd9cc7533eb8-S9709/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/2e146dd0-8a61-4b65-b33e-8057b52aee57/runs/15d9aac3-408b-4db0-aee0-c8ddfcd1fed5/workspace/build/linux-aarch64-debug [2024-03-05T02:42:16,537Z] using configure arguments '--with-conf-name=linux-aarch64-debug --with-boot-jdk=/opt/mach5/mesos/work_dir/jib-master/install/jdk/21/35/bundles/linux-aarch64/jdk-21_linux-aarch64_bin.tar.gz/jdk-21 MAKE=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/gnumake-linux_aarch64/4.0+1.0/gnumake-linux_aarch64-4.0+1.0.tar.gz/bin/make --with-jtreg=/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg --with-jib=/opt/mach5/mesos/work_dir/jib-master/install/com/oracle/java/jib/jib/3.0-SNAPSHOT/jib-3.0-20240202.185321-523-distribution.zip/jib-3.0-SNAPSHOT-distribution --with-jmh=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/jmh/1.37+1.0/jmh-1.37+1.0.tar.gz --with-jcov=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/jcov/3.0-16-jdk-asm+1.0/jcov-3.0-16-jdk-asm+1.0.zip/jcov_3.0 --with-devkit=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/devkit-linux_aarch64/gcc13.2.0-OL7.6+1.0/devkit-linux_aarch64-gcc13.2.0-OL7.6+1.0.tar.gz/aarch64-linux-gnu-to-aarch64-linux-gnu --with-gtest=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/gtest/1.14.0+1.0/gtest-1.14.0+1.0.tar.gz/googletest-1.14.0 DOT=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/graphviz-linux_aarch64/9.0.0+1.0/graphviz-linux_aarch64-9.0.0+1.0.tar.gz/dot PANDOC=/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/pandoc-linux_aarch64/2.19.2+1.0/pandoc-linux_aarch64-2.19.2+1.0.tar.gz/pandoc/pandoc --with-jdl=/opt/mach5/mesos/work_dir/jib-master/install/com/oracle/java/jdl/jdl/1.3.1414/jdl-1.3.1414.zip/jdl-1.3.1414 --with-exclude-translations=es,fr,it,ko,pt_BR,sv,ca,tr,cs,sk,ja_JP_A,ja_JP_HA,ja_JP_HI,ja_JP_I,zh_TW,zh_HK --disable-manpages --disable-jvm-feature-shenandoahgc --with-version-build=13 --with-version-pre=ea --with-version-opt=942 --with-source-date=1709606348 --with-zlib=system --disable-dtrace --enable-compatible-cds-alignment --enable-debug --with-default-make-target='product-bundles test-bundles static-libs-bundles''. [2024-03-05T02:42:16,537Z] [2024-03-05T02:42:16,537Z] Configuration summary: [2024-03-05T02:42:16,537Z] * Name: linux-aarch64-debug [2024-03-05T02:42:16,537Z] * Debug level: fastdebug [2024-03-05T02:42:16,537Z] * HS debug level: fastdebug [2024-03-05T02:42:16,537Z] * JVM variants: server [2024-03-05T02:42:16,537Z] * JVM features: server: 'cds compiler1 compiler2 epsilongc g1gc jfr jni-check jvmci jvmti management oracle-src parallelgc serialgc services vm-structs zgc' [2024-03-05T02:42:16,537Z] * OpenJDK target: OS: linux, CPU architecture: aarch64, address length: 64 [2024-03-05T02:42:16,537Z] * Version string: 23-ea+13-942 (23-ea) [2024-03-05T02:42:16,537Z] * Source date: 1709606348 (2024-03-05T02:39:08Z) [2024-03-05T02:42:16,537Z] [2024-03-05T02:42:16,537Z] Tools summary: [2024-03-05T02:42:16,538Z] * Boot JDK: java version "21" 2023-09-19 LTS Java(TM) SE Runtime Environment (build 21+35-LTS-2513) Java HotSpot(TM) 64-Bit Server VM (build 21+35-LTS-2513, mixed mode, sharing) (at /opt/mach5/mesos/work_dir/jib-master/install/jdk/21/35/bundles/linux-aarch64/jdk-21_linux-aarch64_bin.tar.gz/jdk-21) [2024-03-05T02:42:16,538Z] * Toolchain: gcc (GNU Compiler Collection) [2024-03-05T02:42:16,538Z] * Devkit: gcc-13.2.0 - OL7.6 (/opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/devkit-linux_aarch64/gcc13.2.0-OL7.6+1.0/devkit-linux_aarch64-gcc13.2.0-OL7.6+1.0.tar.gz/aarch64-linux-gnu-to-aarch64-linux-gnu) [2024-03-05T02:42:16,538Z] * C Compiler: Version 13.2.0 (at /opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/devkit-linux_aarch64/gcc13.2.0-OL7.6+1.0/devkit-linux_aarch64-gcc13.2.0-OL7.6+1.0.tar.gz/aarch64-linux-gnu-to-aarch64-linux-gnu/bin/gcc) [2024-03-05T02:42:16,538Z] * C++ Compiler: Version 13.2.0 (at /opt/mach5/mesos/work_dir/jib-master/install/jpg/infra/builddeps/devkit-linux_aarch64/gcc13.2.0-OL7.6+1.0/devkit-linux_aarch64-gcc13.2.0-OL7.6+1.0.tar.gz/aarch64-linux-gnu-to-aarch64-linux-gnu/bin/g++)
06-03-2024
ILW = MMM = P3 This was also run with -J-Dtest.java.opts='-XX:+UnlockExperimentalVMOptions -XX:LockingMode=2'
05-03-2024
Sorry, I cannot reproduce it and cannot understand it. Some questions: Was the jtr file attached from a run with ZGC? Is the error intermittent? On what platforms does the error happen? What are the configure arguments the failing VM was built with?
05-03-2024
[~stuefe] I've attached a recent JTR file for this failure.
05-03-2024
Hi [~dcubed], I cannot reproduce it locally. Could you please attach the jtreg file?
03-03-2024