[Patch] JTreg case FiniteGCLatency.java failed randomly when using Serial GC.

[Alex Kashchenko]

Hi,

On 08/26/2016 10:42 AM, yuanxiang (F) wrote:
> HI, all:
>           We found than JTReg test case jdk/test/java/rmi/server/Unreferenced/finiteGCLatency/FiniteGCLatency.java may fail sometimes.
>
> It reported:
> /*******************************************/
>
> Regression test for bug 4164696
>
> exported remote object
> created registry
> bound remote object in registry
> unbound remote object from registry; waiting for unreferenced() callback...
> java.lang.RuntimeException: TEST FAILED: unrefereced() not invoked after 50.0 seconds
>   at FiniteGCLatency.main(FiniteGCLatency.java:97)
>   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:498)
>   at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
>   at java.lang.Thread.run(Thread.java:745)
>
> JavaTest Message: Test threw exception: java.lang.RuntimeException: TEST FAILED: unrefereced() not invoked after 50.0 seconds
> JavaTest Message: shutting down test
> /*******************************************/
>
> Test command:
> jtreg -va -nr ./jdk8u-aarch32/jdk/test/java/rmi/server/Unreferenced/finiteGCLatency/FiniteGCLatency.java
>           (Use Serial GC.)
>
> This bug is random, and we may need to test it on different account or machine to reproduce.

Just for the record, I cannot reproduce neither this nor the 
TransformationWarningsTest failures on 3 different arm boards. It 
probably requires a bigger machine to reproduce this.

>
>           We found the root cause is that the field _time_of_last_gc of class Generation is not initialized.
>
>
>           This case sets RMI GC interval to 6s, and waits for method Unreferenced to be invoked in 50s.
>           In the failed cases, method Unreferenced didn't been invoked.
>
> And this is because:
>           (1) test case sets 6000ms to sun.rmi.dgc.client.gcInterval
>           (2) DGCClient.lookup() creates a new GC$LatencyRequest object to set the new interval.
>           (3) And the following method calls are:
> constructor GC$LatencyRequest() --> GC$LatencyRequest.adjustLatencyIfNeeded() --> GC$Daemon.setLatencyTarget() -->
> create or notify thread GC$Daemon --> GC$Daemon.run() -->
>                 GC.maxObjectInspectionAge() --> GenCollectedHeap::millis_since_last_gc() -->
>                 GenCollectedHead::generation_iterate() --> GenTimeOfLastGCClosure.do_generation() -->
>                 Generation.time_of_last_gc()
>           (4) Generation.time_of_last_gc() returns the static field _time_of_last_gc, however it hasn't been initialized.
>           (5) If the value of _time_of_last_gc is very big, the test case fails.
>
> The analysis above takes Serial GC as example.
> According to the codes, CMS GC may have the same problem. Parallel GC initializes the field _time_of_last_gc and is OK.
>
>
> Following is the patch to fix this problem.
> /*******************************Patch Begin**********************************/
> Index: hotspot/src/share/vm/memory/generation.cpp
> ===================================================================
> --- hotspot/src/share/vm/memory/generation.cpp
> +++ hotspot/src/share/vm/memory/generation.cpp
> @@ -46,6 +46,7 @@
> PRAGMA_FORMAT_MUTE_WARNINGS_FOR_GCC
>
>   Generation::Generation(ReservedSpace rs, size_t initial_size, int level) :
> +  _time_of_last_gc(0L),
>     _level(level),
>     _ref_processor(NULL) {
>     if (!_virtual_space.initialize(rs, initial_size)) {
> Index: hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp
> ===================================================================
> --- hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp
> +++ hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp
> @@ -553,6 +553,7 @@
> CMSCollector::CMSCollector(ConcurrentMarkSweepGeneration* cmsGen,
>                              CardTableRS*                   ct,
>                              ConcurrentMarkSweepPolicy*     cp):
> +  _time_of_last_gc(0L),
>     _cmsGen(cmsGen),
>     _ct(ct),
>     _ref_processor(NULL),    // will be set later
> /*******************************Patch End**********************************/
>
>
>
> Best Regrards!
>
>
> Xiang Yuan
> 8/26/2016
>
>
>
>


-- 
-Alex