JDK-8012474 : sun/tools/jmap/Basic.sh test failing since hsx 24-b40 integration on unix OSes
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: hs24,7u40
  • Priority: P2
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2013-04-17
  • Updated: 2014-06-11
  • Resolved: 2013-12-12
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 7
7u40Resolved
Related Reports
Duplicate :  
JDK-8012102 - CollectedHeap::ensure_parsability is not always called during heap inspection
Relates :  
JDK-8012572 - ProblemList.txt : Exclude sun/tools/jmap/Basic.sh for short term
Description
I'm seeing the following test fail on JPRT since hsx 24-b40 was pushed to 7u-dev. I noticed this while running JPRT test jobs for the CPU13_02 sync up. It's generic and I see it on all unix platforms.

TEST: sun/tools/jmap/Basic.sh
JDK under test: (/tmp/jprt/T1/084934.scoffey/testproduct/solaris_sparcv9_5.10-product)
java version "1.7.0-internal"
Java(TM) SE Runtime Environment (build 1.7.0-internal-201304170849.scoffey.jdk7u-dev-contender-b00)
Java HotSpot(TM) 64-Bit Server VM (build 24.0-b40, mixed mode)


ACTION: build -- Passed. All files up to date
REASON: User specified action: run build SimpleApplication ShutdownSimpleApplication 
TIME:   0.0 seconds
messages:
command: build SimpleApplication ShutdownSimpleApplication
reason: User specified action: run build SimpleApplication ShutdownSimpleApplication 
elapsed time (seconds): 0.0

ACTION: shell -- Failed. Execution failed: exit code 1
REASON: User specified action: run shell Basic.sh 
TIME:   16.535 seconds
messages:
command: shell Basic.sh []
reason: User specified action: run shell Basic.sh 
elapsed time (seconds): 16.535
STDOUT:
INFO: waiting for SimpleApplication to initialize...
INFO: SimpleApplication is process 27645
INFO: SimpleApplication output is in /tmp/jprt/T1/084934.scoffey/s/jdk/build/solaris-sparcv9/testoutput/jdk_tools/JTwork/classes/sun/tools/jmap/Application.out
Reading from java_pid27645.hprof...
Reading from java_pid27645.hprof...
INFO: Port number of SimpleApplication: 52382
INFO: Connecting to port 52382 to shutdown SimpleApplication ...
STDERR:
Exception in thread "main" java.io.IOException: Premature EOF
	at sun.tools.attach.HotSpotVirtualMachine.readInt(HotSpotVirtualMachine.java:248)
	at sun.tools.attach.SolarisVirtualMachine.execute(SolarisVirtualMachine.java:141)
	at sun.tools.attach.HotSpotVirtualMachine.executeCommand(HotSpotVirtualMachine.java:217)
	at sun.tools.attach.HotSpotVirtualMachine.heapHisto(HotSpotVirtualMachine.java:185)
	at sun.tools.jmap.JMap.histo(JMap.java:219)
	at sun.tools.jmap.JMap.main(JMap.java:136)
27645: Unable to open door: target process not responding or HotSpot VM not loaded
The -F option can be used when the target process is not responding
27645 Abort - core dumped
27645: No such process
java.io.FileNotFoundException: java_pid27645.hprof (No such file or directory)
	at java.io.FileInputStream.open(Native Method)
	at java.io.FileInputStream.<init>(FileInputStream.java:143)
	at java.io.FileInputStream.<init>(FileInputStream.java:101)
	at com.sun.tools.hat.internal.parser.Reader.readFile(Reader.java:84)
	at com.sun.tools.hat.Main.main(Main.java:159)
java_pid27645.hprof: No such file or directory
27645: No such process
java.io.FileNotFoundException: java_pid27645.hprof (No such file or directory)
	at java.io.FileInputStream.open(Native Method)
	at java.io.FileInputStream.<init>(FileInputStream.java:143)
	at java.io.FileInputStream.<init>(FileInputStream.java:101)
	at com.sun.tools.hat.internal.parser.Reader.readFile(Reader.java:84)
	at com.sun.tools.hat.Main.main(Main.java:159)
Exception in thread "main" java.net.ConnectException: Connection refused
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:198)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391)
	at java.net.Socket.connect(Socket.java:579)
	at java.net.Socket.connect(Socket.java:528)
	at ShutdownSimpleApplication.main(ShutdownSimpleApplication.java:68)

TEST RESULT: Failed. Execution failed: exit code 1
Comments
Duplicated by JDK-8012102
12-12-2013
TEST: sun/tools/jmap/Basic.sh was unexcluded and now is executing regularly. The test keeps failing though, but due to another reason.
25-07-2013
The fix has now been synced to jdk7u-dev and both the test and the reproducer are now working as expected.
30-04-2013
On Windows 64 this test is causing the jmap process to hang (with no sign of the target VM crashing) and render the JPRT client machines unusable. Every 7u-dev JPRT job that is running at the moment is killing the JPRT system it is running on. Update: found the remnants of the crashed VM and the hs_err log shows it is this problem. On Windows when the target VM crashes the jmap process isn't notified and so hangs on the pipe.
18-04-2013
JDK-8012572 logged to add this test to exclude list. Please remember to remove sun/tools/jmap/Basic.sh from exclude list once this bug is fixed.
18-04-2013
Without any additional data, it is hard to say the exact cause. However, this looks like https://jbs.oracle.com/bugs/browse/JDK-8012102. KlassInfoTable::record_instance most likely encountered a 0x0BADBABE in a TLAB (or something similar). Unfortunately, the fix for https://jbs.oracle.com/bugs/browse/JDK-8012102 will not reach jdk7u-dev until the PIT that starts on April 18 is done.
18-04-2013
Hidden in the output above was the line "27645 Abort - core dumped". Turns out one of the JVMs involved had crashed. Attached is a hs_err log from such a crash: V [libjvm.so+0x43088d] KlassInfoTable::record_instance(oopDesc*)+0x8d V [libjvm.so+0x43148e] RecordInstanceClosure::do_object(oopDesc*)+0x2e V [libjvm.so+0x6360d5] MutableSpace::object_iterate(ObjectClosure*)+0x35 V [libjvm.so+0x6ce447] PSYoungGen::object_iterate(ObjectClosure*)+0x17 V [libjvm.so+0x688fc6] ParallelScavengeHeap::object_iterate(ObjectClosure*)+0x16 V [libjvm.so+0x430e72] HeapInspection::instance_inspection(KlassInfoTable*, KlassInfoClosure*, bool, BoolObjectClosure*)+0x82 V [libjvm.so+0x4310df] HeapInspection::heap_inspection(outputStream*, bool)+0x15f V [libjvm.so+0x7c9a7c] VM_GC_HeapInspection::doit()+0x3c V [libjvm.so+0x7d2f47] VM_Operation::evaluate()+0x47 V [libjvm.so+0x7d1363] VMThread::evaluate_operation(VM_Operation*)+0xb3 V [libjvm.so+0x7d1738] VMThread::loop()+0x1e8 V [libjvm.so+0x7d1b85] VMThread::run()+0x85 It is easy to reproduce this by doing "jmap -histo <pid>" on a running JVM.
18-04-2013
I would just like to add that the bug causing the failure (https://jbs.oracle.com/bugs/browse/JDK-8012102) has been fixed (http://hg.openjdk.java.net/hsx/hsx24/hotspot/rev/7baf47cf4bed), but it is not synced yet. For the record, I run the reproducer that Staffan described (jmap -heap <pid>) and the problem reproduced with the following assertion: assert(check_obj_alignment(result)) failed: address not aligned: 0x00000000baadbabe This shows that the problem really is that CollectedHeap::ensure_parsability haven't been called, which is exactly the bug https://jbs.oracle.com/bugs/browse/JDK-8012102. Btw, is there a bug failed against the test for the problem that David mentioned? The test should not hang because the VM crashes...
18-04-2013