JDK-6358861 : REGRESSION:RMI regression testcase was failing with 142_11-b01 and Passing with 142_10
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.rmi
  • Affected Version: 1.4.2_11
  • Priority: P2
  • Status: Closed
  • Resolution: Duplicate
  • OS: solaris_10
  • CPU: sparc
  • Submitted: 2005-12-05
  • Updated: 2007-10-16
  • Resolved: 2005-12-05
Related Reports
Duplicate :  
Relates :  
Description
regression testcase was failing with 142_11-b01 and Passing with 142_10
Test case:
----------
<Regression-WS142>/test/java/rmi/activation/Activatable/forceLogSnapshot/ForceLogSnapshot.java
Exception details:
------------------
# Activation.main: an exception occurred: null
# java.io.OptionalDataException
rmid not destroyed in: 60000 milliseconds
JDK Under test:
---------------
(/export/updates/jdks/j2sdk1.4.2_11)
java version "1.4.2_11-ea"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_11-ea-b01)
Java HotSpot(TM) 64-Bit Server VM (build 1.4.2_11-ea-b01, mixed mode)
System.out:
-----------
Regression test for bug 4173960

System.err:
-----------
***********************************************
RMID: starting rmid...
JAVAVM: command = /export/updates/jdks/j2sdk1.4.2_11/jre/bin/java  -Djava.security.policy=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot/rmid.security.policy   -Dsun.rmi.activation.snapshotInterval=10 -Djava.compiler=  -Dsun.rmi.server.activation.debugExec=true -Dtest.src=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot  -Dtest.classes=/export/updates/Regression/JTwork/classes/java/rmi/activation/Activatable/forceLogSnapshot -Djava.rmi.server.logLevel=v  sun.rmi.server.Activation -port 1098 -log /export/updates/Regression/JTwork/scratch/./log -C-Dtest.src=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot -C-Dtest.classes=/export/updates/Regression/JTwork/classes/java/rmi/activation/Activatable/forceLogSnapshot

JAVAVM: finished starting vm.
RMID: finished starting rmid.
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 0
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 1
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 2
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 3
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 4
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 5
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 6
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 7
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 8
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 9
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 10
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 11
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 12
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 13
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 14
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 15
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 16
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 17
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 18
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 19
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 20
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 21
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 22
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 23
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 24
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 25
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 26
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 27
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 28
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 29
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 30
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 31
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 32
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 33
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 34
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 35
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 36
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 37
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 38
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 39
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 40
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 41
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 42
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 43
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 44
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 45
Creating descriptors and remote objects
Objects group number: 2
Registering descriptors
registered activatable #: 46
Creating descriptors and remote objects
Objects group number: 3
Registering descriptors
registered activatable #: 47
Creating descriptors and remote objects
Objects group number: 0
Registering descriptors
registered activatable #: 48
Creating descriptors and remote objects
Objects group number: 1
Registering descriptors
registered activatable #: 49
RMID: getting a reference to the activation system
RMID: obtained a reference to the activation system
# activation daemon shut down
RMID: testlibrary finished shutting down rmid
RMID: rmid exited on shutdown request
RMID: starting rmid...
JAVAVM: command = /export/updates/jdks/j2sdk1.4.2_11/jre/bin/java  -Djava.security.policy=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot/rmid.security.policy  -Djava.security.policy=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot/rmid.security.policy   -Dsun.rmi.activation.snapshotInterval=10 -Djava.compiler=  -Dsun.rmi.server.activation.debugExec=true -Dtest.src=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot  -Dtest.classes=/export/updates/Regression/JTwork/classes/java/rmi/activation/Activatable/forceLogSnapshot -Djava.rmi.server.logLevel=v  sun.rmi.server.Activation -port 1098 -log /export/updates/Regression/JTwork/scratch/./log -C-Dtest.src=/net/urts071/export6/testSuites/Regression/workspace_142/test/java/rmi/activation/Activatable/forceLogSnapshot -C-Dtest.classes=/export/updates/Regression/JTwork/classes/java/rmi/activation/Activatable/forceLogSnapshot

# Activation.main: an exception occurred: null
# java.io.OptionalDataException
# 	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1294)
# 	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:324)
# 	at java.util.HashMap.readObject(HashMap.java:1010)
# 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
# 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
# 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
# 	at java.lang.reflect.Method.invoke(Method.java:324)
# 	at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:838)
# 	at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1746)
# 	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1646)
# 	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1274)
# 	at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1845)
# 	at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1769)
# 	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1646)
# 	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1274)
# 	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:324)
# 	at java.util.Hashtable.readObject(Hashtable.java:841)
# 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
# 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
# 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
# 	at java.lang.reflect.Method.invoke(Method.java:324)
# 	at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:838)
# 	at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1746)
# 	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1646)
# 	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1274)
# 	at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1845)
# 	at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1769)
# 	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1646)
# 	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1274)
# 	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:324)
# 	at sun.rmi.log.LogHandler.recover(LogHandler.java:70)
# 	at sun.rmi.log.ReliableLog.recover(ReliableLog.java:186)
# 	at sun.rmi.server.Activation.startActivation(Activation.java:142)
# 	at sun.rmi.server.Activation.main(Activation.java:2064)
JAVAVM: finished starting vm.
TEST FAILED: start rmid failed... giving up
TEST FAILED: 
Test failed with: TEST FAILED: start rmid failed... giving up
TestFailedException: TEST FAILED: start rmid failed... giving up
	at TestLibrary.bomb(TestLibrary.java:68)
	at RMID.start(RMID.java:204)
	at RMID.start(RMID.java:172)
	at RMID.restart(RMID.java:209)
	at ForceLogSnapshot.main(ForceLogSnapshot.java:193)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:324)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:83)
	at java.lang.Thread.run(Thread.java:534)
ACTIVATION_LIBRARY: tried to shutdown when rmid was not running
TEST FAILED: rmid not destroyed in: 60000 milliseconds
TestFailedException: TEST FAILED: rmid not destroyed in: 60000 milliseconds
	at TestLibrary.bomb(TestLibrary.java:68)
	at TestLibrary.bomb(TestLibrary.java:71)
	at ActivationLibrary.rmidCleanup(ActivationLibrary.java:127)
	at ForceLogSnapshot.main(ForceLogSnapshot.java:229)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:324)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:83)
	at java.lang.Thread.run(Thread.java:534)

JavaTest Message: Test threw exception: TestFailedException: TEST FAILED: rmid not destroyed in: 60000 milliseconds
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: TestFailedException: TEST FAILED: rmid not destroyed in: 60000 milliseconds

***********************************************

Exception:
----------
Failed. Execution failed: `main' threw exception: TestFailedException: TEST FAILED: rmid not destroyed in: 60000 milliseconds

Comments
EVALUATION The java.io.OptionalDataException occurring in java.util.HashMap's readObject method suggests a problem with the fix to HashMap's writeObject method that was done to fix 6280967 in 1.4.2_11. The problem seems to be that the new writeObject implementation, by avoiding invoking the overridable entrySet() method, does not ensure that the private transient entrySet field is initialized before using it. The field is only lazily initialized, and if writeObject discovers it uninitialized, no map entries are written to the serialization stream, even if a non-zero size was written. When reading such a stream, this effect causes HashMap.readObject to throw an OptionalDataException because there is no data in the stream where the serialized entires should be. This problem appears be already filed as 6345452, so I'm marking this as a duplicate.
05-12-2005