From 4bb0e2a886b61b85f724bef52e3d728791cb0544 Mon Sep 17 00:00:00 2001 From: Ben Manes Date: Sat, 8 Jun 2024 20:42:03 -0700 Subject: [PATCH] fix when a weigher or expiry fail on an async completion (fixes #1687) --- .github/actions/run-gradle/action.yml | 2 +- .github/workflows/build.yml | 2 +- .../caffeine/cache/LocalAsyncCache.java | 95 ++++-- .../cache/LocalAsyncLoadingCache.java | 60 ++-- .../caffeine/cache/AsyncCacheTest.java | 78 +++-- .../caffeine/cache/AsyncLoadingCacheTest.java | 28 +- .../caffeine/cache/BoundedLocalCacheTest.java | 35 +- .../benmanes/caffeine/cache/CacheTest.java | 27 +- .../benmanes/caffeine/cache/CaffeineTest.java | 14 +- .../benmanes/caffeine/cache/EvictionTest.java | 323 +++++++++++++++++- .../caffeine/cache/ExpirationTest.java | 15 +- .../caffeine/cache/ExpireAfterVarTest.java | 228 +++++++++++++ .../caffeine/cache/LoadingCacheTest.java | 18 +- .../caffeine/cache/ReferenceTest.java | 19 +- .../caffeine/cache/RefreshAfterWriteTest.java | 28 +- .../caffeine/cache/SchedulerTest.java | 25 +- .../cache/stats/StatsCounterTest.java | 16 +- .../testing/CacheValidationListener.java | 9 +- .../caffeine/testing/LoggingEvents.java | 142 ++++++++ 19 files changed, 948 insertions(+), 216 deletions(-) create mode 100644 caffeine/src/test/java/com/github/benmanes/caffeine/testing/LoggingEvents.java diff --git a/.github/actions/run-gradle/action.yml b/.github/actions/run-gradle/action.yml index f0a7fe4877..00ed95801d 100644 --- a/.github/actions/run-gradle/action.yml +++ b/.github/actions/run-gradle/action.yml @@ -8,7 +8,7 @@ inputs: required: true description: The JDK version early-access: - default: '24' + default: '23' required: false description: The early access release graal: diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index eea5374a00..aa166edc16 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -39,7 +39,7 @@ env: schemastore.org:443 www.graalvm.org:443 PUBLISH_JDK: 11 - EA_JDK: 24 + EA_JDK: 23 jobs: compile: diff --git a/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncCache.java b/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncCache.java index 7c83f97a16..ecea8b4da8 100644 --- a/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncCache.java +++ b/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncCache.java @@ -48,6 +48,7 @@ import com.github.benmanes.caffeine.cache.LocalAsyncCache.AsyncBulkCompleter.NullMapCompletionException; import com.github.benmanes.caffeine.cache.stats.CacheStats; +import com.google.errorprone.annotations.CanIgnoreReturnValue; /** * This class provides a skeletal implementation of the {@link AsyncCache} interface to minimize the @@ -144,9 +145,9 @@ default CompletableFuture> getAll(Iterable keys, try { var loader = mappingFunction.apply( Collections.unmodifiableSet(proxies.keySet()), cache().executor()); - return loader.whenComplete(completer).thenCompose(ignored -> composeResult(futures)); + return loader.handle(completer).thenCompose(ignored -> composeResult(futures)); } catch (Throwable t) { - completer.accept(/* result */ null, t); + completer.apply(/* result */ null, t); throw t; } } @@ -214,9 +215,15 @@ default void handleCompletion(K key, CompletableFuture valueFuture, @SuppressWarnings("unchecked") var castedFuture = (CompletableFuture) valueFuture; - // update the weight and expiration timestamps - cache().statsCounter().recordLoadSuccess(loadTime); - cache().replace(key, castedFuture, castedFuture, /* shouldDiscardRefresh */ false); + try { + // update the weight and expiration timestamps + cache().replace(key, castedFuture, castedFuture, /* shouldDiscardRefresh */ false); + cache().statsCounter().recordLoadSuccess(loadTime); + } catch (Throwable t) { + logger.log(Level.WARNING, "Exception thrown during asynchronous load", t); + cache().statsCounter().recordLoadFailure(loadTime); + cache().remove(key, valueFuture); + } } if (recordMiss) { cache().statsCounter().recordMisses(1); @@ -226,7 +233,7 @@ default void handleCompletion(K key, CompletableFuture valueFuture, /** A function executed asynchronously after a bulk load completes. */ final class AsyncBulkCompleter - implements BiConsumer, Throwable> { + implements BiFunction, Throwable, Map> { private final LocalCache> cache; private final Map> proxies; private final long startTime; @@ -239,9 +246,28 @@ final class AsyncBulkCompleter } @Override - public void accept(@Nullable Map result, @Nullable Throwable error) { + @CanIgnoreReturnValue + public @Nullable Map apply( + @Nullable Map result, @Nullable Throwable error) { long loadTime = cache.statsTicker().read() - startTime; + var failure = handleResponse(result, error); + + if (failure == null) { + cache.statsCounter().recordLoadSuccess(loadTime); + return result; + } + cache.statsCounter().recordLoadFailure(loadTime); + if (failure instanceof RuntimeException) { + throw (RuntimeException) failure; + } else if (failure instanceof Error) { + throw (Error) failure; + } + throw new CompletionException(failure); + } + + private @Nullable Throwable handleResponse( + @Nullable Map result, @Nullable Throwable error) { if (result == null) { if (error == null) { error = new NullMapCompletionException(); @@ -250,38 +276,65 @@ public void accept(@Nullable Map result, @Nullable Thr cache.remove(entry.getKey(), entry.getValue()); entry.getValue().obtrudeException(error); } - cache.statsCounter().recordLoadFailure(loadTime); if (!(error instanceof CancellationException) && !(error instanceof TimeoutException)) { logger.log(Level.WARNING, "Exception thrown during asynchronous load", error); } + return error; } else { - fillProxies(result); - addNewEntries(result); - cache.statsCounter().recordLoadSuccess(loadTime); + var failure = fillProxies(result); + return addNewEntries(result, failure); } } /** Populates the proxies with the computed result. */ - private void fillProxies(Map result) { - proxies.forEach((key, future) -> { - V value = result.get(key); + private @Nullable Throwable fillProxies(Map result) { + Throwable error = null; + for (var entry : proxies.entrySet()) { + var key = entry.getKey(); + var value = result.get(key); + var future = entry.getValue(); future.obtrudeValue(value); + if (value == null) { cache.remove(key, future); } else { - // update the weight and expiration timestamps - cache.replace(key, future, future); + try { + // update the weight and expiration timestamps + cache.replace(key, future, future); + } catch (Throwable t) { + logger.log(Level.WARNING, "Exception thrown during asynchronous load", t); + cache.remove(key, future); + if (error == null) { + error = t; + } else { + error.addSuppressed(t); + } + } } - }); + } + return error; } /** Adds to the cache any extra entries computed that were not requested. */ - private void addNewEntries(Map result) { - result.forEach((key, value) -> { + private @Nullable Throwable addNewEntries( + Map result, @Nullable Throwable error) { + for (var entry : result.entrySet()) { + var key = entry.getKey(); + var value = result.get(key); if (!proxies.containsKey(key)) { - cache.put(key, CompletableFuture.completedFuture(value)); + try { + cache.put(key, CompletableFuture.completedFuture(value)); + } catch (Throwable t) { + logger.log(Level.WARNING, "Exception thrown during asynchronous load", t); + if (error == null) { + error = t; + } else { + error.addSuppressed(t); + } + } } - }); + } + return error; } static final class NullMapCompletionException extends CompletionException { diff --git a/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncLoadingCache.java b/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncLoadingCache.java index 77ae29f98e..838b198070 100644 --- a/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncLoadingCache.java +++ b/caffeine/src/main/java/com/github/benmanes/caffeine/cache/LocalAsyncLoadingCache.java @@ -295,36 +295,42 @@ public CompletableFuture> refreshAll(Iterable keys) { return; } - boolean[] discard = new boolean[1]; - var value = asyncCache.cache().compute(key, (ignored, currentValue) -> { - var successful = asyncCache.cache().refreshes().remove(keyReference, castedFuture); - if (successful && (currentValue == oldValueFuture[0])) { - if (currentValue == null) { - // If the entry is absent then discard the refresh and maybe notifying the listener - discard[0] = (newValue != null); - return null; - } else if ((currentValue == newValue) || (currentValue == castedFuture)) { - // If the reloaded value is the same instance then no-op - return currentValue; - } else if (newValue == Async.getIfReady((CompletableFuture) currentValue)) { - // If the completed futures hold the same value instance then no-op - return currentValue; + try { + boolean[] discard = new boolean[1]; + var value = asyncCache.cache().compute(key, (ignored, currentValue) -> { + var successful = asyncCache.cache().refreshes().remove(keyReference, castedFuture); + if (successful && (currentValue == oldValueFuture[0])) { + if (currentValue == null) { + // If the entry is absent then discard the refresh and maybe notifying the listener + discard[0] = (newValue != null); + return null; + } else if ((currentValue == newValue) || (currentValue == castedFuture)) { + // If the reloaded value is the same instance then no-op + return currentValue; + } else if (newValue == Async.getIfReady((CompletableFuture) currentValue)) { + // If the completed futures hold the same value instance then no-op + return currentValue; + } + return (newValue == null) ? null : castedFuture; } - return (newValue == null) ? null : castedFuture; + // Otherwise, a write invalidated the refresh so discard it and notify the listener + discard[0] = true; + return currentValue; + }, asyncCache.cache().expiry(), /* recordLoad */ false, /* recordLoadFailure */ true); + + if (discard[0] && (newValue != null)) { + var cause = (value == null) ? RemovalCause.EXPLICIT : RemovalCause.REPLACED; + asyncCache.cache().notifyRemoval(key, castedFuture, cause); } - // Otherwise, a write invalidated the refresh so discard it and notify the listener - discard[0] = true; - return currentValue; - }, asyncCache.cache().expiry(), /* recordLoad */ false, /* recordLoadFailure */ true); - - if (discard[0] && (newValue != null)) { - var cause = (value == null) ? RemovalCause.EXPLICIT : RemovalCause.REPLACED; - asyncCache.cache().notifyRemoval(key, castedFuture, cause); - } - if (newValue == null) { + if (newValue == null) { + asyncCache.cache().statsCounter().recordLoadFailure(loadTime); + } else { + asyncCache.cache().statsCounter().recordLoadSuccess(loadTime); + } + } catch (Throwable t) { + logger.log(Level.WARNING, "Exception thrown during asynchronous load", t); asyncCache.cache().statsCounter().recordLoadFailure(loadTime); - } else { - asyncCache.cache().statsCounter().recordLoadSuccess(loadTime); + asyncCache.cache().remove(key, castedFuture); } }); } diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncCacheTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncCacheTest.java index df5b5a255e..3098629344 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncCacheTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncCacheTest.java @@ -24,6 +24,7 @@ import static com.github.benmanes.caffeine.testing.CollectionSubject.assertThat; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; import static com.github.benmanes.caffeine.testing.IntSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; @@ -66,7 +67,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoEvictions; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.collect.ImmutableSet; import com.google.common.collect.Iterables; import com.google.common.collect.Maps; @@ -169,12 +169,12 @@ public void getFunc_absent_failure(AsyncCache cache, CacheContext cont assertThat(valueFuture).hasCompletedExceptionally(); assertThat(cache).doesNotContainKey(context.absentKey()); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()) - .hasCauseThat().isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withUnderlyingCause(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -297,11 +297,12 @@ public void getBiFunc_absent_failure_before(AsyncCache cache, CacheCon assertThat(valueFuture).hasCompletedExceptionally(); assertThat(cache).doesNotContainKey(key); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @CacheSpec @@ -316,11 +317,12 @@ public void getBiFunc_absent_failure_after(AsyncCache cache, CacheCont assertThat(valueFuture).hasCompletedExceptionally(); assertThat(cache).doesNotContainKey(key); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @CacheSpec @@ -446,12 +448,12 @@ public void getAllFunction_absent_failure(AsyncCache cache, CacheConte .hasCauseThat().isInstanceOf(IllegalStateException.class); int misses = context.absentKeys().size(); assertThat(context).stats().hits(0).misses(misses).success(0).failures(1); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()) - .hasCauseThat().isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withUnderlyingCause(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -739,11 +741,12 @@ public void getAllBifunction_absent_failure(AsyncCache cache, CacheCon assertThat(future).failsWith(CompletionException.class) .hasCauseThat().isInstanceOf(IllegalStateException.class); assertThat(context).stats().hits(0).misses(context.absentKeys().size()).success(0).failures(1); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @CacheSpec @@ -1010,7 +1013,7 @@ public void getAllBifunction_early_failure(AsyncCache cache, CacheCont } else { assertThat(result.join()).containsExactlyEntriesIn(context.absent()); } - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } /* --------------- put --------------- */ @@ -1043,7 +1046,7 @@ public void put_insert_failure_before(AsyncCache cache, CacheContext c cache.put(context.absentKey(), failedFuture); assertThat(cache).hasSize(context.initialSize()); assertThat(cache).doesNotContainKey(context.absentKey()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @Test(dataProvider = "caches") @@ -1055,11 +1058,12 @@ public void put_insert_failure_after(AsyncCache cache, CacheContext co failedFuture.completeExceptionally(new IllegalStateException()); assertThat(cache).doesNotContainKey(context.absentKey()); assertThat(cache).hasSize(context.initialSize()); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -1081,7 +1085,7 @@ public void put_replace_failure_before(AsyncCache cache, CacheContext cache.put(context.middleKey(), failedFuture); assertThat(cache).hasSize(context.initialSize() - 1); assertThat(cache).doesNotContainKey(context.absentKey()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @Test(dataProvider = "caches") @@ -1093,7 +1097,7 @@ public void put_replace_failure_after(AsyncCache cache, CacheContext c failedFuture.completeExceptionally(new IllegalStateException()); assertThat(cache).doesNotContainKey(context.absentKey()); assertThat(cache).hasSize(context.initialSize() - 1); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncLoadingCacheTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncLoadingCacheTest.java index 6f6319db79..70a6fdc282 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncLoadingCacheTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/AsyncLoadingCacheTest.java @@ -22,6 +22,7 @@ import static com.github.benmanes.caffeine.testing.CollectionSubject.assertThat; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; import static com.github.benmanes.caffeine.testing.IntSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; @@ -64,7 +65,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoEvictions; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.collect.ImmutableMap; import com.google.common.collect.ImmutableSet; import com.google.common.collect.Iterables; @@ -100,12 +100,12 @@ public void get_absent(AsyncLoadingCache cache, CacheContext context) public void get_absent_failure(AsyncLoadingCache cache, CacheContext context) { assertThat(cache.get(context.absentKey())).hasCompletedExceptionally(); assertThat(cache).doesNotContainKey(context.absentKey()); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()) - .hasCauseThat().isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withUnderlyingCause(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -232,14 +232,12 @@ public void getAll_absent_failure(AsyncLoadingCache cache, CacheContex int misses = context.absentKeys().size(); int loadFailures = (context.loader().isBulk() || context.isSync()) ? 1 : misses; assertThat(context).stats().hits(0).misses(misses).success(0).failures(loadFailures); - - for (var event : TestLoggerFactory.getLoggingEvents()) { - assertThat(event.getFormattedMessage()).isAnyOf( - "Exception thrown during asynchronous load", "Exception thrown during asynchronous load"); - assertThat(event.getThrowable().orElseThrow()) - .hasCauseThat().isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); - } + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withUnderlyingCause(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(loadFailures); } @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/BoundedLocalCacheTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/BoundedLocalCacheTest.java index 396fec48a9..8fdbad4fea 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/BoundedLocalCacheTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/BoundedLocalCacheTest.java @@ -39,6 +39,7 @@ import static com.github.benmanes.caffeine.testing.Awaits.await; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; import static com.github.benmanes.caffeine.testing.IntSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.truth.Truth.assertThat; @@ -254,12 +255,12 @@ public void cleanupTask_exception() { doThrow(expected).when(cache).performCleanUp(any()); var task = new PerformCleanupTask(cache); assertThat(task.exec()).isFalse(); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).isSameInstanceAs(expected); - assertThat(event.getFormattedMessage()).isEqualTo( - "Exception thrown when performing the maintenance task"); - assertThat(event.getLevel()).isEqualTo(ERROR); + assertThat(logEvents() + .withMessage("Exception thrown when performing the maintenance task") + .withThrowable(expected) + .withLevel(ERROR) + .exclusively()) + .hasSize(1); } @Test @@ -271,11 +272,12 @@ public void cleanup_exception() { doCallRealMethod().when(cache).cleanUp(); cache.cleanUp(); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).isSameInstanceAs(expected); - assertThat(event.getFormattedMessage()).isEqualTo( - "Exception thrown when performing the maintenance task"); - assertThat(event.getLevel()).isEqualTo(ERROR); + assertThat(logEvents() + .withMessage("Exception thrown when performing the maintenance task") + .withThrowable(expected) + .withLevel(ERROR) + .exclusively()) + .hasSize(1); } @Test @@ -555,11 +557,12 @@ public void afterWrite_exception() { assertThat(cache.drainStatus).isEqualTo(PROCESSING_TO_REQUIRED); cache.afterWrite(pendingTask); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).isSameInstanceAs(expected); - assertThat(event.getFormattedMessage()).isEqualTo( - "Exception thrown when performing the maintenance task"); - assertThat(event.getLevel()).isEqualTo(ERROR); + assertThat(logEvents() + .withMessage("Exception thrown when performing the maintenance task") + .withThrowable(expected) + .withLevel(ERROR) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CacheTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CacheTest.java index 981deb1499..018aee0749 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CacheTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CacheTest.java @@ -20,8 +20,8 @@ import static com.github.benmanes.caffeine.cache.testing.CacheContext.intern; import static com.github.benmanes.caffeine.cache.testing.CacheContextSubject.assertThat; import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; -import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; import static com.google.common.truth.Truth.assertThat; import static com.google.common.truth.Truth.assertWithMessage; @@ -86,7 +86,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoEvictions; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.collect.ImmutableMap; import com.google.common.collect.ImmutableSet; import com.google.common.collect.ImmutableSetMultimap; @@ -845,11 +844,12 @@ public void cleanup(Cache cache, CacheContext context) { @CacheSpec(population = Population.SINGLETON, removalListener = Listener.REJECTING) public void removalListener_error_log(Cache cache, CacheContext context) { cache.invalidateAll(); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getLevel()).isEqualTo(WARN); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown by removal listener"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(RejectedExecutionException.class); + assertThat(logEvents() + .withMessage("Exception thrown by removal listener") + .withThrowable(RejectedExecutionException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @CheckMaxLogLevel(ERROR) @@ -859,13 +859,12 @@ public void removalListener_error_log(Cache cache, CacheContext contex removalListener = Listener.CONSUMING) public void removalListener_submit_error_log(Cache cache, CacheContext context) { cache.invalidateAll(); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents().stream() - .filter(e -> e.getLevel() == ERROR) - .collect(toImmutableList())); - assertThat(event.getFormattedMessage()).isEqualTo( - "Exception thrown when submitting removal listener"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(RejectedExecutionException.class); + assertThat(logEvents() + .withMessage("Exception thrown when submitting removal listener") + .withThrowable(RejectedExecutionException.class) + .withLevel(ERROR) + .exclusively()) + .hasSize(1); } @CheckNoStats diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CaffeineTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CaffeineTest.java index eaf3f7be47..ca95e74cb4 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CaffeineTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/CaffeineTest.java @@ -15,6 +15,7 @@ */ package com.github.benmanes.caffeine.cache; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.google.common.truth.Truth.assertThat; import static com.google.common.util.concurrent.MoreExecutors.directExecutor; import static org.junit.Assert.assertThrows; @@ -46,7 +47,6 @@ import com.github.benmanes.caffeine.cache.testing.CacheSpec.Maximum; import com.github.benmanes.caffeine.cache.testing.CacheSpec.Population; import com.github.valfirst.slf4jtest.TestLoggerFactory; -import com.google.common.collect.Iterables; import com.google.common.testing.FakeTicker; import com.google.common.testing.NullPointerTester; @@ -112,12 +112,12 @@ public void fromSpec_null() { public void fromSpec_lenientParsing() { var cache = Caffeine.from(CaffeineSpec.parse("maximumSize=100")).weigher((k, v) -> 0).build(); assertThat(cache).isNotNull(); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()) - .isEqualTo("ignoring weigher specified without maximumWeight"); - assertThat(event.getThrowable()).isEmpty(); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("ignoring weigher specified without maximumWeight") + .withoutThrowable() + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/EvictionTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/EvictionTest.java index 51ea883b55..2f18254635 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/EvictionTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/EvictionTest.java @@ -25,6 +25,8 @@ import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; import static com.github.benmanes.caffeine.testing.Awaits.await; import static com.github.benmanes.caffeine.testing.ConcurrentTestHarness.executor; +import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; @@ -42,6 +44,7 @@ import java.util.List; import java.util.Map; import java.util.concurrent.CompletableFuture; +import java.util.concurrent.CompletionException; import java.util.concurrent.RejectedExecutionException; import java.util.concurrent.atomic.AtomicBoolean; @@ -58,6 +61,7 @@ import com.github.benmanes.caffeine.cache.testing.CacheSpec.Implementation; import com.github.benmanes.caffeine.cache.testing.CacheSpec.InitialCapacity; import com.github.benmanes.caffeine.cache.testing.CacheSpec.Listener; +import com.github.benmanes.caffeine.cache.testing.CacheSpec.Loader; import com.github.benmanes.caffeine.cache.testing.CacheSpec.Maximum; import com.github.benmanes.caffeine.cache.testing.CacheSpec.Population; import com.github.benmanes.caffeine.cache.testing.CacheValidationListener; @@ -65,7 +69,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.cache.testing.RemovalListeners.RejectingRemovalListener; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.collect.ImmutableList; import com.google.common.collect.Maps; import com.google.common.collect.Range; @@ -273,18 +276,54 @@ public void evict_zero_async(AsyncCache> cache, CacheContext cont public void evict_evictionListener_failure(Cache cache, CacheContext context) { cache.policy().eviction().ifPresent(policy -> policy.setMaximum(0)); assertThat(context).evictionNotifications().hasSize(context.original().size()); + assertThat(logEvents() + .withMessage("Exception thrown by eviction listener") + .withThrowable(RejectedExecutionException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.original().size()); + } + + /* --------------- Weighted --------------- */ - var events = TestLoggerFactory.getLoggingEvents().stream() - .filter(e -> e.getFormattedMessage().equals("Exception thrown by eviction listener")) - .collect(toImmutableList()); - assertThat(events).hasSize(context.original().size()); - for (var event : events) { - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(RejectedExecutionException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void getAll_weigherFails(Cache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + assertThrows(IllegalStateException.class, () -> + cache.getAll(context.absentKeys(), keys -> Maps.toMap(keys, Int::negate))); + assertThat(cache).containsExactlyEntriesIn(context.original()); + if (context.isCaffeine()) { + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.isAsync() ? context.absentKeys().size() : 0); } } - /* --------------- Weighted --------------- */ + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void getAll_weigherFails_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture>(); + var result = cache.getAll(context.absentKeys(), (keys, executor) -> future); + future.complete(Maps.toMap(context.absentKeys(), Int::negate)); + + assertThat(context).stats().failures(1); + assertThat(result).failsWith(CompletionException.class) + .hasCauseThat().isInstanceOf(IllegalStateException.class); + assertThat(cache).containsExactlyEntriesIn(context.original()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.absentKeys().size()); + } @Test(dataProvider = "caches") @CacheSpec(population = Population.EMPTY, @@ -305,6 +344,24 @@ public void put_weigherFails_insert(Cache cache, CacheContext context) assertThat(cache).doesNotContainKey(context.absentKey()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void put_weigherFails_insert_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.put(context.absentKey(), future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) @@ -317,6 +374,24 @@ public void put_weigherFails_update(Cache cache, assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void put_weigherFails_update_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.put(context.absentKey(), future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(maximumSize = Maximum.FULL, weigher = CacheWeigher.ZERO, population = Population.EMPTY) @@ -402,6 +477,24 @@ public void replace_weigherFails_present(Cache cache, assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void replace_weigherFails_present_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().replace(context.firstKey(), future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.EMPTY, maximumSize = Maximum.FULL, weigher = CacheWeigher.COLLECTION) @@ -471,11 +564,30 @@ public void replaceConditionally_weigherFails_presentKey( Cache cache, CacheContext context, Eviction eviction) { when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); assertThrows(IllegalStateException.class, () -> - cache.asMap().replace(context.firstKey(), context.absentValue(), context.absentValue())); + cache.asMap().replace(context.firstKey(), context.absentValue())); assertThat(cache).containsExactlyEntriesIn(context.original()); assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void replaceConditionally_weigherFails_presentKey_async( + AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().replace(context.firstKey(), future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) @@ -490,6 +602,25 @@ public void replaceConditionally_weigherFails_presentKeyAndValue( assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void replaceConditionally_weigherFails_presentKeyAndValue_async( + AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().replace(context.firstKey(), cache.getIfPresent(context.firstKey()), future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.EMPTY, maximumSize = Maximum.FULL, weigher = CacheWeigher.COLLECTION) @@ -552,6 +683,24 @@ public void computeIfAbsent_weigherFails(Cache cache, CacheContext con assertThat(cache).doesNotContainKey(context.absentKey()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void computeIfAbsent_weigherFails_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().computeIfAbsent(context.absentKey(), key -> future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.EMPTY, maximumSize = Maximum.FULL, weigher = CacheWeigher.TEN) @@ -574,6 +723,25 @@ public void computeIfPresent_weigherFails(Cache cache, assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void computeIfPresent_weigherFails(AsyncCache cache, + CacheContext context, Eviction eviction) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().computeIfPresent(context.firstKey(), (key, value) -> future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.UNREACHABLE, weigher = CacheWeigher.VALUE) @@ -597,6 +765,24 @@ public void compute_weigherFails_absent(Cache cache, CacheContext cont assertThat(cache).doesNotContainKey(context.absentKey()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void compute_weigherFails_absent_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().compute(context.absentKey(), (key, value) -> future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) @@ -609,6 +795,24 @@ public void compute_weigherFails_present(Cache cache, assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void compute_weigherFails_present_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().compute(context.firstKey(), (key, value) -> future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.UNREACHABLE, weigher = CacheWeigher.VALUE) @@ -641,10 +845,31 @@ public void compute_update(Cache cache, public void merge_weigherFails_absent(Cache cache, CacheContext context) { when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); assertThrows(IllegalStateException.class, () -> { - cache.asMap().merge(context.absentKey(), - context.absentKey(), (key, value) -> context.absentValue()); + cache.asMap().merge(context.absentKey(), context.absentKey(), (key, value) -> { + throw new AssertionError(); + }); + }); + assertThat(cache).doesNotContainKey(context.absentKey()); + } + + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void merge_weigherFails_absent_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().merge(context.absentKey(), future, (key, value) -> { + throw new AssertionError(); }); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -661,6 +886,24 @@ public void merge_weigherFails_present(Cache cache, assertThat(eviction.weightOf(context.firstKey())).hasValue(1); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void merge_weigherFails_present_async(AsyncCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = new CompletableFuture(); + cache.asMap().merge(context.firstKey(), future, (key, value) -> future); + future.complete(context.absentValue()); + assertThat(context).stats().failures(1); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, maximumSize = Maximum.UNREACHABLE, weigher = CacheWeigher.VALUE) @@ -689,6 +932,62 @@ public void merge_update(Cache cache, assertThat(context).hasWeightedSize(weightedSize); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void refresh_weigherFails_absent(LoadingCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + try { + cache.refresh(context.absentKey()).join(); + } catch (IllegalStateException e) { /* ignored */ } + assertThat(cache).doesNotContainKey(context.absentKey()); + } + + @Test(dataProvider = "caches") + @CacheSpec(population = Population.EMPTY, implementation = Implementation.Caffeine, + loader = Loader.ASYNC_INCOMPLETE, maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void refresh_weigherFails_absent_async( + LoadingCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = cache.refresh(context.absentKey()); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.isAsync() ? 1 : 0); + } + + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, loader = Loader.IDENTITY, + maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void refresh_weigherFails_present(LoadingCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + try { + cache.refresh(context.firstKey()).join(); + } catch (IllegalStateException e) { /* ignored */ } + assertThat(cache).containsExactlyEntriesIn(context.original()); + } + + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, implementation = Implementation.Caffeine, + loader = Loader.ASYNC_INCOMPLETE, maximumSize = Maximum.FULL, weigher = CacheWeigher.MOCKITO) + public void refresh_weigherFails_present_async( + LoadingCache cache, CacheContext context) { + when(context.weigher().weigh(any(), any())).thenThrow(IllegalStateException.class); + var future = cache.refresh(context.firstKey()); + future.complete(context.absentValue()); + assertThat(cache).containsExactlyEntriesIn(context.original()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.isAsync() ? 1 : 0); + } + /* --------------- Policy --------------- */ @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpirationTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpirationTest.java index 779ef3c31a..eea96ad211 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpirationTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpirationTest.java @@ -25,9 +25,9 @@ import static com.github.benmanes.caffeine.cache.testing.CacheSpec.Expiration.VARIABLE; import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.base.Functions.identity; -import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.truth.Truth.assertThat; import static java.util.Map.entry; import static org.junit.Assert.assertThrows; @@ -72,9 +72,7 @@ import com.github.benmanes.caffeine.cache.testing.CheckMaxLogLevel; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.base.Splitter; -import com.google.common.collect.Iterables; import com.google.common.collect.Maps; import com.google.common.collect.Range; import com.google.common.util.concurrent.Futures; @@ -125,11 +123,12 @@ public void expire_evictionListener_failure(Cache cache, CacheContext assertThat(cache).isEmpty(); assertThat(context).evictionNotifications().hasSize(1); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents().stream() - .filter(e -> e.getFormattedMessage().equals("Exception thrown by eviction listener")) - .collect(toImmutableList())); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(RejectedExecutionException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown by eviction listener") + .withThrowable(RejectedExecutionException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpireAfterVarTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpireAfterVarTest.java index 1426cfa705..acfe70b48a 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpireAfterVarTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ExpireAfterVarTest.java @@ -27,7 +27,9 @@ import static com.github.benmanes.caffeine.cache.testing.CacheSpec.Expiration.VARIABLE; import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; import static com.github.benmanes.caffeine.testing.Awaits.await; +import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; import static com.github.benmanes.caffeine.testing.IntSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; @@ -50,6 +52,7 @@ import java.util.HashMap; import java.util.Map; import java.util.concurrent.CompletableFuture; +import java.util.concurrent.CompletionException; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.BiFunction; @@ -76,6 +79,7 @@ import com.github.benmanes.caffeine.testing.ConcurrentTestHarness; import com.github.benmanes.caffeine.testing.Int; import com.google.common.collect.ImmutableList; +import com.google.common.collect.Maps; import com.google.common.testing.SerializableTester; /** @@ -286,6 +290,23 @@ public void replace_expiryFails(Map map, CacheContext context) { assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void replace_expiryFails_async(AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.asMap().replace(context.firstKey(), future); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.firstKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiryTime = Expire.ONE_MINUTE, expiry = CacheExpiry.CREATE) @@ -310,6 +331,25 @@ public void replaceConditionally_expiryFails(Map map, CacheContext con assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void replaceConditionally_expiryFails_asybc( + AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var prior = cache.getIfPresent(context.firstKey()); + var future = new CompletableFuture(); + cache.asMap().replace(context.firstKey(), prior, future); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.firstKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + /* --------------- Exceptional --------------- */ @Test(dataProvider = "caches") @@ -334,6 +374,23 @@ public void get_expiryFails_create(Cache cache, CacheContext context) assertThat(cache).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void get_expiryFails_create_async(AsyncCache cache, CacheContext context) { + context.ticker().advance(Duration.ofHours(1)); + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = cache.get(context.absentKey(), (key, executor) -> new CompletableFuture()); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void get_expiryFails_read(Cache cache, CacheContext context) { @@ -345,6 +402,38 @@ public void get_expiryFails_read(Cache cache, CacheContext context) { assertThat(cache).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void getAll_expiryFails(Cache cache, CacheContext context) { + context.ticker().advance(Duration.ofHours(1)); + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + assertThrows(ExpirationException.class, () -> + cache.getAll(context.absentKeys(), keys -> Maps.toMap(keys, Int::negate))); + context.ticker().advance(Duration.ofHours(-1)); + assertThat(cache).containsExactlyEntriesIn(context.original()); + } + + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void getAll_expiryFails_async(AsyncCache cache, CacheContext context) { + context.ticker().advance(Duration.ofHours(1)); + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture>(); + var result = cache.getAll(context.absentKeys(), (keys, executor) -> future); + future.complete(Maps.toMap(context.absentKeys(), Int::negate)); + assertThat(result).failsWith(CompletionException.class) + .hasCauseThat().isInstanceOf(ExpirationException.class); + assertThat(cache).containsExactlyEntriesIn(context.original()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.absentKeys().size()); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void getAllPresent_expiryFails(Cache cache, CacheContext context) { @@ -369,6 +458,24 @@ public void put_insert_expiryFails(Cache cache, CacheContext context) assertThat(cache).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void put_insert_expiryFails_async(AsyncCache cache, CacheContext context) { + context.ticker().advance(Duration.ofHours(1)); + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.put(context.absentKey(), future); + future.complete(context.absentKey()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO, expiryTime = Expire.ONE_MINUTE) @@ -406,6 +513,25 @@ public void put_update_expiryFails(Cache cache, assertThat(currentDuration).isEqualTo(expectedDuration); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void put_update_expiryFails_async(AsyncCache cache, + CacheContext context, VarExpiration expireVariably) { + context.ticker().advance(Duration.ofHours(1)); + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.put(context.firstKey(), future); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.firstKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + /* --------------- Compute --------------- */ @Test(dataProvider = "caches") @@ -441,6 +567,23 @@ public void computeIfAbsent_expiryFails(Map map, CacheContext context) assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void computeIfAbsent_expiryFails_async(AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.asMap().computeIfAbsent(context.absentKey(), key -> future); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void computeIfPresent_absent(Map map, CacheContext context) { @@ -481,6 +624,23 @@ public void computeIfPresent_expiryFails(Map map, CacheContext context assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void computeIfPresent_expiryFails_async(AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.asMap().computeIfPresent(context.firstKey(), (k, v) -> future); + future.complete(context.firstKey()); + assertThat(cache).doesNotContainKey(context.firstKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void compute_absent(Map map, CacheContext context) { @@ -555,6 +715,23 @@ public void refresh_absent(LoadingCache cache, CacheContext context) { verifyNoMoreInteractions(context.expiry()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + expiry = CacheExpiry.MOCKITO, loader = Loader.ASYNC_INCOMPLETE) + public void refresh_expiryFails_absent(LoadingCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = cache.refresh(context.absentKey()); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.isAsync() ? 1 : 0); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void refresh_present(LoadingCache cache, CacheContext context) { @@ -564,6 +741,23 @@ public void refresh_present(LoadingCache cache, CacheContext context) verifyNoMoreInteractions(context.expiry()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, + expiry = CacheExpiry.MOCKITO, loader = Loader.ASYNC_INCOMPLETE) + public void refresh_expiryFails_present(LoadingCache cache, CacheContext context) { + when(context.expiry().expireAfterUpdate(any(), any(), anyLong(), anyLong())) + .thenThrow(ExpirationException.class); + var future = cache.refresh(context.firstKey()); + future.complete(context.absentValue()); + assertThat(cache).containsExactlyEntriesIn(context.original()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.isAsync() ? 1 : 0); + } + /* --------------- Policy --------------- */ @CheckNoStats @@ -1349,6 +1543,23 @@ public void compute_absent_expiryFails(Map map, CacheContext context) assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void compute_absent_expiryFails_async(AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.asMap().compute(context.absentKey(), (k, v) -> future); + future.complete(context.absentValue()); + assertThat(cache).doesNotContainKey(context.absentKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + @Test(dataProvider = "caches") @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) public void compute_present_expiryFails(Map map, CacheContext context) { @@ -1359,6 +1570,23 @@ public void compute_present_expiryFails(Map map, CacheContext context) assertThat(map).containsExactlyEntriesIn(context.original()); } + @Test(dataProvider = "caches") + @CacheSpec(population = Population.FULL, expiry = CacheExpiry.MOCKITO) + public void compute_present_expiryFails_async(AsyncCache cache, CacheContext context) { + when(context.expiry().expireAfterCreate(any(), any(), anyLong())) + .thenThrow(ExpirationException.class); + var future = new CompletableFuture(); + cache.asMap().compute(context.firstKey(), (k, v) -> future); + future.complete(context.firstKey()); + assertThat(cache).doesNotContainKey(context.firstKey()); + assertThat(logEvents() + .withMessage("Exception thrown during asynchronous load") + .withThrowable(ExpirationException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); + } + /* --------------- Policy: oldest --------------- */ @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/LoadingCacheTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/LoadingCacheTest.java index 7d44442a7e..65a7dd08af 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/LoadingCacheTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/LoadingCacheTest.java @@ -29,6 +29,7 @@ import static com.github.benmanes.caffeine.testing.CollectionSubject.assertThat; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; import static com.github.benmanes.caffeine.testing.IntSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.collect.ImmutableMap.toImmutableMap; import static com.google.common.truth.Truth.assertThat; @@ -72,7 +73,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoEvictions; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.base.Functions; import com.google.common.cache.CacheLoader.InvalidCacheLoadException; import com.google.common.collect.ImmutableMap; @@ -906,7 +906,7 @@ public void refresh_cancel_noLog(CacheContext context) { ? context.buildAsync(cacheLoader).synchronous() : context.build(cacheLoader); cache.refresh(context.absentKey()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @Test(dataProvider = "caches") @@ -928,7 +928,7 @@ public void refresh_timeout_noLog(CacheContext context) { ? context.buildAsync(cacheLoader).synchronous() : context.build(cacheLoader); cache.refresh(context.absentKey()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @Test(dataProvider = "caches") @@ -941,11 +941,13 @@ public void refresh_error_log(CacheContext context) { ? context.buildAsync(cacheLoader).synchronous() : context.build(cacheLoader); cache.refresh(context.absentKey()); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).hasCauseThat().isSameInstanceAs(expected); - assertThat(event.getFormattedMessage()).isAnyOf( - "Exception thrown during asynchronous load", "Exception thrown during refresh"); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage(msg -> msg.equals("Exception thrown during asynchronous load") + || msg.equals("Exception thrown during refresh")) + .withUnderlyingCause(expected) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ReferenceTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ReferenceTest.java index 4498aa2195..dadcb60158 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ReferenceTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/ReferenceTest.java @@ -22,11 +22,12 @@ import static com.github.benmanes.caffeine.cache.testing.CacheContext.intern; import static com.github.benmanes.caffeine.cache.testing.CacheContextSubject.assertThat; import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; +import static com.github.benmanes.caffeine.testing.CollectionSubject.assertThat; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.base.Predicates.equalTo; import static com.google.common.base.Predicates.not; -import static com.google.common.collect.ImmutableList.toImmutableList; import static com.google.common.collect.ImmutableMap.toImmutableMap; import static com.google.common.truth.Truth.assertThat; import static java.util.function.Function.identity; @@ -73,7 +74,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckMaxLogLevel; import com.github.benmanes.caffeine.cache.testing.CheckNoStats; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; import com.google.common.base.Splitter; import com.google.common.collect.Maps; import com.google.common.testing.EqualsTester; @@ -116,15 +116,12 @@ public void collect_evictionListener_failure(CacheContext context) { assertThat(context.cache()).whenCleanedUp().isEmpty(); assertThat(context).evictionNotifications().hasSize(context.initialSize()); - - var events = TestLoggerFactory.getLoggingEvents().stream() - .filter(e -> e.getFormattedMessage().equals("Exception thrown by eviction listener")) - .collect(toImmutableList()); - assertThat(events).hasSize((int) context.initialSize()); - for (var event : events) { - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(RejectedExecutionException.class); - assertThat(event.getLevel()).isEqualTo(WARN); - } + assertThat(logEvents() + .withMessage("Exception thrown by eviction listener") + .withThrowable(RejectedExecutionException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(context.initialSize()); } /* --------------- Cache --------------- */ diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/RefreshAfterWriteTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/RefreshAfterWriteTest.java index 8dadfd4eb1..29d4736430 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/RefreshAfterWriteTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/RefreshAfterWriteTest.java @@ -27,6 +27,7 @@ import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; import static com.github.benmanes.caffeine.testing.Awaits.await; import static com.github.benmanes.caffeine.testing.FutureSubject.assertThat; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.github.benmanes.caffeine.testing.MapSubject.assertThat; import static com.google.common.truth.Truth.assertThat; import static java.util.function.Function.identity; @@ -66,8 +67,6 @@ import com.github.benmanes.caffeine.cache.testing.CheckNoEvictions; import com.github.benmanes.caffeine.testing.ConcurrentTestHarness; import com.github.benmanes.caffeine.testing.Int; -import com.github.valfirst.slf4jtest.TestLoggerFactory; -import com.google.common.collect.Iterables; import com.google.common.collect.Maps; import com.google.errorprone.annotations.CanIgnoreReturnValue; @@ -342,7 +341,7 @@ public void refreshIfNeeded_cancel_noLog(CacheContext context) { var value = cache.get(context.absentKey()); assertThat(value).isEqualTo(context.absentValue()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @CheckNoEvictions @@ -370,7 +369,7 @@ public void refreshIfNeeded_timeout_noLog(CacheContext context) { var value = cache.get(context.absentKey()); assertThat(value).isEqualTo(context.absentValue()); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); + assertThat(logEvents()).isEmpty(); } @CheckNoEvictions @@ -388,10 +387,12 @@ public void refreshIfNeeded_error_log(CacheContext context) { var value = cache.get(context.absentKey()); assertThat(value).isEqualTo(context.absentValue()); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).hasCauseThat().isSameInstanceAs(expected); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown during refresh"); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown during refresh") + .withUnderlyingCause(expected) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } @Test(dataProvider = "caches") @@ -418,11 +419,12 @@ public void refreshIfNeeded_nullFuture(CacheContext context) { var value = cache.get(context.absentKey()); assertThat(value).isNotNull(); - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(NullPointerException.class); - assertThat(event.getFormattedMessage()).isEqualTo( - "Exception thrown when submitting refresh task"); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown when submitting refresh task") + .withThrowable(NullPointerException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); assertThat(refreshed.get()).isTrue(); assertThat(cache.policy().refreshes()).isEmpty(); diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/SchedulerTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/SchedulerTest.java index a6389d2b8c..363708ee14 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/SchedulerTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/SchedulerTest.java @@ -18,6 +18,7 @@ import static com.github.benmanes.caffeine.testing.Awaits.await; import static com.github.benmanes.caffeine.testing.ConcurrentTestHarness.executor; import static com.github.benmanes.caffeine.testing.ConcurrentTestHarness.scheduledExecutor; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.google.common.truth.Truth.assertThat; import static com.google.common.util.concurrent.testing.TestingExecutors.sameThreadScheduledExecutor; import static org.hamcrest.Matchers.is; @@ -48,7 +49,6 @@ import org.testng.annotations.Test; import com.github.valfirst.slf4jtest.TestLoggerFactory; -import com.google.common.collect.Iterables; import com.google.common.testing.NullPointerTester; import com.google.common.util.concurrent.Futures; @@ -80,11 +80,12 @@ public void scheduler_exception(Scheduler scheduler) { await().untilAtomic(thread, is(not(nullValue()))); if (thread.get() == Thread.currentThread()) { - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()) - .isEqualTo("Exception thrown when submitting scheduled task"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown when submitting scheduled task") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } } @@ -152,12 +153,12 @@ public void guardedScheduler_exception() { var future = Scheduler.guardedScheduler((r, e, d, u) -> { throw new IllegalStateException(); }) .schedule(Runnable::run, () -> {}, 1, TimeUnit.MINUTES); assertThat(future).isSameInstanceAs(DisabledFuture.INSTANCE); - - var event = Iterables.getOnlyElement(TestLoggerFactory.getLoggingEvents()); - assertThat(event.getFormattedMessage()) - .isEqualTo("Exception thrown by scheduler; discarded task"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(IllegalStateException.class); - assertThat(event.getLevel()).isEqualTo(WARN); + assertThat(logEvents() + .withMessage("Exception thrown by scheduler; discarded task") + .withThrowable(IllegalStateException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(1); } /* --------------- ScheduledExecutorService --------------- */ diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/stats/StatsCounterTest.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/stats/StatsCounterTest.java index 27d7ca2138..5cd32524d5 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/stats/StatsCounterTest.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/stats/StatsCounterTest.java @@ -15,6 +15,7 @@ */ package com.github.benmanes.caffeine.cache.stats; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.google.common.truth.Truth.assertThat; import static org.mockito.ArgumentMatchers.any; import static org.mockito.ArgumentMatchers.anyInt; @@ -99,9 +100,9 @@ public void guarded() { counter.recordLoadFailure(1); var expected = CacheStats.of(1, 1, 1, 1, 2, 1, 10); assertThat(counter.snapshot()).isEqualTo(expected); - assertThat(TestLoggerFactory.getLoggingEvents()).isEmpty(); assertThat(counter.toString()).isEqualTo(expected.toString()); assertThat(counter.snapshot().toString()).isEqualTo(expected.toString()); + assertThat(logEvents()).isEmpty(); } @Test @@ -134,13 +135,12 @@ public void guarded_exception() { verify(statsCounter).recordLoadFailure(1); verify(statsCounter).recordEviction(10, RemovalCause.SIZE); - var events = TestLoggerFactory.getLoggingEvents(); - assertThat(events).hasSize(6); - for (var event : events) { - assertThat(event.getLevel()).isEqualTo(WARN); - assertThat(event.getFormattedMessage()).isEqualTo("Exception thrown by stats counter"); - assertThat(event.getThrowable().orElseThrow()).isInstanceOf(NullPointerException.class); - } + assertThat(logEvents() + .withMessage("Exception thrown by stats counter") + .withThrowable(NullPointerException.class) + .withLevel(WARN) + .exclusively()) + .hasSize(6); } @Test diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/testing/CacheValidationListener.java b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/testing/CacheValidationListener.java index f98f813116..99e8eae9ba 100644 --- a/caffeine/src/test/java/com/github/benmanes/caffeine/cache/testing/CacheValidationListener.java +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/cache/testing/CacheValidationListener.java @@ -19,7 +19,7 @@ import static com.github.benmanes.caffeine.cache.testing.CacheContextSubject.assertThat; import static com.github.benmanes.caffeine.cache.testing.CacheSubject.assertThat; import static com.github.benmanes.caffeine.testing.Awaits.await; -import static com.google.common.collect.ImmutableList.toImmutableList; +import static com.github.benmanes.caffeine.testing.LoggingEvents.logEvents; import static com.google.common.truth.Truth.assertThat; import static com.google.common.truth.Truth.assertWithMessage; import static org.testng.ITestResult.FAILURE; @@ -234,10 +234,9 @@ private static void checkLogger(ITestResult testResult) { .orElseGet(() -> testResult.getTestClass() .getRealClass().getAnnotation(CheckMaxLogLevel.class)); if (checkMaxLogLevel != null) { - var events = TestLoggerFactory.getLoggingEvents().stream() - .filter(event -> event.getLevel().toInt() > checkMaxLogLevel.value().toInt()) - .collect(toImmutableList()); - assertWithMessage("maxLevel=%s", checkMaxLogLevel.value()).that(events).isEmpty(); + assertWithMessage("maxLevel=%s", checkMaxLogLevel.value()).that(logEvents() + .filter(event -> event.getLevel().toInt() > checkMaxLogLevel.value().toInt())) + .isEmpty(); } } diff --git a/caffeine/src/test/java/com/github/benmanes/caffeine/testing/LoggingEvents.java b/caffeine/src/test/java/com/github/benmanes/caffeine/testing/LoggingEvents.java new file mode 100644 index 0000000000..1f1be4976f --- /dev/null +++ b/caffeine/src/test/java/com/github/benmanes/caffeine/testing/LoggingEvents.java @@ -0,0 +1,142 @@ +/* + * Copyright 2024 Ben Manes. All Rights Reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package com.github.benmanes.caffeine.testing; + +import static com.google.common.base.Preconditions.checkState; +import static com.google.common.collect.ImmutableList.toImmutableList; +import static com.google.common.truth.Truth.assertThat; +import static java.util.Objects.requireNonNull; + +import java.util.ArrayList; +import java.util.List; +import java.util.Objects; +import java.util.function.Predicate; + +import org.slf4j.event.Level; + +import com.github.valfirst.slf4jtest.LoggingEvent; +import com.github.valfirst.slf4jtest.TestLoggerFactory; +import com.google.common.collect.ForwardingList; +import com.google.common.collect.ImmutableList; +import com.google.errorprone.annotations.CanIgnoreReturnValue; + +/** + * A fluent, immutable collection of logging events. + * + * @author ben.manes@gmail.com (Ben Manes) + */ +public final class LoggingEvents extends ForwardingList { + private final List> predicates; + private final List events; + + private ImmutableList filteredEvents; + private boolean exclusive; + + private LoggingEvents(List events) { + this.events = requireNonNull(events); + this.predicates = new ArrayList<>(); + } + + /** Returns the logging events. */ + public static LoggingEvents logEvents() { + return new LoggingEvents(TestLoggerFactory.getLoggingEvents()); + } + + /** Returns the events with the message. */ + @CanIgnoreReturnValue + public LoggingEvents withMessage(String formattedMessage) { + return filter(e -> Objects.equals(e.getFormattedMessage(), formattedMessage)); + } + + /** Returns the events with the message. */ + @CanIgnoreReturnValue + public LoggingEvents withMessage(Predicate predicate) { + return filter(e -> predicate.test(e.getFormattedMessage())); + } + + /** Returns the events without a throwable. */ + @CanIgnoreReturnValue + public LoggingEvents withoutThrowable() { + return filter(e -> e.getThrowable().isEmpty()); + } + + /** Returns the events with the same throwable. */ + @CanIgnoreReturnValue + public LoggingEvents withThrowable(Throwable t) { + return filter(e -> e.getThrowable().orElse(null) == t); + } + + /** Returns the events with the throwable class. */ + @CanIgnoreReturnValue + public LoggingEvents withThrowable(Class clazz) { + return filter(e -> clazz.isInstance(e.getThrowable().orElse(null))); + } + + /** Returns the events with a throwable whose cause is the same. */ + @CanIgnoreReturnValue + public LoggingEvents withUnderlyingCause(Throwable t) { + return filter(e -> e.getThrowable().filter(error -> error.getCause() == t).isPresent()); + } + + /** Returns the events with a throwable whose cause is an instance of the class. */ + @CanIgnoreReturnValue + public LoggingEvents withUnderlyingCause(Class clazz) { + return filter(e -> clazz.isInstance(e.getThrowable().map(Throwable::getCause).orElse(null))); + } + + /** Returns the events with the log level. */ + @CanIgnoreReturnValue + public LoggingEvents withLevel(Level level) { + return filter(e -> e.getLevel() == level); + } + + /** Returns the events that satisfy the predicate. */ + @CanIgnoreReturnValue + public LoggingEvents filter(Predicate predicate) { + predicates.add(requireNonNull(predicate)); + checkState(filteredEvents == null); + return this; + } + + /** Returns the events and fails at evaluation time if any would be filtered out. */ + @CanIgnoreReturnValue + public LoggingEvents exclusively() { + checkState(filteredEvents == null); + exclusive = true; + return this; + } + + @Override + protected ImmutableList delegate() { + if (filteredEvents == null) { + filteredEvents = applyFilters(); + } + return filteredEvents; + } + + /** Returns the events that match the predicates. */ + private ImmutableList applyFilters() { + var stream = events.stream(); + for (var predicate : predicates) { + stream = stream.filter(predicate); + } + var results = stream.collect(toImmutableList()); + if (exclusive) { + assertThat(results).hasSize(events.size()); + } + return results; + } +}