JDK-8283578 : serviceability/sa/ClhsdbInspect.java fails due to caching Object address between SA attaches
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 20,21,repo-loom
  • Priority: P4
  • Status: Open
  • Resolution: Unresolved
  • Submitted: 2022-03-23
  • Updated: 2024-07-27
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
Duplicate :  
JDK-8317438 - serviceability/sa/ClhsdbInspect.java is transiently failing UnknownOopException on libgraal
Duplicate :  
JDK-8295862 - Test serviceability/sa/ClhsdbInspect.java failing with UnmappedAddressException
Relates :  
JDK-8283010 - serviceability/sa/ClhsdbThread.java failed with "'Base of Stack:' missing from stdout/stderr "
Relates :  
JDK-8284045 - serviceability/sa/ClhsdbFindPC.java#xcomp-core is failing - sun.jvm.hotspot.debugger.UnalignedAddressException: 8baadbabe
Sub Tasks
JDK-8305678 :  
ProblemList serviceability/sa/ClhsdbInspect.java on windows-x64 in Xcomp - Resolved
Description
Starting March 19th I've seen the following error or similar 5 times in Loom CI tier6-comp and tier7-comp testing:

hsdb> + inspect 0x00000000b0300138
Error: sun.jvm.hotspot.debugger.UnmappedAddressException: b0300140
sun.jvm.hotspot.debugger.UnmappedAddressException: b0300140
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208)
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getInt(PageCache.java:96)
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:363)
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCompKlassAddressValue(DebuggerBase.java:477)
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readCompKlassAddress(WindbgDebuggerLocal.java:322)
	at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getCompKlassAddressAt(WindbgAddress.java:79)
	at jdk.hotspot.agent/sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:212)
	at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:181)
	at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor$25.doit(CommandProcessor.java:1109)
	at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2212)
	at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2182)
	at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.run(CommandProcessor.java:2053)
	at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:112)
	at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:44)
	at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:281)
	at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500)

Sometimes instead the exception is UnalignedAddressException. Failures so far have been on linux-x64 and windows-x64. Flags used are:

tier6-comp: -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation
tier7-comp: -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:+TieredCompilation -XX:-DoEscapeAnalysis

The address being inspected (0x00000000b0300138) was gleaned from following part of the jstack output. It's the address that shows up as "waiting to lock", so it appears to be  a java.lang.Class instance that is currently locked.

"Thread-0" #33 prio=5 tid=0x000001dee6ce0040 nid=39056 waiting for monitor entry [0x0000009c9faff000]
   java.lang.Thread.State: BLOCKED (on object monitor)
   JavaThread state: _thread_blocked
 - LingeredAppWithLock.lockMethod(java.lang.Object) @bci=3, line=30, pc=0x000001ded4b1ecd0, Method*=0x000001dee0401640 (Compiled frame)
	- waiting to lock <0x00000000b0300138> (a java.lang.Class for LingeredAppWithLock)
 - LingeredAppWithLock.lambda$main$0() @bci=2, line=40, pc=0x000001ded4b1ecd0, Method*=0x000001dee0401ad8 (Compiled frame)
 - LingeredAppWithLock$$Lambda$1+0x0000000801000d30.run() @bci=0, pc=0x000001ded4b36b88, Method*=0x000001dee04076f0 (Compiled frame)
 - java.lang.Thread.run() @bci=13, line=1532, pc=0x000001ded4bfcc24, Method*=0x0000000800010d38 (Compiled frame)
Comments
The cause of this failure is understood. See my comment https://bugs.openjdk.org/browse/JDK-8283578?focusedCommentId=14486276&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14486276 The failures seem to come and go, and have been active recently. We might want to problem list it. The recent failures seem to be triggered with -Xcomp runs.
15-03-2023
Here's a log file snippet from the jdk-21+14-1066-tier7 sighting: serviceability/sa/ClhsdbInspect.java #section:main ----------messages:(6/253)---------- command: main ClhsdbInspect reason: User specified action: run main/othervm/timeout=480 ClhsdbInspect started: Fri Mar 10 18:34:08 UTC 2023 Mode: othervm [/othervm specified] finished: Fri Mar 10 18:36:45 UTC 2023 elapsed time (seconds): 156.873 ----------configuration:(0/0)---------- ----------System.out:(190/14296)*---------- Starting the ClhsdbInspect test Command line: ['c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-21+14-1066\\windows-x64-debug.jdk\\jdk-21\\fastdebug\\bin\\java.exe' '-XX:MaxRAMPercentage=4.16667' '-Dtest.boot.jdk=c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk\\19\\36\\bundles\\windows-x64\\jdk-19_windows-x64_bin.zip\\jdk-19' '-Djava.io.tmpdir=c:\\sb\\prod\\1678471023\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\tmp' '-Xcomp' '-XX:+CreateCoredumpOnCrash' '-ea' '-esa' '-XX:CompileThreshold=100' '-XX:+UnlockExperimentalVMOptions' '-server' '-XX:-TieredCompilation' '-XX:+DeoptimizeALot' '-cp' 'C:\\sb\\prod\\1678471023\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\classes\\3\\serviceability\\sa\\ClhsdbInspect.d;C:\\sb\\prod\\1678471023\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_hotspot_serviceability\\classes\\3\\test\\lib' 'LingeredAppWithLock' '8e13cf1a-741b-430c-8da3-a9523eadba0e.lck'] LingeredApp startup took 21386ms Check for hs_err_pid/core/mdmp files: None. Started LingeredApp with pid 40516 Starting clhsdb against 40516 [2023-03-10T18:35:02.383989900Z] Gathering output for process 54244 [2023-03-10T18:36:05.708454200Z] Waiting for completion for process 54244 [2023-03-10T18:36:05.771247700Z] Waiting for completion finished for process 54244 Output: Attaching to process 40516, please wait... hsdb> hsdb> + verbose true hsdb> + jstack -v Deadlock Detection: No deadlocks found. "main" #1 prio=5 tid=0x0000017177855cd0 nid=61368 waiting on condition [0x0000004784dff000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep0(long) @bci=0, pc=0x000001710069d1d5, Method*=0x00000008004b67b0 (Compiled frame; information may be imprecise) - java.lang.Thread.sleep(long) @bci=99, line=484, pc=0x000001710069c4b0, Method*=0x00000008004b66d0 (Compiled frame) - jdk.test.lib.apps.LingeredApp.main(java.lang.String[]) @bci=158, line=629, pc=0x000001710001e1a6, Method*=0x0000017108405668 (Interpreted frame) - locked <0x00000000d7e70118> (a java.lang.Object) - LingeredAppWithLock.main(java.lang.String[]) @bci=147, line=63, pc=0x000001710001e1a6, Method*=0x00000171084017d0 (Interpreted frame) Locked ownable synchronizers: - None "Reference Handler" #8 daemon prio=10 tid=0x00000171075cf590 nid=66512 waiting on condition [0x00000047854fe000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked - java.lang.ref.Reference.waitForReferencePendingList() @bci=0, pc=0x00000171000243af, Method*=0x0000000800046550 (Interpreted frame) - java.lang.ref.Reference.processPendingReferences() @bci=0, line=246, pc=0x000001710001e1a6, Method*=0x00000008000467c0 (Interpreted frame) - java.lang.ref.Reference$ReferenceHandler.run() @bci=8, line=208, pc=0x000001710001e1a6, Method*=0x00000008001450d0 (Interpreted frame) Locked ownable synchronizers: - None "Finalizer" #9 daemon prio=8 tid=0x00000171075d2720 nid=19496 in Object.wait() [0x00000047855ff000] java.lang.Thread.State: WAITING (on object monitor) JavaThread state: _thread_blocked - java.lang.Object.wait0(long) @bci=0, pc=0x00000171000243af, Method*=0x00000008005057a8 (Interpreted frame) - java.lang.Object.wait(long) @bci=6, line=366, pc=0x000001710001e1a6, Method*=0x00000008005055b8 (Interpreted frame) - java.lang.Object.wait() @bci=2, line=339, pc=0x000001710001e1a6, Method*=0x00000008005054d8 (Interpreted frame) - java.lang.ref.NativeReferenceQueue.await() @bci=4, line=48, pc=0x000001710001e1a6, Method*=0x0000000800049a00 (Interpreted frame) - java.lang.ref.ReferenceQueue.remove0() @bci=12, line=158, pc=0x000001710001e1a6, Method*=0x0000000800494930 (Interpreted frame) - java.lang.ref.NativeReferenceQueue.remove() @bci=8, line=89, pc=0x000001710001e318, Method*=0x00000008000497d0 (Interpreted frame) - locked <0x00000000d7f0b578> (a java.lang.ref.NativeReferenceQueue$Lock) - java.lang.ref.Finalizer$FinalizerThread.run() @bci=20, line=173, pc=0x000001710001e318, Method*=0x0000000800049288 (Interpreted frame) Locked ownable synchronizers: - None "Signal Dispatcher" #10 daemon prio=9 tid=0x00000171075d6090 nid=20144 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Locked ownable synchronizers: - None "Attach Listener" #11 daemon prio=5 tid=0x00000171075d6a70 nid=41320 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_blocked Locked ownable synchronizers: - None "Common-Cleaner" #20 daemon prio=8 tid=0x000001710781a540 nid=60172 waiting on condition [0x0000004785dff000] java.lang.Thread.State: TIMED_WAITING (parking) JavaThread state: _thread_blocked - jdk.internal.misc.Unsafe.park(boolean, long) @bci=0, pc=0x00000171004ce753, Method*=0x00000008004c9bc8 (Compiled frame; information may be imprecise) - parking to wait for <0x00000000d7e45498> (a java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject) - java.util.concurrent.locks.LockSupport.parkNanos(java.lang.Object, long) @bci=34, line=269, pc=0x00000171004ceba0, Method*=0x00000008001c0940 (Compiled frame [deoptimized]) - java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(long, java.util.concurrent.TimeUnit) @bci=134, line=1847, pc=0x000001710001e1a6, Method*=0x00000008001f1008 (Interpreted frame) - java.lang.ref.ReferenceQueue.await(long) @bci=8, line=71, pc=0x000001710001e75a, Method*=0x00000008001de5e8 (Interpreted frame) - java.lang.ref.ReferenceQueue.remove0(long) @bci=18, line=143, pc=0x00000171004b47dc, Method*=0x00000008004948c0 (Compiled frame [deoptimized]) - java.lang.ref.ReferenceQueue.remove(long) @bci=36, line=218, pc=0x00000171004ade74, Method*=0x00000008001de478 (Compiled frame [deoptimized]) - jdk.internal.ref.CleanerImpl.run() @bci=45, line=140, pc=0x00000171004a96f0, Method*=0x0000000800194ed8 (Compiled frame [deoptimized]) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1636, pc=0x00000171004a7928, Method*=0x00000008004b7340 (Compiled frame [deoptimized]) - java.lang.Thread.run() @bci=19, line=1623, pc=0x00000171004a7928, Method*=0x000000080001a9b0 (Compiled frame [deoptimized]) - jdk.internal.misc.InnocuousThread.run() @bci=20, line=186, pc=0x00000171004a7928, Method*=0x00000008001584e0 (Compiled frame [deoptimized]) Locked ownable synchronizers: - None "Thread-0" #21 prio=5 tid=0x000001710781ab10 nid=79724 waiting on condition [0x0000004785eff000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep0(long) @bci=0, pc=0x000001710069d1d5, Method*=0x00000008004b67b0 (Compiled frame; information may be imprecise) - java.lang.Thread.sleep(long) @bci=99, line=484, pc=0x000001710001e1a6, Method*=0x00000008004b66d0 (Interpreted frame) - LingeredAppWithLock.lockMethod(java.lang.Object) @bci=7, line=32, pc=0x0000017100521154, Method*=0x0000017108401640 (Compiled frame [deoptimized]) - locked <0x00000000d7e504c0> (a java.lang.Class for LingeredAppWithLock) - LingeredAppWithLock.lambda$main$0() @bci=2, line=40, pc=0x0000017100521154, Method*=0x0000017108401ad8 (Compiled frame [deoptimized]) - LingeredAppWithLock$$Lambda+0x0000000801000d40.run() @bci=0, pc=0x000001710069b1e4, Method*=0x0000017108407e00 (Compiled frame [deoptimized]) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1636, pc=0x00000171006933f8, Method*=0x00000008004b7340 (Compiled frame [deoptimized]) - java.lang.Thread.run() @bci=19, line=1623, pc=0x00000171006933f8, Method*=0x000000080001a9b0 (Compiled frame [deoptimized]) Locked ownable synchronizers: - None "Thread-1" #22 prio=5 tid=0x0000017107818830 nid=35556 waiting for monitor entry [0x0000004785ffe000] java.lang.Thread.State: BLOCKED (on object monitor) JavaThread state: _thread_blocked - LingeredAppWithLock.lockMethod(java.lang.Object) @bci=3, line=30, pc=0x000001710064e420, Method*=0x0000017108401640 (Compiled frame [deoptimized]) - waiting to lock <0x00000000d7e504c0> (a java.lang.Class for LingeredAppWithLock) - LingeredAppWithLock.lambda$main$1() @bci=2, line=41, pc=0x000001710064e420, Method*=0x0000017108401a20 (Compiled frame [deoptimized]) - LingeredAppWithLock$$Lambda+0x0000000801001318.run() @bci=0, pc=0x000001710069aee4, Method*=0x00000171084084c0 (Compiled frame [deoptimized]) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1636, pc=0x000001710001e632, Method*=0x00000008004b7340 (Interpreted frame) - java.lang.Thread.run() @bci=19, line=1623, pc=0x000001710001e1a6, Method*=0x000000080001a9b0 (Interpreted frame) Locked ownable synchronizers: - None "Thread-2" #23 prio=5 tid=0x0000017107818e00 nid=18076 waiting on condition [0x00000047860ff000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep0(long) @bci=0, pc=0x000001710069d1d5, Method*=0x00000008004b67b0 (Compiled frame; information may be imprecise) - java.lang.Thread.sleep(long) @bci=99, line=484, pc=0x000001710001e1a6, Method*=0x00000008004b66d0 (Interpreted frame) - LingeredAppWithLock.lockMethod(java.lang.Object) @bci=7, line=32, pc=0x0000017100678e5c, Method*=0x0000017108401640 (Compiled frame [deoptimized]) - locked <0x00000000d7e53130> (a java.lang.Thread) - LingeredAppWithLock.lambda$main$2(java.lang.Thread) @bci=1, line=42, pc=0x0000017100678e5c, Method*=0x0000017108401968 (Compiled frame [deoptimized]) - LingeredAppWithLock$$Lambda+0x0000000801001538.run() @bci=4, pc=0x000001710069abbc, Method*=0x0000017108408b70 (Compiled frame [deoptimized]) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1636, pc=0x000001710069bc0c, Method*=0x00000008004b7340 (Compiled frame [deoptimized]) - java.lang.Thread.run() @bci=19, line=1623, pc=0x000001710001e1a6, Method*=0x000000080001a9b0 (Interpreted frame) Locked ownable synchronizers: - None "Thread-3" #24 prio=5 tid=0x00000171078193d0 nid=47580 waiting on condition [0x00000047861ff000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep0(long) @bci=0, pc=0x000001710069d1d5, Method*=0x00000008004b67b0 (Compiled frame; information may be imprecise) - java.lang.Thread.sleep(long) @bci=99, line=484, pc=0x000001710069c4b0, Method*=0x00000008004b66d0 (Compiled frame [deoptimized]) - LingeredAppWithLock.lockMethod(java.lang.Object) @bci=7, line=32, pc=0x000001710069d55c, Method*=0x0000017108401640 (Compiled frame [deoptimized]) - locked <0x00000000d7f004c0> (a java.lang.Class for int) - LingeredAppWithLock.lambda$main$3() @bci=3, line=43, pc=0x000001710001e1a6, Method*=0x00000171084018b0 (Interpreted frame) - LingeredAppWithLock$$Lambda+0x0000000801002000.run() @bci=0, pc=0x000001710069b8e4, Method*=0x0000017108409238 (Compiled frame [deoptimized]) - java.lang.Thread.runWith(java.lang.Object, java.lang.Runnable) @bci=5, line=1636, pc=0x000001710001e632, Method*=0x00000008004b7340 (Interpreted frame) - java.lang.Thread.run() @bci=19, line=1623, pc=0x000001710001e1a6, Method*=0x000000080001a9b0 (Interpreted frame) Locked ownable synchronizers: - None "SteadyStateThread" #25 prio=5 tid=0x00000171078199a0 nid=23076 waiting for monitor entry [0x00000047862ff000] java.lang.Thread.State: BLOCKED (on object monitor) JavaThread state: _thread_blocked - jdk.test.lib.apps.LingeredApp.steadyState(java.lang.Object) @bci=7, line=566, pc=0x00000171006b5fc4, Method*=0x0000017108405360 (Compiled frame [deoptimized]) - waiting to lock <0x00000000d7e70118> (a java.lang.Object) - jdk.test.lib.apps.LingeredApp$1.run() @bci=4, line=573, pc=0x000001710001e1a6, Method*=0x0000017108405d20 (Interpreted frame) Locked ownable synchronizers: - None hsdb> + quit Starting clhsdb against 40516 [2023-03-10T18:36:06.759507200Z] Gathering output for process 56496 [2023-03-10T18:36:39.267590400Z] Waiting for completion for process 56496 [2023-03-10T18:36:39.267590400Z] Waiting for completion finished for process 56496 Output: Attaching to process 40516, please wait... hsdb> hsdb> + verbose true hsdb> + inspect 0x00000000d7e504c0 Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8 sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8 at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getInt(PageCache.java:96) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:355) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCompKlassAddressValue(DebuggerBase.java:397) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readCompKlassAddress(WindbgDebuggerLocal.java:283) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getCompKlassAddressAt(WindbgAddress.java:79) at jdk.hotspot.agent/sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:210) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:181) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor$25.doit(CommandProcessor.java:1109) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2212) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2182) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.run(CommandProcessor.java:2053) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:112) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:44) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:281) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500) hsdb> + quit [2023-03-10T18:36:39.267590400Z] Waiting for completion for process 56496 [2023-03-10T18:36:39.267590400Z] Waiting for completion finished for process 56496 LingeredApp stdout: []; LingeredApp stderr: [] LingeredApp exitValue = 0 ----------System.err:(43/3114)---------- stdout: [Attaching to process 40516, please wait... hsdb> hsdb> + verbose true hsdb> + inspect 0x00000000d7e504c0 Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8 sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8 at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getInt(PageCache.java:96) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:355) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCompKlassAddressValue(DebuggerBase.java:397) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readCompKlassAddress(WindbgDebuggerLocal.java:283) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getCompKlassAddressAt(WindbgAddress.java:79) at jdk.hotspot.agent/sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:210) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:181) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor$25.doit(CommandProcessor.java:1109) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2212) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2182) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.run(CommandProcessor.java:2053) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:112) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:44) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:281) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500) hsdb> + quit ]; stderr: [] exitValue = 0 java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8' at ClhsdbInspect.main(ClhsdbInspect.java:194) 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) Caused by: java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8' at jdk.test.lib.process.OutputAnalyzer.shouldNotMatch(OutputAnalyzer.java:396) at ClhsdbLauncher.runCmd(ClhsdbLauncher.java:154) at ClhsdbLauncher.run(ClhsdbLauncher.java:203) at ClhsdbInspect.main(ClhsdbInspect.java:97) ... 4 more JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8' JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e504c8' ----------rerun:(48/6515)*----------
10-03-2023
Here's a log file snippet from the jdk-20+21-1539-tier7 sighting: serviceability/sa/ClhsdbInspect.java Starting clhsdb against 50140 [2022-10-27T07:38:18.196683Z] Gathering output for process 17272 [2022-10-27T07:38:46.337885500Z] Waiting for completion for process 17272 [2022-10-27T07:38:46.337885500Z] Waiting for completion finished for process 17272 Output: Attaching to process 50140, please wait... hsdb> hsdb> + verbose true hsdb> + inspect 0x00000000d7e4ffa8 Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0 sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0 at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getInt(PageCache.java:96) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:355) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCompKlassAddressValue(DebuggerBase.java:397) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readCompKlassAddress(WindbgDebuggerLocal.java:283) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getCompKlassAddressAt(WindbgAddress.java:79) at jdk.hotspot.agent/sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:210) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:181) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor$25.doit(CommandProcessor.java:1109) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2212) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2182) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.run(CommandProcessor.java:2053) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:112) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:44) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:281) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500) hsdb> + quit [2022-10-27T07:38:46.337885500Z] Waiting for completion for process 17272 [2022-10-27T07:38:46.337885500Z] Waiting for completion finished for process 17272 LingeredApp stdout: []; LingeredApp stderr: [] LingeredApp exitValue = 0 ----------System.err:(43/3114)---------- stdout: [Attaching to process 50140, please wait... hsdb> hsdb> + verbose true hsdb> + inspect 0x00000000d7e4ffa8 Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0 sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0 at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getInt(PageCache.java:96) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:355) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCompKlassAddressValue(DebuggerBase.java:397) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readCompKlassAddress(WindbgDebuggerLocal.java:283) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getCompKlassAddressAt(WindbgAddress.java:79) at jdk.hotspot.agent/sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:210) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:181) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor$25.doit(CommandProcessor.java:1109) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2212) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.executeCommand(CommandProcessor.java:2182) at jdk.hotspot.agent/sun.jvm.hotspot.CommandProcessor.run(CommandProcessor.java:2053) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:112) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:44) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:281) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500) hsdb> + quit ]; stderr: [] exitValue = 0 java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0' at ClhsdbInspect.main(ClhsdbInspect.java:194) at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) 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:1591) Caused by: java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0' at jdk.test.lib.process.OutputAnalyzer.shouldNotMatch(OutputAnalyzer.java:396) at ClhsdbLauncher.runCmd(ClhsdbLauncher.java:154) at ClhsdbLauncher.run(ClhsdbLauncher.java:203) at ClhsdbInspect.main(ClhsdbInspect.java:97) ... 4 more JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0' JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: '^Error: .*$' found in stdout: 'Error: sun.jvm.hotspot.debugger.UnmappedAddressException: d7e4ffb0' ----------rerun:(47/5911)*----------
27-10-2022
This is not just a loom issue. -Xcomp also tends to trigger a GC between clhsdb executions, and of course ZGC is constantly moving objects around in the heap.
25-10-2022
This is a test bug. It can’t assume that the oop remains valid between clhsdb runs. Since it is possible for a GC to happen during this time, the oop can become invalid. Normally this is not an issue, but with Loom the code cache sweeper will trigger a GC, and test runs are also being done with -Xcomp, make this more likely. I found a build and set of JVM options that was reproducing the issue every time. When I ran with -XX:-LoomVM, which disables the sweeper GC, the problem went away. The test needs to be modified to do the jstack and inspect commands during the same clhsdb session. I'm not too sure how to do that. I need to find an example of a test that has an interactive session with a shell, and can see the output of each command as it’s executed, not just after the process exits like ClhsdbLauncher does now, which is what nearly every clhsdb test is based on, and those that aren't are doing something similar.
01-04-2022
Seems to be back now, starting with build 328, and reproducing quite a bit in builds after it.
28-03-2022