CacheReferencesTest fails on Mac with JDK 1.7/1.8

[gissuebot]

Original issue created by sebastian.davids on 2013-11-04 at 07:40 AM

---

---

 T E S T S

Running com.google.common.cache.CacheReferencesTest Tests run: 5, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 155.376 sec <<< FAILURE!

Results :

Failed tests:   testCleanupOnReferenceCollection(com.google.common.cache.CacheReferencesTest): expected:<1> but was:<2>

@@@@

$ git rev-parse HEAD cff5df6b48b892574975dc045f6ed3552d4b3d1d

It fails with:

Apache Maven 3.0.5 (r01de14724cdef164cd33c7c8c2fe155faf9602da; 2013-02-19 14:51:28+0100) Maven home: /opt/local/share/java/maven3 Java version: 1.7.0_40, vendor: Oracle Corporation Java home: /Library/Java/JavaVirtualMachines/jdk1.7.0_40.jdk/Contents/Home/jre Default locale: en_US, platform encoding: UTF-8 OS name: "mac os x", version: "10.8.5", arch: "x86_64", family: "mac"

and

Apache Maven 3.0.5 (r01de14724cdef164cd33c7c8c2fe155faf9602da; 2013-02-19 14:51:28+0100) Maven home: /opt/local/share/java/maven3 Java version: 1.7.0_45, vendor: Oracle Corporation Java home: /Library/Java/JavaVirtualMachines/jdk1.7.0_40.jdk/Contents/Home/jre Default locale: en_US, platform encoding: UTF-8 OS name: "mac os x", version: "10.8.5", arch: "x86_64", family: "mac"

and

Apache Maven 3.0.5 (r01de14724cdef164cd33c7c8c2fe155faf9602da; 2013-02-19 14:51:28+0100) Maven home: /opt/local/share/java/maven3 Java version: 1.8.0-ea, vendor: Oracle Corporation Java home: /Library/Java/JavaVirtualMachines/jdk1.8.0.jdk/Contents/Home/jre Default locale: en_US, platform encoding: UTF-8 OS name: "mac os x", version: "10.8.5", arch: "x86_64", family: "mac"

But works with:

Apache Maven 3.0.5 (r01de14724cdef164cd33c7c8c2fe155faf9602da; 2013-02-19 14:51:28+0100) Maven home: /opt/local/share/java/maven3 Java version: 1.6.0_65, vendor: Apple Inc. Java home: /System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home Default locale: en_US, platform encoding: MacRoman OS name: "mac os x", version: "10.8.5", arch: "x86_64", family: "mac"

Running the tests on JDK 1.7/1.8 takes very long compared to running them with JDK 1.6.

[gissuebot]

Original comment posted by kevinb@google.com on 2013-11-20 at 08:13 PM

---

(No comment entered for this change.)

---

Status: Research Labels: Type-Dev, Package-Cache

[gissuebot]

Original comment posted by cpovirk@google.com on 2013-12-09 at 09:24 PM

---

This might be a 64-bit thing, whether a bug in the test or a 64-bit-specific JIT (or something) problem. I say that because I'm seeing failures and mysterious early terminations when running the test with a 64-bit Linux JDK7. (The mysterious early terminations might conceivably be caused by our internal build system, though I should note that the build system is reporting FAILED and not TIMEOUT.)

... Running com.google.common.cache.CacheReferencesTest Tests run: 5, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 1,535.714 sec <<< FAILURE! Running com.google.common.cache.EmptyCachesTest <end of log>

... Running com.google.common.cache.CacheReferencesTest <end of log>

[gissuebot]

Original comment posted by cpovirk@google.com on 2013-12-09 at 09:54 PM

---

Here's the failure that I'm getting when I run with a couple flags (-Dtest.include="**/CacheReferencesTest.java" -Dsurefire.useFile=false):

Running com.google.common.cache.CacheReferencesTest Tests run: 5, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 279.781 sec <<< FAILURE! testCleanupOnReferenceCollection(com.google.common.cache.CacheReferencesTest) Time elapsed: 279.67 sec <<< FAILURE! junit.framework.AssertionFailedError: expected:<1> but was:<2>   at junit.framework.Assert.fail(Assert.java:47)   at junit.framework.Assert.failNotEquals(Assert.java:283)   at junit.framework.Assert.assertEquals(Assert.java:64)   at junit.framework.Assert.assertEquals(Assert.java:130)   at junit.framework.Assert.assertEquals(Assert.java:136)   at com.google.common.cache.CacheReferencesTest.assertCleanup(CacheReferencesTest.java:179)   at com.google.common.cache.CacheReferencesTest.testCleanupOnReferenceCollection(CacheReferencesTest.java:146)   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)   at java.lang.reflect.Method.invoke(Method.java:606)   at junit.framework.TestCase.runTest(TestCase.java:168)   at junit.framework.TestCase.runBare(TestCase.java:134)   at junit.framework.TestResult$1.protect(TestResult.java:110)   at junit.framework.TestResult.runProtected(TestResult.java:128)   at junit.framework.TestResult.run(TestResult.java:113)   at junit.framework.TestCase.run(TestCase.java:124)   at junit.framework.TestSuite.runTest(TestSuite.java:243)   at junit.framework.TestSuite.run(TestSuite.java:238)   at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)   at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:35)   at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:115)   at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:97)   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)   at java.lang.reflect.Method.invoke(Method.java:606)   at org.apache.maven.surefire.booter.ProviderFactory$ClassLoaderProxy.invoke(ProviderFactory.java:103)   at com.sun.proxy.$Proxy0.invoke(Unknown Source)   at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:150)   at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcess(SurefireStarter.java:91)   at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:69)

Here's the failing assertion: https://github.com/google/guava/blob/release15/guava-tests/test/com/google/common/cache/CacheReferencesTest.java#L179

[gissuebot]

Original comment posted by cpovirk@google.com on 2013-12-09 at 10:23 PM

---

Hmm, if the problem is the use of 64-bit JVMs, I have a theory: testCleanupOnReferenceCollection attempts to "fill up heap so soft references get cleared." If the 64-bit JVMs have a bigger heap, this would naturally take much longer, if it happens at all.

[gissuebot]

Original comment posted by cgdecker@google.com on 2013-12-09 at 10:36 PM

---

And it looks like by "fill up heap" it means "create bigger and bigger byte arrays until the array is 1 GB and then just keep creating 1 GB arrays and garbage collecting them".

[gissuebot]

Original comment posted by cpovirk@google.com on 2013-12-10 at 12:23 AM

---

If that's the problem, then a possible solution is to limit the memory available to Maven's test runner. For now, though, I'm going to suppress the test.

[ben-manes]

I saw this issue when comparing my tests with Guava's and wondering at first why Guava's even passed. Modifying my test to mimic Guava's causes it to run forever.

The problem is that the test creates eden-space strong-reference garbage. This will be collected by a minor collection, whereas soft references requires a major collection. The correct way to do this is to classify the generated garbage as soft references in order to force a major gc. As the eviction is performed in LRU order, it should keep creating garbage until a flag reference was cleared, meaning that the cache's contents must have been evicted too.

It also appears to have a questionable usage of drainReferenceQueues(). It reads as if the author assumed that it would fully drain the reference queues, whereas in fact that is not a guarantee. Because the cleanup is amortized across caller threads, each type of cleanup has a threshold on how many entries it will discard. This is so if a large cache suddenly has a high number of discardable entries, an excessive penalty will not be thrusted upon one caller. Instead it is spread out on many calls if need be. This is important as no one wants a user-facing request to suddenly halt for seconds due to cache cleanup.

The following test passes with both Caffeine and Guava caches.

  @Test(dataProvider = "caches")
  @CacheSpec(values = ReferenceType.SOFT, population = Population.FULL)
  public void evict_softValues(Cache<Integer, Integer> cache, CacheContext context) {
    context.original().clear();
    awaitSoftRefGc();
    cleanUp(cache, context, 0);
    assertThat(cache.size(), is(0L));
  }

  static void cleanUp(Cache<Integer, Integer> cache, CacheContext context, long finalSize) {
    // As clean-up is amortized, pretend that the increment count may be as low as per entry
    for (int i = 0; i < context.population().size(); i++) {
      cache.cleanUp();
      if (cache.size() == finalSize) {
        return; // passed
      }
    }
    Assert.fail("Expected an empty cache but has size: " + cache.size());
  }

  static void awaitSoftRefGc() {
    byte[] garbage = new byte[1024];
    SoftReference<Object> flag = new SoftReference<>(new Object());
    List<Object> softRefs = new ArrayList<>();
    while (flag.get() != null) {
      garbage = new byte[Math.max(garbage.length, garbage.length << 2)];
      softRefs.add(new SoftReference<>(garbage));
    }
  }

[ben-manes]

FYI, soft reference tests must be run sequentially and cannot use the G1 garbage collector. The first not surprising and is to avoid breaking tests that run in parallel due to out of memory errors. The second is because G1 does not provide a deterministic LRU eviction (cross region) which is much more efficient than a stop-the-world major collection, but breaks a simple detection scheme like the one above.

[ben-manes]

The best way to do this is to use -XX:SoftRefLRUPolicyMSPerMB=0 to force soft references to behave as weak references, thereby allowing the test to safely assume a GC will clear the reference. This means running the test through the build can be reliable, but a note on the unit test has to be added for anyone running the test through their IDE.