Runtime Exception during refresh prevents future refreshes.

[aschepp]

Hello,

I am not sure, if this is intended behaviour or not. If a RuntimeException happens during the refreshIfNeeded code, it will never be refreshed again, until the element is discarded by expire or removed otherwise.

@Test
public void refreshingCacheWithRuntimeException() throws InterruptedException {
	RuntimeExceptionTestCacheLoader runtimeExceptionTestCacheLoader = Mockito.spy(new RuntimeExceptionTestCacheLoader());
	LoadingCache<String, String> cache = Caffeine.newBuilder()
		.refreshAfterWrite(Duration.ofNanos(1))
		.expireAfterWrite(Duration.ofSeconds(1))
		.build(runtimeExceptionTestCacheLoader::apply);

	cache.put("key", "value");
	String value = cache.get("key");
	assertEquals("value", value);
	verify(runtimeExceptionTestCacheLoader, timeout(1000).times(1)).apply("key");
	value = cache.get("key");
	assertEquals("value", value);
	// This should've already called the loader again, but it doesn't.
	verify(runtimeExceptionTestCacheLoader, timeout(1000).times(1)).apply("key");
	// Wait for it to expire
	Thread.sleep(1500);
	assertThrows(RuntimeException.class, () -> cache.get("key"));
	verify(runtimeExceptionTestCacheLoader, timeout(2000).times(2)).apply("key");
}

public static class RuntimeExceptionTestCacheLoader implements Function<String, String> {

	@Override
	public String apply(String key) {
		throw new RuntimeException("Test");
	}
}

Thanks for your work,
Alex

[ben-manes]

Thanks! Can you check if this is the same as #1478? Sorry, I haven't had time to work on this project and will try to trace through your test this evening.

[ben-manes]

Oh, that other issue was only for an AsyncCache and unrelated to this.

Here your tests passes for me and I see multiple refreshes. If I add a println to your loader then it shows two refreshes. So it seems to be working on v3.1.8. What version are you using?

[aschepp]

Sorry, I should have written the test, so that it fails. In the correct case, all the times(x) should increase, but it doesn't in the second one.

[aschepp]

It should fail like this.

@Test
public void refreshingCacheWithRuntimeException() throws InterruptedException {
	RuntimeExceptionTestCacheLoader runtimeExceptionTestCacheLoader = Mockito.spy(new RuntimeExceptionTestCacheLoader());
	LoadingCache<String, String> cache = Caffeine.newBuilder()
		.refreshAfterWrite(Duration.ofNanos(1))
		.expireAfterWrite(Duration.ofSeconds(1))
		.build(runtimeExceptionTestCacheLoader::apply);

	cache.put("key", "value");
	String value = cache.get("key");
	assertEquals("value", value);
	verify(runtimeExceptionTestCacheLoader, timeout(1000).times(1)).apply("key");
	value = cache.get("key");
	assertEquals("value", value);
	// This should've already called the loader again, but it doesn't.
	verify(runtimeExceptionTestCacheLoader, timeout(1000).times(2)).apply("key");
	// Wait for it to expire
	Thread.sleep(1500);
	assertThrows(RuntimeException.class, () -> cache.get("key"));
	verify(runtimeExceptionTestCacheLoader, timeout(2000).times(3)).apply("key");
}

public static class RuntimeExceptionTestCacheLoader implements Function<String, String> {

	@Override
	public String apply(String key) {
		throw new RuntimeException("Test");
	}
}

[ben-manes]

I think you might be hitting a race condition because you are using the default executor, making things async. If I use a caller runs executor and make it more explicit using a CacheLoader, then I think it gives the right results?

  @Test
  public void refreshingCacheWithRuntimeException() throws InterruptedException {
    var runtimeExceptionTestCacheLoader = Mockito.spy(new RuntimeExceptionTestCacheLoader());
    LoadingCache<String, String> cache = Caffeine.newBuilder()
        .executor(Runnable::run)
        .refreshAfterWrite(Duration.ofNanos(1))
        .expireAfterWrite(Duration.ofSeconds(1))
        .build(runtimeExceptionTestCacheLoader);

    cache.put("key", "value");
    String value = cache.get("key");
    assertEquals("value", value);
    verify(runtimeExceptionTestCacheLoader, timeout(1000).times(1)).reload(eq("key"), anyString());
    value = cache.get("key");
    assertEquals("value", value);
    // This should've already called the loader again, but it doesn't.
    verify(runtimeExceptionTestCacheLoader, timeout(1000).times(2)).reload(eq("key"), anyString());
    // Wait for it to expire
    Thread.sleep(1500);
    assertThrows(RuntimeException.class, () -> cache.get("key"));
    verify(runtimeExceptionTestCacheLoader, timeout(2000).times(1)).load("key");
  }

  public static class RuntimeExceptionTestCacheLoader implements CacheLoader<String, String> {
    @Override
    public String load(String key) {
      System.err.println("Loading key: " + key);
      throw new RuntimeException("Test");
    }
    @Override
    public String reload(String key, String oldValue) {
      System.err.println("Refreshing key: " + key);
      throw new RuntimeException("Test");
    }
  }

[ben-manes]

fyi adding .executor(Runnable::run) to your test passes

[ben-manes]

When you do want to write a concurrent test, using a FakeTicker and Awaitility to manage time and concurrency really helpful. Using sleeps is unfortunately error prone so its better to coordinate it more explicitly. Those two are really good tools.

[aschepp]

Yeah, we normally use Awaitility, but it wasn't important in this case. I will test it next week, when I am working on this again and let you know. I'm pretty sure I already tested it with an executor as well. I just removed it to keep the test as small as possible.

[aschepp]

Actually, I tested it really quick, yes adding an executor seems to fix it. What I did was adding a scheduler in the past.

[aschepp]

Thanks for your help! Really appreciate it.

[ben-manes]

thanks. When I sprinkle some awaits after the cache.get calls then it passes using the default executor,

await().until(() -> cache.policy().refreshes().isEmpty());

[ben-manes]

wonderful! glad its not an issue. let me know if you run into anything else.