JDK-8230731 : SA tests fail with "Windbg Error: ReadVirtual failed"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 14,15
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: windows
  • CPU: x86_64
  • Submitted: 2019-09-07
  • Updated: 2023-01-02
  • Resolved: 2020-04-16
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 11 JDK 15 JDK 16
11.0.19-oracleFixed 15 b20Fixed 16Resolved
Related Reports
Relates :  
JDK-8204994 - SA might fail to attach to process with "Windbg Error: WaitForEvent failed"
Relates :  
JDK-8242787 - sun/tools/jhsdb/HeapDumpTestWithActiveProcess.java fails with sun.jvm.hotspot.types.WrongTypeException
Relates :  
JDK-8235220 - ClhsdbScanOops.java fails with sun.jvm.hotspot.types.WrongTypeException
Relates :  
JDK-8231288 - "jhsdb jmap" test needed to reproduce issues that used to be reproduced by JShellHeapDumpTest
Relates :  
JDK-8230872 - sun/tools/jhsdb/JShellHeapDumpTest.java fails with RuntimeException: Test ERROR java.io.EOFException
Relates :  
JDK-8235846 - Improve WindbgDebuggerLocal implementation
Relates :  
JDK-8242789 - sun/tools/jhsdb/HeapDumpTestWithActiveProcess.java fails with 'JShellToolProvider' missing from stdout/stderr
Description
The following test failed in the JDK14 CI due to "Windbg Error":

serviceability/sa/ClhsdbCDSJstackPrintAll.java

Here's the error that was spotted:

Error: sun.jvm.hotspot.debugger.DebuggerException: Windbg Error: ReadVirtual failed!
Comments
Fix request [11u] I backport this for parity with 11.0.19-oracle. No risk, touches only SA, a debugging tool. Clean backport. Test ClhsdbScanOops.java passes. SAP nighlty testing passed.
01-01-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk11u-dev/pull/1619 Date: 2022-12-31 11:14:10 +0000
31-12-2022
Git URL: https://github.com/openjdk/jdk/commit/c6c1f9bad9c1742bc3fe44607df864ed05fe2195
31-12-2022
URL: https://hg.openjdk.java.net/jdk/client/rev/def421e710ce User: prr Date: 2020-04-23 17:45:29 +0000
23-04-2020
Fix was pushed while main bug was targeted to '16'. Reset the main bug to fixed in '15' and copied the hgupdater entry here.
16-04-2020
URL: https://hg.openjdk.java.net/jdk/jdk/rev/def421e710ce User: cjplummer Date: 2020-04-16 14:25:27 +0000
16-04-2020
Returning NULL from readBytesFromProcess0() does seem to be the right thing to do. It fixes ClhsdbScanoops. It also results in more correct behavior for JShellHeapDumpTest, although it still fails as a result of the generated AddressException, so there is a different bug there that needs to be figured out. I couldn't get any of the other tests mentioned to fail, even without the fix. These are the ones I've been running: sun/tools/jhsdb/JShellHeapDumpTest.java sun/tools/jhsdb/HeapDumpTest.java serviceability/sa/ClhsdbDumpheap.java serviceability/sa/ClhsdbScanOops.java serviceability/sa/ClhsdbPstack.java serviceability/sa/ClhsdbJstackXcompStress.java serviceability/sa/ClhsdbPrintAs.java serviceability/sa/ClhsdbCDSJstackPrintAll.java serviceability/sa/jmap-hprof/JMapHProfLargeHeapTest.java serviceability/sa/TestG1HeapRegion.java serviceability/sa/TestHeapDumpForInvokeDynamic.java serviceability/sa/TestJmapCore.java
12-04-2020
Linux and BSD return NULL from readBytesFromProcess0() if the bytes cannot be read. The Windows version should be doing the same. This would be a good start to see if this problem continues to turn up.
11-04-2020
I've looked a few stack traces and it seems this "ReadVirtual failed" error turns up in a few difference ways. In some of the cases I think it's just window's way of telling you the address is illegal. So perhaps these should end up being handled with an AddressException. There are many parts of SA that play lose and dangerous with potentially invalid addresses, but they expect an AddressException when that happens, and will do the right thing afterwards. The stacktrace above with a frame in ObjectHeap.iterateLiveRegions() is an example of that. Maybe it is accessing a page in the java heap that has never been paged in, and just needs better error handling to deal with it. Another clue that maybe some sort of AddressException is appropriate is the implementation of DebuggerBase.readBytes(): /** May be called by subclasses directly but may not be overridden */ protected final byte[] readBytes(long address, long numBytes) throws UnmappedAddressException, DebuggerException { if (cache != null) { return cache.getData(address, numBytes); } else { ReadResult res = readBytesFromProcess(address, numBytes); if (res.getData() != null) { return res.getData(); } throw new UnmappedAddressException(res.getFailureAddress()); } } So it expects res.getData() to be null if readBytesFromProcess() can't read in the page, in which case it will throw UnmappedAddressException. But instead the failure to read in the bytes results in a DebuggerException, and no one expects or catches this. However the most recent stack dump listed above does not seem to fall in this category of "failing to properly handle address errors". The code that is triggering this error is fairly simple and basic for SA. It's part of the initialization code in HotSpotTypeDataBase.readVMTypes(). It is iterating over the VMTypeEntry[] array pointed to by gHotSpotVMTypes, which points to VMStructs::localHotSpotVMTypes[]. The last entry in the array is a struct with all 0's, so it detects the last entry by finding a NULL in one of these fields. The exception gets triggered by the following line: typeNameAddr = entryAddr.getAddressAt(typeEntryTypeNameOffset); entryAddr is the address of the VMTypeEntry that is being looked at. It is incremented at the end of the loop on each iteration: entryAddr = entryAddr.addOffsetTo(typeEntryArrayStride); Eventually it should point to the VMTypeEntry with all 0's, and that will trigger the exit from the loop. However, before that happens this "ReadVirtual failed" exception happens during the getAddressAt() call. Currently there is no post mortem evidence indicating how far along in the loop it got. This code is fairly simple and core to the SA initialization, so it's hard to believe it is buggy and the loop is just going off the deep end and ends up traversing beyond then end of VMStructs::localHotSpotVMTypes[]. So that leads to there being a real issue with paging in the memory that VMStructs::localHotSpotVMTypes[] is in, OR possibly this is a core file generated before vmStructs_init() was called.
11-04-2020
This issue is reproducible on my local windows machine as well, == C:\Data\work\bugdb\31024179\March-18>c:\Data\softwares\java\jdk-11.0.7\bin\jhsdb.exe clhsdb --exe c:\Data\softwares\java\jdk-11.0.7\bin\java.exe --core hs_err_pid52532.mdmp Opening core file, please wait... Unable to open core file hs_err_pid52532.mdmp: Windbg Error: ReadVirtual failed! sun.jvm.hotspot.debugger.DebuggerException: Windbg Error: ReadVirtual failed! at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readBytesFromProcess0(Native Method) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readBytesFromProcess(WindbgDebuggerLocal.java:482) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase$Fetcher.fetchPage(DebuggerBase.java:80) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getPage(PageCache.java:178) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getData(PageCache.java:63) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readBytes(DebuggerBase.java:225) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:383) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readAddressValue(DebuggerBase.java:462) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readAddress(WindbgDebuggerLocal.java:308) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getAddressAt(WindbgAddress.java:72) at jdk.hotspot.agent/sun.jvm.hotspot.HotSpotTypeDataBase.readVMTypes(HotSpotTypeDataBase.java:180) at jdk.hotspot.agent/sun.jvm.hotspot.HotSpotTypeDataBase.<init>(HotSpotTypeDataBase.java:89) at jdk.hotspot.agent/sun.jvm.hotspot.HotSpotAgent.setupVM(HotSpotAgent.java:392) at jdk.hotspot.agent/sun.jvm.hotspot.HotSpotAgent.go(HotSpotAgent.java:306) at jdk.hotspot.agent/sun.jvm.hotspot.HotSpotAgent.attach(HotSpotAgent.java:157) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.attachDebugger(CLHSDB.java:202) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.run(CLHSDB.java:63) at jdk.hotspot.agent/sun.jvm.hotspot.CLHSDB.main(CLHSDB.java:40) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runCLHSDB(SALauncher.java:191) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:439) hsdb>
23-03-2020
The latest failure logged error code: 0x8007001E This is HRESULT_FROM_WIN32(ERROR_READ_FAULT) - the system cannot read from the specified device. Quite generic failure.
20-02-2020
Please only use this CR for "Windbg Error: ReadVirtual failed". Use JDK-8204994 for "Windbg Error: WaitForEvent failed"
31-10-2019
I should also add that this is only a problem if you remove the 2 second sleep() done at the start of JShellHeapDumpTest.java. This sleep is done to work around other stability issues as discussed on JDK-8230872. So it appears that like the JDK-8230872, this issue might be due to the target process not being in a stable state.
27-09-2019
JShellHeapDumpTest.java, which is a fairly new test, sees this error on about half of it's windows runs. You see the following in the output: Windbg Error: ReadVirtual failed! However, this does not result in the jmap process producing an error and failing with an error code. The exception is consumed by the following code in JMap.java: public boolean writeHeapHprofBin(String fileName) { try { HeapGraphWriter hgw = new HeapHprofBinWriter(); hgw.write(fileName); System.out.println("heap written to " + fileName); return true; } catch (IOException | RuntimeException exp) { System.err.println(exp.getMessage()); return false; } } So all you get in the output stream is the exception message, and then the JMap process completes with no error code. JShellHeapDumpTest.java then proceeds to read in the hprof file (even though it appears to not have fully been dumped) and actually successfully prints all the stack traces in the hprof file, so the test passes. I noticed this when I changed the above code to the following: public boolean writeHeapHprofBin(String fileName) { try { HeapGraphWriter hgw = new HeapHprofBinWriter(); hgw.write(fileName); System.out.println("heap written to " + fileName); return true; } catch (IOException | RuntimeException exp) { exp.printStackTrace(System.err); throw new RuntimeException(exp); } } I'm doing this for JDK-8231287. This way exceptions are no longer quietly consumed by JMap, and upstream the JMap process will exit with error code 1, which is what it does for other exceptions that are thrown. When I did this, suddenly the JShellHeapDumpTest.java started to fail over half the time on windows due to "Windbg Error: ReadVirtual failed!" The stack trace is the same as for JDK-8001227. Since the failure mode for this CR does not include a backtrace, just the exception message, it's unclear if it is the same: sun.jvm.hotspot.debugger.DebuggerException: Windbg Error: ReadVirtual failed! at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readBytesFromProcess0(Native Method) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readBytesFromProcess(WindbgDebuggerLocal.java:482) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase$Fetcher.fetchPage(DebuggerBase.java:80) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getPage(PageCache.java:178) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.PageCache.getLong(PageCache.java:100) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readCInteger(DebuggerBase.java:364) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.DebuggerBase.readAddressValue(DebuggerBase.java:462) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.readAddress(WindbgDebuggerLocal.java:308) at jdk.hotspot.agent/sun.jvm.hotspot.debugger.windbg.WindbgAddress.getAddressAt(WindbgAddress.java:72) at jdk.hotspot.agent/sun.jvm.hotspot.types.basic.BasicTypeDataBase.findDynamicTypeForAddress(BasicTypeDataBase.java:297) at jdk.hotspot.agent/sun.jvm.hotspot.runtime.VirtualBaseConstructor.instantiateWrapperFor(VirtualBaseConstructor.java:102) at jdk.hotspot.agent/sun.jvm.hotspot.oops.Metadata.instantiateWrapperFor(Metadata.java:74) 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:182) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.iterateLiveRegions(ObjectHeap.java:261) at jdk.hotspot.agent/sun.jvm.hotspot.oops.ObjectHeap.iterate(ObjectHeap.java:102) at jdk.hotspot.agent/sun.jvm.hotspot.utilities.AbstractHeapGraphWriter.write(AbstractHeapGraphWriter.java:51) at jdk.hotspot.agent/sun.jvm.hotspot.utilities.HeapHprofBinWriter.write(HeapHprofBinWriter.java:445) at jdk.hotspot.agent/sun.jvm.hotspot.tools.JMap.writeHeapHprofBin(JMap.java:182) at jdk.hotspot.agent/sun.jvm.hotspot.tools.JMap.run(JMap.java:97) at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:260) at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.start(Tool.java:223) at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.execute(Tool.java:118) at jdk.hotspot.agent/sun.jvm.hotspot.tools.JMap.main(JMap.java:176) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runJMAP(SALauncher.java:321) at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:406)
27-09-2019
This test seems to have multiple failure modes outside of the CI testing, but seems clean in CI until now.
07-09-2019