From 81e313b02e68ce50aec4627d4312e315aa736175 Mon Sep 17 00:00:00 2001 From: michaelabuckley Date: Mon, 19 Dec 2022 09:47:51 -0500 Subject: [PATCH] Log capture test helper cleanup (#4378) * Only log PHI at debug or lower, even in tests. * Log capture test helper cleanup --- .../fhir/jpa/auth/FhirQueryRuleImplTest.java | 10 +- .../uhn/test/concurrency/PointcutLatch.java | 2 +- .../util/LogbackCaptureTestExtension.java | 105 +++++++++++++++--- 3 files changed, 96 insertions(+), 21 deletions(-) diff --git a/hapi-fhir-jpaserver-test-utilities/src/test/java/ca/uhn/fhir/jpa/auth/FhirQueryRuleImplTest.java b/hapi-fhir-jpaserver-test-utilities/src/test/java/ca/uhn/fhir/jpa/auth/FhirQueryRuleImplTest.java index 99679f2713b..a1ba8859a87 100644 --- a/hapi-fhir-jpaserver-test-utilities/src/test/java/ca/uhn/fhir/jpa/auth/FhirQueryRuleImplTest.java +++ b/hapi-fhir-jpaserver-test-utilities/src/test/java/ca/uhn/fhir/jpa/auth/FhirQueryRuleImplTest.java @@ -32,13 +32,15 @@ import java.util.HashSet; import static ca.uhn.fhir.rest.server.interceptor.auth.IAuthorizationSearchParamMatcher.MatchResult.buildMatched; import static ca.uhn.fhir.rest.server.interceptor.auth.IAuthorizationSearchParamMatcher.MatchResult.buildUnmatched; import static ca.uhn.fhir.rest.server.interceptor.auth.IAuthorizationSearchParamMatcher.MatchResult.buildUnsupported; +import static ca.uhn.test.util.LogbackCaptureTestExtension.eventWithLevelAndMessageContains; import static org.hamcrest.MatcherAssert.assertThat; import static org.hamcrest.Matchers.equalTo; +import static org.hamcrest.Matchers.hasItem; import static org.hamcrest.Matchers.notNullValue; import static org.hamcrest.Matchers.nullValue; import static org.mockito.Mockito.when; -// wipjv where should this test live? - It can't live in hapi-fhir-server since we need a real FhirContext for the compartment checks. +// TODO: Is there a better home for this test? It can't live in hapi-fhir-server since we need a real FhirContext for the compartment checks. @MockitoSettings class FhirQueryRuleImplTest implements ITestDataBuilder { @@ -279,7 +281,7 @@ class FhirQueryRuleImplTest implements ITestDataBuilder { // then assertThat(verdict, nullValue()); MatcherAssert.assertThat(myLogCapture.getLogEvents(), - Matchers.hasItem(myLogCapture.eventWithLevelAndMessageContains(Level.WARN, "unsupported chain XXX"))); + hasItem(eventWithLevelAndMessageContains(Level.WARN, "unsupported chain XXX"))); } @Test @@ -295,7 +297,7 @@ class FhirQueryRuleImplTest implements ITestDataBuilder { // then assertThat(verdict.getDecision(), equalTo(PolicyEnum.DENY)); MatcherAssert.assertThat(myLogCapture.getLogEvents(), - Matchers.hasItem(myLogCapture.eventWithLevelAndMessageContains(Level.WARN, "unsupported chain XXX"))); + hasItem(eventWithLevelAndMessageContains(Level.WARN, "unsupported chain XXX"))); } /** @@ -315,7 +317,7 @@ class FhirQueryRuleImplTest implements ITestDataBuilder { // then assertThat(verdict, nullValue()); MatcherAssert.assertThat(myLogCapture.getLogEvents(), - Matchers.hasItem(myLogCapture.eventWithLevelAndMessageContains(Level.WARN, "No matcher provided"))); + hasItem(eventWithLevelAndMessageContains(Level.WARN, "No matcher provided"))); } } diff --git a/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/concurrency/PointcutLatch.java b/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/concurrency/PointcutLatch.java index 0b6d2eb8c51..85736e5f545 100644 --- a/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/concurrency/PointcutLatch.java +++ b/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/concurrency/PointcutLatch.java @@ -208,7 +208,7 @@ public class PointcutLatch implements IAnonymousInterceptor, IPointcutLatch { if (myCalledWith.get() != null) { myCalledWith.get().add(theArgs); } - ourLog.info("Called {} {} with {}", myName, latch, hookParamsToString(theArgs)); + ourLog.debug("Called {} {} with {}", myName, latch, hookParamsToString(theArgs)); latch.countDown(); } diff --git a/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/util/LogbackCaptureTestExtension.java b/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/util/LogbackCaptureTestExtension.java index 8cacf2079d1..7c527e12a61 100644 --- a/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/util/LogbackCaptureTestExtension.java +++ b/hapi-fhir-test-utilities/src/main/java/ca/uhn/test/util/LogbackCaptureTestExtension.java @@ -31,6 +31,13 @@ import org.junit.jupiter.api.extension.BeforeEachCallback; import org.junit.jupiter.api.extension.ExtensionContext; import org.slf4j.LoggerFactory; +import javax.annotation.Nonnull; +import javax.annotation.Nullable; +import java.util.ArrayList; +import java.util.List; +import java.util.function.Predicate; +import java.util.stream.Collectors; + /** * Test helper to collect logback lines. * @@ -38,13 +45,21 @@ import org.slf4j.LoggerFactory; */ public class LogbackCaptureTestExtension implements BeforeEachCallback, AfterEachCallback { private final Logger myLogger; - private final ListAppender myListAppender = new ListAppender<>(); + private ListAppender myListAppender = null; /** - * @param theLoggerName the log name root to capture + * + * @param theLogger the log to capture + */ + public LogbackCaptureTestExtension(Logger theLogger) { + myLogger = theLogger; + } + + /** + * @param theLoggerName the log name to capture */ public LogbackCaptureTestExtension(String theLoggerName) { - myLogger = (Logger) LoggerFactory.getLogger(theLoggerName); + this((Logger) LoggerFactory.getLogger(theLoggerName)); } /** @@ -55,17 +70,27 @@ public class LogbackCaptureTestExtension implements BeforeEachCallback, AfterEac } /** - * Direct reference to the list of events. - * You may clear() it, or whatever. - * @return the modifiable List of events captured so far. + * Returns a copy to avoid concurrent modification errors. + * @return A copy of the log events so far. */ public java.util.List getLogEvents() { - return myListAppender.list; + // copy to avoid concurrent mod errors + return new ArrayList<>(myListAppender.list); + } + + /** Clear accumulated log events. */ + public void clearEvents() { + myListAppender.list.clear(); + } + + public ListAppender getAppender() { + return myListAppender; } @Override public void beforeEach(ExtensionContext context) throws Exception { - myListAppender.start(); // SecurityContextHolder.getContext().setAuthentication(authResult); + myListAppender = new ListAppender<>(); + myListAppender.start(); myLogger.addAppender(myListAppender); } @@ -73,26 +98,74 @@ public class LogbackCaptureTestExtension implements BeforeEachCallback, AfterEac @Override public void afterEach(ExtensionContext context) throws Exception { myLogger.detachAppender(myListAppender); + myListAppender.stop(); } - public Matcher eventWithLevelAndMessageContains(Level theLevel, String thePartialMessage) { - return new LogbackEventMatcher("log event", theLevel, thePartialMessage); + + public List filterLoggingEventsWithMessageEqualTo(String theMessageText){ + return filterLoggingEventsWithPredicate(loggingEvent -> loggingEvent.getFormattedMessage().equals(theMessageText)); } + + public List filterLoggingEventsWithMessageContaining(String theMessageText){ + return filterLoggingEventsWithPredicate(loggingEvent -> loggingEvent.getFormattedMessage().contains(theMessageText)); + } + + public List filterLoggingEventsWithPredicate(Predicate theLoggingEventPredicate){ + return getLogEvents() + .stream() + .filter(theLoggingEventPredicate) + .collect(Collectors.toList()); + } + + // Hamcrest matcher support + public static Matcher eventWithLevelAndMessageContains(@Nonnull Level theLevel, @Nonnull String thePartialMessage) { + return new LogbackEventMatcher(theLevel, thePartialMessage); + } + + public static Matcher eventWithLevel(@Nonnull Level theLevel) { + return new LogbackEventMatcher(theLevel, null); + } + + public static Matcher eventWithMessageContains(@Nonnull String thePartialMessage) { + return new LogbackEventMatcher(null, thePartialMessage); + } + + /** + * A Hamcrest matcher for junit assertions. + * Matches on level and/or partial message. + */ public static class LogbackEventMatcher extends CustomTypeSafeMatcher { + @Nullable + private final Level myLevel; + @Nullable + private final String myString; - private Level myLevel; - private String myString; + public LogbackEventMatcher(@Nullable Level theLevel, @Nullable String thePartialString) { + this("log event", theLevel, thePartialString); + } - public LogbackEventMatcher(String description, Level theLevel, String theString) { - super(description); + public LogbackEventMatcher(String description, @Nullable Level theLevel, @Nullable String thePartialString) { + super(makeDescription(description, theLevel, thePartialString)); myLevel = theLevel; - myString = theString; + myString = thePartialString; + } + @Nonnull + private static String makeDescription(String description, Level theLevel, String thePartialString) { + String msg = description; + if (theLevel != null) { + msg = msg + " with level at least " + theLevel; + } + if (thePartialString != null) { + msg = msg + " containing string \"" + thePartialString + "\""; + + } + return msg; } @Override protected boolean matchesSafely(ILoggingEvent item) { return (myLevel == null || item.getLevel().isGreaterOrEqual(myLevel)) && - item.getFormattedMessage().contains(myString); + (myString == null || item.getFormattedMessage().contains(myString)); } } }