JDK-7168267 : TEST_BUG: Cleanup of rmi regression tests (activation and others)
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.rmi
  • Affected Version: 8
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2012-05-11
  • Updated: 2023-08-01
  • Resolved: 2013-12-20
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 8 JDK 9
8u401Fixed 9 b01Fixed
Related Reports
Relates :  
JDK-8005436 - TEST_BUG: speed up RMI tests
Relates :  
JDK-7161503 - java/rmi/activation/CommandEnvironment/SetChildEnv.java test fails
Relates :  
JDK-7144861 - RMI activation tests are too slow
Description
While investigating improvement fix for 7144861 Rmi activation tests are too slow,
It has been noticed that all the activation, ang more generally speaking all the rmi
regression tests would need some cleanup in the future.

As an example, but not limited to, the rmi/testlibrary classes, as well as some other
rmi tests (activation or not) do use timer loops with Thread.sleep() blocking method(),
for which InterruptedException is not handled at all.

At least reasonable cleanup would be largely beneficial to the whole set of rmi regression tests
Comments
URL: http://hg.openjdk.java.net/jdk9/jdk9/jdk/rev/eaa533e9778a User: lana Date: 2014-01-15 02:08:46 +0000
15-01-2014
URL: http://hg.openjdk.java.net/jdk9/dev/jdk/rev/eaa533e9778a User: smarks Date: 2013-12-20 23:34:36 +0000
20-12-2013
Suggested fix sent to open http://mail.openjdk.java.net/pipermail/core-libs-dev/2013-December/023899.html
11-12-2013
Root Cause: Per Stuart comment, this is a cleanup effort for rmi code Suggested fix Check all sleep to see if it could be changed to timeout.
10-12-2013
This issue isn't specifically about performance; that's covered by JDK-8005436. The "cleanup" referred to in this bug is about sleep loops that don't handle InterruptedException. It may also be the case that there are sleep loops that want to wait (say) a maximum of 30 seconds, that do something like this: for (int i = 0; i < 60; i++) { attemptSomeOperation(); if (itWasSuccessful) { break; } Thread.sleep(500); } Suppose attemptSomeOperation() never succeeds. It seems like this would retry a maximum of 60 times, sleeping 500ms each time, resulting in a maximum wait time of 30 sec, right? Well, no, there was this one case where attemptSomeOperation() itself took 60 sec to timeout, so this loop ran only a couple times before the test framework timed out the whole test. So the retry logic has to call System.currentTimeMillis() each time around the loop in order to make sure that the maximum wait time hasn't been exceeded. I think there are some of these incorrect retry loop styles somewhere in the RMI test library. ===== I don't think anything is actually recursive. Did you mean a retry loop, not a recursive? I don't know where waitAllStarted is. There is a method howManyRestarted() in forceLogSnapshot(). Using a CountDownLatch here is probably a good idea so that the test waits the minimal amount of time when all objects are restarted successfully (which I think is the common case). Note this will save on average 5 sec per call, and it's called twice, so on average this saves only 10 sec in the total runtime of 82 sec. So there are other sources of slowness in this test as well. Finally, note, I have a couple other things already cooking with SetChildEnv. See JDK-7195382 and JDK-7187852.
05-12-2013
Initial discussion sent to open http://mail.openjdk.java.net/pipermail/core-libs-dev/2013-December/023737.html
04-12-2013
Initial analysis java/rmi/activation/Activatable/forceLogSnapshot method waitAllStarted is using recursive sleep to poll 50 restartedObject to be true, we can use modern CountDownLatch to implement blocking-time wait. Also suggest shorten waiting time to 5 seconds. java/rmi/activation/Activatable/checkAnnotations We can subclass ByteArrayOutputStream which support notification when data was written. Also use two thread wait output string and error string to be not null java/rmi/activation/CommandEnvironment/SetChildEnv.java try to use wait-notify to replace recursive sleep-check to shorten wait time
02-12-2013
Had a run with rmi/activation tests and got a time-sorted result as below, will focus on time consuming test improvement 1st java/rmi/activation/Activatable/forceLogSnapshot 82.819 java/rmi/activation/Activatable/checkAnnotations 49.116 java/rmi/activation/CommandEnvironment 30.132 java/rmi/activation/Activatable/checkActivateRef 24.82 java/rmi/activation/Activatable/restartCrashedService 13.605 java/rmi/activation/Activatable/checkImplClassLoader 10.618 java/rmi/activation/Activatable/restartService 8.032 java/rmi/activation/Activatable/checkRegisterInLog 7.72 java/rmi/activation/Activatable/inactiveGroup 7.599 java/rmi/activation/Activatable/restartLatecomer 7.371 java/rmi/activation/ActivationSystem/stubClassesPermitted 5.8 java/rmi/activation/Activatable/shutdownGracefully 5.373 java/rmi/activation/ActivateFailedException 4.659 java/rmi/activation/log 4.381 java/rmi/activation/ActivationSystem/modifyDescriptor 3.701 java/rmi/activation/ActivationSystem/unregisterGroup 2.694 java/rmi/activation/Activatable/extLoadedImpl 2.128 java/rmi/activation/Activatable/nestedActivate 1.938 java/rmi/activation/Activatable/createPrivateActivable 1.905 java/rmi/activation/ActivationGroup/downloadActivationGroup 1.885 java/rmi/activation/Activatable/downloadParameterClass 1.883 java/rmi/activation/Activatable/unregisterInactive 1.785 java/rmi/activation/Activatable/nonExistentActivatable 1.721 java/rmi/activation/rmidViaInheritedChannel/RmidViaInheritedChannel 1.594 java/rmi/activation/Activatable/elucidateNoSuchMethod 1.579 java/rmi/activation/ActivationSystem/activeGroup 1.483 java/rmi/activation/rmidViaInheritedChannel/InheritedChannelNotServerSocket 1.376 java/rmi/activation/Activatable/lookupActivationSystem 0.93 java/rmi/activation/Activatable/notSerializable 0.521 java/rmi/activation/checkusage 0.258 java/rmi/activation/ActivationGroupDesc/checkDefaultGroupName 0.117 java/rmi/activation/CommandEnvironment 0.105
26-11-2013
While improvements are certainly possible in the testlibrary, the sleep() calls in the testlibrary are generally within polling loops that try to minimize the amount of waiting. For example, it's quite reasonable to have a loop that checks every 100ms in a loop, waiting for a JVM subprocess to become ready. So having a sleep() in a loop isn't necessarily a cause of bad performance.
07-11-2013
most of Thread.sleep() statements are in a loop, it causes performance becoming worse. the cleanup will start from classes rmi/testlibrary as they are helper classes which are referenced by other tests.
07-11-2013
By searching rmi testbase with keyword Thread.sleep, there are total 32 files found as below: Search "Thread.sleep" (43 hits in 32 files) test\java\rmi\activation\Activatable\checkActivateRef\CheckActivateRef.java (2 hits) Line 180: Thread.sleep(5000); Line 236: Thread.sleep(3000); test\java\rmi\activation\Activatable\checkAnnotations\CheckAnnotations.java (3 hits) Line 127: Thread.sleep(4000); Line 145: Thread.sleep(5000); Line 172: Thread.sleep(4000); test\java\rmi\activation\Activatable\checkImplClassLoader\CheckImplClassLoader.java (1 hits) Line 109: Thread.sleep(4000); test\java\rmi\activation\Activatable\checkRegisterInLog\CheckRegisterInLog.java (1 hits) Line 142: Thread.sleep(5000); test\java\rmi\activation\Activatable\forceLogSnapshot\ForceLogSnapshot.java (1 hits) Line 278: Thread.sleep(10000); test\java\rmi\activation\Activatable\inactiveGroup\InactiveGroup.java (1 hits) Line 150: Thread.sleep(500); test\java\rmi\activation\Activatable\restartLatecomer\RestartLatecomer.java (1 hits) Line 237: Thread.sleep(5000); test\java\rmi\activation\Activatable\shutdownGracefully\ShutdownGracefully.java (2 hits) Line 164: Thread.sleep(4000); Line 257: Thread.sleep(50 * 1000); test\java\rmi\activation\ActivateFailedException\activateFails\ActivateFails.java (1 hits) Line 153: Thread.sleep(2000); test\java\rmi\activation\ActivationSystem\stubClassesPermitted\StubClassesPermitted.java (1 hits) Line 169: Thread.sleep(4000); test\java\rmi\activation\CommandEnvironment\Doctor.java (1 hits) Line 85: Thread.sleep(5000); test\java\rmi\activation\CommandEnvironment\SetChildEnv.java (2 hits) Line 155: Thread.sleep(1000); Line 205: Thread.sleep(5000); test\java\rmi\dgc\dgcImplInsulation\DGCImplInsulation.java (1 hits) Line 89: Thread.sleep(2000); test\java\rmi\registry\classPathCodebase\ClassPathCodebase.java (1 hits) Line 106: Thread.sleep(REGISTRY_WAIT); test\java\rmi\registry\reexport\Reexport.java (1 hits) Line 133: Thread.sleep (5000); test\java\rmi\reliability\juicer\AppleUserImpl.java (1 hits) Line 215: Thread.sleep(Math.abs(random.nextInt() % 10) * 1000); test\java\rmi\reliability\juicer\ApplicationServer.java (1 hits) Line 83: Thread.sleep(10000); //sleep 10 seconds and try again test\java\rmi\server\RMISocketFactory\useSocketFactory\activatable\UseCustomSocketFactory.java (1 hits) Line 111: Thread.sleep(2000); test\java\rmi\server\RMISocketFactory\useSocketFactory\unicast\UseCustomSocketFactory.java (1 hits) Line 88: Thread.sleep(2000); test\java\rmi\server\UnicastRemoteObject\exportObject\GcDuringExport.java (1 hits) Line 47: try { Thread.sleep(1); } catch (InterruptedException e) { } test\java\rmi\server\UnicastRemoteObject\keepAliveDuringCall\ShutdownImpl.java (4 hits) Line 52: Thread.sleep(500); Line 54: Thread.sleep(500); Line 56: Thread.sleep(500); Line 58: Thread.sleep(500); test\java\rmi\testlibrary\ActivationLibrary.java (2 hits) Line 78: Thread.sleep(deactivateSleepTime); Line 162: Thread.sleep(100); test\java\rmi\testlibrary\RMID.java (2 hits) Line 227: Thread.sleep(Math.min(waitTime, rmidStartSleepTime)); Line 328: Thread.sleep(vmProcessEndWaitInterval); test\java\rmi\transport\checkLeaseInfoLeak\CheckLeaseLeak.java (1 hits) Line 111: Thread.sleep(3000); test\java\rmi\transport\closeServerSocket\CloseServerSocket.java (1 hits) Line 61: Thread.sleep(1); // work around BindException (bug?) test\java\rmi\transport\dgcDeadLock\DGCDeadLock.java (1 hits) Line 142: Thread.sleep(10); test\java\rmi\transport\dgcDeadLock\TestImpl.java (1 hits) Line 78: Thread.sleep(DGCDeadLock.TEST_FAIL_TIME); test\java\rmi\transport\pinClientSocketFactory\PinClientSocketFactory.java (1 hits) Line 110: Thread.sleep(3 * Long.getLong("sun.rmi.transport.connectionTimeout", test\java\rmi\transport\pinLastArguments\PinLastArguments.java (1 hits) Line 86: Thread.sleep(20); test\java\rmi\transport\rapidExportUnexport\RapidExportUnexport.java (1 hits) Line 56: Thread.sleep(1); // work around BindException (bug?) test\java\rmi\transport\readTimeout\ReadTimeoutTest.java (2 hits) Line 82: //Thread.sleep(2000); Line 97: Thread.sleep(DELAY); test\java\rmi\transport\runtimeThreadInheritanceLeak\RuntimeThreadInheritanceLeak.java (1 hits) Line 108: Thread.sleep(2000);
07-11-2013
Assigning to Eric
04-11-2013
A generalized retry loop should be time-based, not count-and-delay based. Specifically, the current retry loops do something like retrying up to 50 times, delaying 100ms each time. This is intended to give a maximum delay of five seconds. But it doesn't actually do this, since the operation being tried might have its own timeout. For example, a network connection might take 30 seconds to time out. If this occurs it's probably reasonable not to retry at all, or at least to retry until the maximum time requested has passed.
22-12-2012
EVALUATION Specific improvements include (but are not limited to) - better InterruptedException handling, as mentioned above - refactoring of sleep loops into some kind of poll-repeatedly function
11-05-2012