Log capture test helper cleanup (#4378)

* Only log PHI at debug or lower, even in tests.
* Log capture test helper cleanup

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")));
 		}
 
 	}

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();
 	}

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<ILoggingEvent> myListAppender = new ListAppender<>();
+	private ListAppender<ILoggingEvent> 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.
+	 * Returns a copy to avoid concurrent modification errors.
-	 * You may clear() it, or whatever.
+	 * @return A copy of the log events so far.
-	 * @return the modifiable List of events captured so far.
 	 */
 	public java.util.List<ILoggingEvent> 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<ILoggingEvent> 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<ILoggingEvent> eventWithLevelAndMessageContains(Level theLevel, String thePartialMessage) {
+
-		return new LogbackEventMatcher("log event", theLevel, thePartialMessage);
+	public List<ILoggingEvent> filterLoggingEventsWithMessageEqualTo(String theMessageText){
+		return filterLoggingEventsWithPredicate(loggingEvent -> loggingEvent.getFormattedMessage().equals(theMessageText));
 	}
+
+	public List<ILoggingEvent> filterLoggingEventsWithMessageContaining(String theMessageText){
+		return filterLoggingEventsWithPredicate(loggingEvent -> loggingEvent.getFormattedMessage().contains(theMessageText));
+	}
+
+	public List<ILoggingEvent> filterLoggingEventsWithPredicate(Predicate<ILoggingEvent> theLoggingEventPredicate){
+		return getLogEvents()
+			.stream()
+			.filter(theLoggingEventPredicate)
+			.collect(Collectors.toList());
+	}
+
+	//  Hamcrest matcher support
+	public static Matcher<ILoggingEvent> eventWithLevelAndMessageContains(@Nonnull Level theLevel, @Nonnull String thePartialMessage) {
+		return new LogbackEventMatcher(theLevel, thePartialMessage);
+	}
+
+	public static Matcher<ILoggingEvent> eventWithLevel(@Nonnull Level theLevel) {
+		return new LogbackEventMatcher(theLevel, null);
+	}
+
+	public static Matcher<ILoggingEvent> 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<ILoggingEvent> {
+		@Nullable
+		private final Level myLevel;
+		@Nullable
+		private final String myString;
 
-		private Level myLevel;
+		public LogbackEventMatcher(@Nullable Level theLevel, @Nullable String thePartialString) {
-		private String myString;
+			this("log event", theLevel, thePartialString);
+		}
 
-		public LogbackEventMatcher(String description, Level theLevel, String theString) {
+		public LogbackEventMatcher(String description, @Nullable Level theLevel, @Nullable String thePartialString) {
-			super(description);
+			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));
 		}
 	}
 }