JDK-8035388 : TEST_BUG: java/rmi/activation/Activatable/checkActivateRef/CheckActivateRef.java fails
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.rmi
  • Affected Version: 7u91,emb-8u33,9
  • Priority: P4
  • Status: Closed
  • Resolution: Won't Fix
  • OS: generic
  • Submitted: 2014-02-20
  • Updated: 2023-01-05
  • Resolved: 2023-01-05
Related Reports
Relates :  
JDK-8042390 - TEST_BUG: java/rmi/activation/Activatable/checkActivateRef/CheckActivateRef.java fails intermittently with NullPointerException
Relates :  
JDK-4277196 - Regression test CheckActivateRef.java failing
Description
TESTFAIL:java/rmi/activation/Activatable/checkActivateRef/CheckActivateRef.java

The failure found during JDK9 nightly test on windows machine.

OS=Windows 8 6.2 (amd64)

java version "1.9.0-ea"
Java(TM) SE Runtime Environment (build 1.9.0-ea-langtools-nightly-h103-20140218-b03-b00)
Java HotSpot(TM) 64-Bit Server VM (build 25.0-b62, mixed mode)

It can be reproduced on same machine.


Error message :

#section:main
----------messages:(3/248)----------
command: main -Djava.rmi.server.ignoreStubClasses=true CheckActivateRef
reason: User specified action: run main/othervm/policy=security.policy/timeout=240 -Djava.rmi.server.ignoreStubClasses=true CheckActivateRef 
elapsed time (seconds): 14.604
----------System.out:(0/0)----------
----------System.err:(213/16252)*----------

Regression test for bug 4105080

java.security.policy = =C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_rmi\\JTwork\\scratch\\security.policy_new
RMID: starting rmid on port #64225...
JAVAVM: command = [C:\\Users\\aurora\\CommonData\\jdk\\jre\\bin\\java, -Djava.security.policy=C:\\Users\\aurora\\sandbox\\testbase\\test\\java\\rmi\\activation\\Activatable\\checkActivateRef\\rmid.security.policy, -Dsun.rmi.server.activation.debugExec=true, -Dtest.src=C:\\Users\\aurora\\sandbox\\testbase\\test\\java\\rmi\\activation\\Activatable\\checkActivateRef, -Dtest.classes=C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_rmi\\JTwork\\classes\\java\\rmi\\activation\\Activatable\\checkActivateRef, -Djava.rmi.server.logLevel=v, -Dsun.rmi.activation.execTimeout=60000, sun.rmi.server.Activation, -log, C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_rmi\\JTwork\\scratch\\.\\log, -port, 64225, -C-Dtest.src=C:\\Users\\aurora\\sandbox\\testbase\\test\\java\\rmi\\activation\\Activatable\\checkActivateRef, -C-Dtest.classes=C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_rmi\\JTwork\\classes\\java\\rmi\\activation\\Activatable\\checkActivateRef, -C-Djava.rmi.server.useCodebaseOnly=false]
ACTIVATION_LIBRARY: Activation System available after 0 milliseconds
RMID: finished starting rmid.
Create activation group in this VM
Creating descriptor
Registering descriptor
proxy = Proxy[ActivateMe,RemoteObjectInvocationHandler[ActivatableRef [remoteRef: null]]]
Activate object via method call
proxy = Proxy[ActivateMe,RemoteObjectInvocationHandler[ActivatableRef [remoteRef: sun.rmi.server.UnicastRef2@289179b2]]]
insideRef = sun.rmi.server.UnicastRef2@289179b2
ActivatableRef's embedded ref type: sun.rmi.server.UnicastRef2
Deactivate object via method call
ACTIVATION_LIBRARY: inactive successful
Activate object via method call
rmid: debugExec: running "C:\\Users\\aurora\\CommonData\\jdk\\jre\\bin\\java -Djava.security.manager=default -Djava.rmi.server.useDynamicProxies=false -Djava.security.policy=C:\\Users\\aurora\\sandbox\\testbase\\test\\java\\rmi\\activation\\Activatable\\checkActivateRef\\group.security.policy -Dtest.src=C:\\Users\\aurora\\sandbox\\testbase\\test\\java\\rmi\\activation\\Activatable\\checkActivateRef -Dtest.classes=C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_rmi\\JTwork\\classes\\java\\rmi\\activation\\Activatable\\checkActivateRef -Djava.rmi.server.useCodebaseOnly=false sun.rmi.server.ActivationGroupInit"
proxy = Proxy[ActivateMe,RemoteObjectInvocationHandler[ActivatableRef [remoteRef: sun.rmi.server.UnicastRef2@605f25e9]]]
insideRef = sun.rmi.server.UnicastRef2@605f25e9
ActivatableRef's embedded ref type: sun.rmi.server.UnicastRef2
Deactivate object via method call
Activate object via method call
Tue Feb 18 20:15:02 PST 2014:ExecGroup-0:err:ACTIVATION_LIBRARY: inactive successful
TEST FAILED: 
Test failed with: activation failed; nested exception is: 
	java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
java.rmi.activation.ActivateFailedException: activation failed; nested exception is: 
	java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivatableRef.activate(ActivatableRef.java:304)
	at sun.rmi.server.ActivatableRef.invoke(ActivatableRef.java:220)
	at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:194)
	at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:148)
	at $Proxy4.ping(Unknown Source)
	at CheckActivateRef.main(CheckActivateRef.java:172)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivationGroupImpl.newInstance(ActivationGroupImpl.java:313)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:744)
	at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:276)
	at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:253)
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:162)
	at java.rmi.activation.ActivationGroup_Stub.newInstance(Unknown Source)
	at sun.rmi.server.Activation$ObjectEntry.activate(Activation.java:1487)
	at sun.rmi.server.Activation$GroupEntry.activate(Activation.java:1173)
	at sun.rmi.server.Activation$ActivatorImpl.activate(Activation.java:438)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:744)
	at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:276)
	at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:253)
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:162)
	at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:194)
	at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:148)
	at com.sun.proxy.$Proxy3.activate(Unknown Source)
	at java.rmi.activation.ActivationID.activate(ActivationID.java:118)
	at sun.rmi.server.ActivatableRef.activate(ActivatableRef.java:277)
	... 11 more
Caused by: sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivationGroupImpl.newInstance(ActivationGroupImpl.java:220)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	... 1 more
ACTIVATION_LIBRARY: Activation System available after 0 milliseconds
RMID: getting a reference to the activation system
RMID: obtained a reference to the activation system
RMID: testlibrary finished shutting down rmid
activation daemon shut down
RMID: RMID's process still not terminated after more than 200 milliseconds
RMID: rmid exited on shutdown request
ACTIVATION_LIBRARY: finished destroying rmid
RMID: removing rmid's old log file...
TestFailedException: TEST FAILED: ; nested exception is: 
	java.rmi.activation.ActivateFailedException: activation failed; nested exception is: 
	java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
java.rmi.activation.ActivateFailedException: activation failed; nested exception is: 
	java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivatableRef.activate(ActivatableRef.java:304)
	at sun.rmi.server.ActivatableRef.invoke(ActivatableRef.java:220)
	at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:194)
	at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:148)
	at $Proxy4.ping(Unknown Source)
	at CheckActivateRef.main(CheckActivateRef.java:172)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivationGroupImpl.newInstance(ActivationGroupImpl.java:313)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:744)
	at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:276)
	at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:253)
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:162)
	at java.rmi.activation.ActivationGroup_Stub.newInstance(Unknown Source)
	at sun.rmi.server.Activation$ObjectEntry.activate(Activation.java:1487)
	at sun.rmi.server.Activation$GroupEntry.activate(Activation.java:1173)
	at sun.rmi.server.Activation$ActivatorImpl.activate(Activation.java:438)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:744)
	at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:276)
	at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:253)
	at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:162)
	at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:194)
	at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:148)
	at com.sun.proxy.$Proxy3.activate(Unknown Source)
	at java.rmi.activation.ActivationID.activate(ActivationID.java:118)
	at sun.rmi.server.ActivatableRef.activate(ActivatableRef.java:277)
	... 11 more
Caused by: sun.rmi.server.InactiveGroupException: group is inactive
	at sun.rmi.server.ActivationGroupImpl.newInstance(ActivationGroupImpl.java:220)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:484)
	at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:323)
	at sun.rmi.transport.Transport$1.run(Transport.java:178)
	at sun.rmi.transport.Transport$1.run(Transport.java:175)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.Transport.serviceCall(Transport.java:174)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:557)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:812)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:671)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	... 1 more

JavaTest Message: Test threw exception: TestFailedException: TEST FAILED: ; nested exception is: 
	java.rmi.activation.ActivateFailedException: activation failed; nested exception is: 
	java.rmi.activation.ActivationException: unable to activate object; nested exception is: 
	sun.rmi.server.InactiveGroupException: group is inactive
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: TestFailedException: TEST FAILED: ; nested exception is: java.rmi.activation.ActivateFailedException: activation failed; nested exception is: java.rmi.activation.ActivationException: unable to activate object; nested exception is: sun.rmi.server.InactiveGroupException: group is inactive
Comments
RMI Activation and its tests have been removed from recent releases.
05-01-2023
This is not a duplicate of JDK-8042390. Reopening. JDK-8042390 covers a mysterious NullPointerException coming from somewhere deep within the RMI runtime. This bug (JDK-8035388) is a simple timing issue in the CheckActivateRef.java test itself.
24-02-2015
JDK-8042390
24-02-2015
Code fix sent to open alias: http://mail.openjdk.java.net/pipermail/core-libs-dev/2014-February/025311.html
25-02-2014
Root Cause: inactiveObject release lock before checkInactiveGroup, this could cause groupInactive reset too early Suggested Fix: do checkInactiveGroup before release lock
25-02-2014
Failure is pretty easy to reproduce by reducing or removing the sleep() call at line 236 of the test. This clearly indicates it's a timing problem.
20-02-2014
The test deactivates and object, waits a bit, and then activates it again. If a particular exception is received when trying to activate the object again, the test sleeps more and tries again. If the system is really slow, the activation retry will fail. I suspect that's what's happening here. We may need to refine the logic of the test to find a better way to wait until the deactivation is complete before reactivating the object.
20-02-2014