Race condition in computing write timestamp

[chaoren]

The expireAfterWrite timestamp for an async load should be computed when the CompletableFuture is complete and not when it is put into the cache, right? It looks like there's an after-write maintenance task to make incomplete CompletableFutures unevictable after the CompletableFuture is first put into the cache, but if the CompletableFuture is completed before that maintenance task runs, then the write timestamp would be incorrect.

Here's a failing test case of the issue:

  @Test
  public void writeTimeRaceCondition() {
    FakeTicker ticker = new FakeTicker();
    CountDownLatch latch = new CountDownLatch(1);
    AsyncCache<String, String> cache =
        Caffeine.newBuilder()
            .executor(
                command ->
                    commonPool()
                        .execute(
                            () -> {
                              awaitUninterruptibly(latch);
                              command.run(); // afterWrite maintenance task
                            }))
            .expireAfterWrite(Duration.ofMillis(5))
            .ticker(ticker::read)
            .buildAsync();
    CompletableFuture<String> future = cache.get("key", (k, e) -> new CompletableFuture<>());

    ticker.advance(Duration.ofMillis(10));
    future.complete("value");
    latch.countDown();

    assertThat(cache.getIfPresent("key")).isNotNull();
    ticker.advance(Duration.ofMillis(4));
    assertThat(cache.getIfPresent("key")).isNotNull();
    ticker.advance(Duration.ofMillis(1));
    assertThat(cache.getIfPresent("key")).isNull();
  }

[chaoren]

Looks like this is the part that ensures "that in-flight async computation cannot expire."

caffeine/caffeine/src/main/java/com/github/benmanes/caffeine/cache/BoundedLocalCache.java

Lines 1930 to 1940 in 5d453e9

	// Ensure that in-flight async computation cannot expire (reset on a completion callback)
	if (isComputingAsync(node)) {
	synchronized (node) {
	if (!Async.isReady((CompletableFuture<?>) node.getValue())) {
	long expirationTime = expirationTicker().read() + ASYNC_EXPIRY;
	setVariableTime(node, expirationTime);
	setAccessTime(node, expirationTime);
	setWriteTime(node, expirationTime);
	}
	}
	}

Why can't it be done synchronously at the same time as when the node is first inserted?

[ben-manes]

I wanted to investigate removing that (#1478 (comment)). I think that other changes meant this wasn't needed, and maybe an artifact of old logic or bug workarounds. Offhand I don't recall of the details, but it did seem like some of this should be changed to be simpler and more correct.

At insertion time the AsyncExpiry sets the value for a variable expired entry. For fixed expiration it might have seemed easier to do it here than at all of the other write paths. Ideally it would done at insertion time, but synchronized (node) for this task guard or the metadata update should have avoided a race due to the node lock.

[ben-manes]

Released in 3.2.0 (sorry for the delay)