Add tap filter (#96)

* Add tap filter

* Reformat

* spotlessApply

* Fix tests

logback-turbomarker/src/main/java/com/tersesystems/logback/turbomarker/FormatParamsDecider.java → logback-classic/src/main/java/com/tersesystems/logback/classic/FormatParamsDecider.java

@@ -8,7 +8,7 @@
  *
  *     http://creativecommons.org/publicdomain/zero/1.0/
  */
-package com.tersesystems.logback.turbomarker;
+package com.tersesystems.logback.classic;
 
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;

logback-turbomarker/src/main/java/com/tersesystems/logback/turbomarker/LoggerDecider.java → logback-classic/src/main/java/com/tersesystems/logback/classic/LoggerDecider.java

@@ -8,7 +8,7 @@
  *
  *     http://creativecommons.org/publicdomain/zero/1.0/
  */
-package com.tersesystems.logback.turbomarker;
+package com.tersesystems.logback.classic;
 
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.core.spi.FilterReply;

logback-turbomarker/src/main/java/com/tersesystems/logback/turbomarker/MarkerLoggerDecider.java → logback-classic/src/main/java/com/tersesystems/logback/classic/MarkerLoggerDecider.java

@@ -8,7 +8,7 @@
  *
  *     http://creativecommons.org/publicdomain/zero/1.0/
  */
-package com.tersesystems.logback.turbomarker;
+package com.tersesystems.logback.classic;
 
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.core.spi.FilterReply;

logback-classic/src/main/java/com/tersesystems/logback/classic/TapFilter.java

@@ -0,0 +1,108 @@
+package com.tersesystems.logback.classic;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.classic.spi.TurboFilterList;
+import ch.qos.logback.classic.turbo.TurboFilter;
+import ch.qos.logback.core.spi.AppenderAttachableImpl;
+import ch.qos.logback.core.spi.FilterReply;
+import com.tersesystems.logback.core.DefaultAppenderAttachable;
+import org.slf4j.Marker;
+
+/**
+ * A tap filter is used to tap some amount of incoming process and pass them to a specially
+ * configured appender even if they do not qualify as a logging event under normal circumstances.
+ * This is a <a
+ * href="https://www.enterpriseintegrationpatterns.com/patterns/messaging/WireTap.html">wiretap</a>
+ * pattern from Enterprise Integration Patterns.
+ *
+ * <p>It completely bypasses any kind of logging level configured on the front end, so you can set a
+ * logger to INFO level but still have access to all TRACE events when an error occurs, through the
+ * tap filter's appenders.
+ *
+ * <p>NOTE: This means that isLoggingTrace etc always returns true.
+ */
+public class TapFilter extends TurboFilter
+    implements DefaultAppenderAttachable<ILoggingEvent>, TurboFilterDecider {
+
+  private final AppenderAttachableImpl<ILoggingEvent> aae = new AppenderAttachableImpl<>();
+
+  private ILoggingEventFactory<ILoggingEvent> loggingEventFactory;
+
+  private TurboFilterList evaluatorList = new TurboFilterList();
+
+  public void addTurboFilter(TurboFilter turboFilter) {
+    evaluatorList.add(turboFilter);
+  }
+
+  public TurboFilterList getTurboFilters() {
+    return evaluatorList;
+  }
+
+  public void getTurboFilters(TurboFilterList tapEvaluator) {
+    this.evaluatorList = tapEvaluator;
+  }
+
+  @Override
+  public AppenderAttachableImpl<ILoggingEvent> appenderAttachableImpl() {
+    return aae;
+  }
+
+  public ILoggingEventFactory<ILoggingEvent> getLoggingEventFactory() {
+    return loggingEventFactory;
+  }
+
+  public void setLoggingEventFactory(ILoggingEventFactory<ILoggingEvent> loggingEventFactory) {
+    this.loggingEventFactory = loggingEventFactory;
+  }
+
+  @Override
+  public void start() {
+    if (this.loggingEventFactory == null) {
+      this.loggingEventFactory = new LoggingEventFactory();
+    }
+
+    if (evaluatorList.isEmpty()) {
+      TurboFilter acceptAllTurboFilter =
+          new TurboFilter() {
+            @Override
+            public FilterReply decide(
+                Marker marker,
+                Logger logger,
+                Level level,
+                String format,
+                Object[] params,
+                Throwable t) {
+              return FilterReply.ACCEPT;
+            }
+          };
+      evaluatorList.add(acceptAllTurboFilter);
+    }
+
+    super.start();
+  }
+
+  @Override
+  public FilterReply decide(
+      Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
+    // Called by isLoggingTrace() -- there's no actual message here.
+    if (logger != null && format == null && params == null) {
+      // Need to turn on events for everything so that we can cover conditional events.
+      return FilterReply.ACCEPT;
+    }
+
+    // Only tap if the internal filters pass.
+    FilterReply turboFilterChainDecision =
+        evaluatorList.getTurboFilterChainDecision(marker, logger, level, format, params, t);
+    if (turboFilterChainDecision.equals(FilterReply.ACCEPT)) {
+      ILoggingEvent loggingEvent =
+          loggingEventFactory.create(marker, logger, level, format, params, t);
+      // initialize the mdc in the logging event...
+      loggingEvent.prepareForDeferredProcessing();
+      // For every message that is acceptable, store it in the appender and return.
+      aae.appendLoopOnAppenders(loggingEvent);
+    }
+    return FilterReply.NEUTRAL;
+  }
+}

logback-turbomarker/src/main/java/com/tersesystems/logback/turbomarker/TurboFilterDecider.java → logback-classic/src/main/java/com/tersesystems/logback/classic/TurboFilterDecider.java

@@ -8,13 +8,21 @@
  *
  *     http://creativecommons.org/publicdomain/zero/1.0/
  */
-package com.tersesystems.logback.turbomarker;
+package com.tersesystems.logback.classic;
 
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.core.spi.FilterReply;
 import org.slf4j.Marker;
 
+/**
+ * An interface that decides what sort of filter reply there is.
+ *
+ * <p>Logback doesn't provide an interface for this out of the box for all turbofilters, so we have
+ * to add one in by hand when we want decisions without the whole turbo filter.
+ *
+ * <p>This comes in handy for turbomarkers and tap filters.
+ */
 public interface TurboFilterDecider {
   FilterReply decide(
       Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t);

logback-classic/src/test/java/com/tersesystems/logback/classic/CorrelationIdMarker.java

@@ -0,0 +1,26 @@
+package com.tersesystems.logback.classic;
+
+import org.slf4j.Marker;
+
+/** A very simple correlation id marker. */
+public interface CorrelationIdMarker extends Marker {
+  String getCorrelationId();
+
+  static CorrelationIdMarker create(String value) {
+    return new CorrelationIdBasicMarker(value);
+  }
+}
+
+/** Implementation of correlation id. */
+class CorrelationIdBasicMarker extends TerseBasicMarker implements CorrelationIdMarker {
+  private final String value;
+
+  public CorrelationIdBasicMarker(String value) {
+    super("TS_CORRELATION_ID");
+    this.value = value;
+  }
+
+  public String getCorrelationId() {
+    return value;
+  }
+}

logback-classic/src/test/java/com/tersesystems/logback/classic/CorrelationIdTurboFilter.java

@@ -0,0 +1,63 @@
+package com.tersesystems.logback.classic;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.turbo.TurboFilter;
+import ch.qos.logback.classic.util.LogbackMDCAdapter;
+import ch.qos.logback.core.spi.FilterReply;
+import com.tersesystems.logback.core.StreamUtils;
+import java.util.Collections;
+import java.util.Map;
+import java.util.stream.Stream;
+import org.slf4j.MDC;
+import org.slf4j.Marker;
+import org.slf4j.spi.MDCAdapter;
+
+/** Tells the tap filter to create an event and append it if a correlation id is found. */
+public class CorrelationIdTurboFilter extends TurboFilter {
+  private String mdcKey = "correlation_id";
+
+  public String getMdcKey() {
+    return mdcKey;
+  }
+
+  public void setMdcKey(String mdcKey) {
+    this.mdcKey = mdcKey;
+  }
+
+  @Override
+  public FilterReply decide(
+      Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
+    // If there's a correlation id marker somewhere in the hierarchy, then good.
+    Stream<Marker> markerStream = StreamUtils.fromMarker(marker);
+    if (markerStream.anyMatch(m -> m instanceof CorrelationIdMarker)) {
+      return FilterReply.ACCEPT;
+    }
+
+    // Look in MDC for a correlation id as well...
+    Map<String, String> mdcPropertyMap = getMDCPropertyMap();
+    String mdcKey = getMdcKey();
+    if (mdcKey != null) {
+      if (mdcPropertyMap.containsKey(mdcKey)) {
+        return FilterReply.ACCEPT;
+      }
+    }
+
+    // Otherwise no.
+    return FilterReply.DENY;
+  }
+
+  public Map<String, String> getMDCPropertyMap() {
+    MDCAdapter mdc = MDC.getMDCAdapter();
+
+    Map<String, String> mdcPropertyMap;
+    if (mdc instanceof LogbackMDCAdapter)
+      mdcPropertyMap = ((LogbackMDCAdapter) mdc).getPropertyMap();
+    else mdcPropertyMap = mdc.getCopyOfContextMap();
+
+    // mdcPropertyMap still null, use emptyMap()
+    if (mdcPropertyMap == null) mdcPropertyMap = Collections.emptyMap();
+
+    return mdcPropertyMap;
+  }
+}

logback-classic/src/test/java/com/tersesystems/logback/classic/TapFilterTest.java

@@ -0,0 +1,134 @@
+/*
+ * SPDX-License-Identifier: CC0-1.0
+ *
+ * Copyright 2018-2019 Will Sargent.
+ *
+ * Licensed under the CC0 Public Domain Dedication;
+ * You may obtain a copy of the License at
+ *
+ *     http://creativecommons.org/publicdomain/zero/1.0/
+ */
+package com.tersesystems.logback.classic;
+
+import static java.util.Objects.requireNonNull;
+import static org.assertj.core.api.Assertions.assertThat;
+
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.joran.JoranConfigurator;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.classic.spi.TurboFilterList;
+import ch.qos.logback.core.Appender;
+import ch.qos.logback.core.joran.spi.JoranException;
+import ch.qos.logback.core.read.ListAppender;
+import ch.qos.logback.core.spi.AppenderAttachable;
+import java.net.URL;
+import java.util.Optional;
+import org.junit.jupiter.api.Test;
+import org.slf4j.MDC;
+
+public class TapFilterTest {
+
+  @Test
+  public void testSimple() throws JoranException {
+    LoggerContext loggerFactory = createLoggerFactory("/logback-tapfilter.xml");
+
+    // Write something that never gets logged explicitly...
+    Logger debugLogger = loggerFactory.getLogger("com.example.Debug");
+    debugLogger.debug("debug one");
+    debugLogger.debug("debug two");
+    debugLogger.debug("debug three");
+    debugLogger.debug("debug four");
+
+    Logger logger = loggerFactory.getLogger("com.example.Test");
+    logger.error("Write out error message to console");
+
+    ListAppender<ILoggingEvent> listAppender = getListAppender(loggerFactory);
+    assertThat(listAppender.list.size()).isEqualTo(5);
+  }
+
+  @Test
+  public void testCorrelationWithNoMarker() throws JoranException {
+    LoggerContext loggerFactory = createLoggerFactory("/logback-tapfilter-correlation.xml");
+
+    // Because there's no correlation id, it should never make it past the filter here.
+    Logger debugLogger = loggerFactory.getLogger("com.example.Debug");
+    debugLogger.debug("debug one");
+    debugLogger.debug("debug two");
+    debugLogger.debug("debug three");
+    debugLogger.debug("debug four");
+
+    Logger logger = loggerFactory.getLogger("com.example.Test");
+    logger.error("Write out error message to console");
+
+    ListAppender<ILoggingEvent> listAppender = getListAppender(loggerFactory);
+    assertThat(listAppender.list.size()).isEqualTo(0);
+  }
+
+  @Test
+  public void testCorrelationWithMarker() throws JoranException {
+    LoggerContext loggerFactory = createLoggerFactory("/logback-tapfilter-correlation.xml");
+
+    CorrelationIdMarker correlationIdMarker = CorrelationIdMarker.create("12345");
+
+    // Because there's no correlation id, it should never make it past the filter here.
+    Logger debugLogger = loggerFactory.getLogger("com.example.Debug");
+    debugLogger.debug(correlationIdMarker, "debug one");
+    debugLogger.debug(correlationIdMarker, "debug two");
+    debugLogger.debug("debug three");
+    debugLogger.debug("debug four");
+
+    Logger logger = loggerFactory.getLogger("com.example.Test");
+    logger.error("Write out error message to console");
+
+    ListAppender<ILoggingEvent> listAppender = getListAppender(loggerFactory);
+    assertThat(listAppender.list.size()).isEqualTo(2);
+  }
+
+  @Test
+  public void testCorrelationWithMDC() throws JoranException {
+    LoggerContext loggerFactory = createLoggerFactory("/logback-tapfilter-correlation.xml");
+
+    MDC.put("correlationId", "12345");
+    CorrelationIdMarker correlationIdMarker = CorrelationIdMarker.create("12345");
+
+    // Because there's no correlation id, it should never make it past the filter here.
+    Logger debugLogger = loggerFactory.getLogger("com.example.Debug");
+    debugLogger.debug(correlationIdMarker, "debug one");
+    debugLogger.debug(correlationIdMarker, "debug two");
+    debugLogger.debug("debug three");
+    debugLogger.debug("debug four");
+
+    Logger logger = loggerFactory.getLogger("com.example.Test");
+    logger.error("Write out error message to console");
+
+    ListAppender<ILoggingEvent> listAppender = getListAppender(loggerFactory);
+    assertThat(listAppender.list.size()).isEqualTo(5);
+  }
+
+  LoggerContext createLoggerFactory(String resourceName) throws JoranException {
+    LoggerContext context = new LoggerContext();
+    URL resource = getClass().getResource(resourceName);
+    JoranConfigurator configurator = new JoranConfigurator();
+    configurator.setContext(context);
+    configurator.doConfigure(resource);
+    return context;
+  }
+
+  Optional<Appender<ILoggingEvent>> getFilterAppender(TurboFilterList turboFilterList) {
+    return turboFilterList.stream()
+        .filter(f -> f instanceof AppenderAttachable<?>)
+        .map(f -> ((AppenderAttachable<ILoggingEvent>) f).iteratorForAppenders().next())
+        .findFirst();
+  }
+
+  ListAppender<ILoggingEvent> getListAppender(LoggerContext context) {
+    Optional<Appender<ILoggingEvent>> maybeAppender =
+        getFilterAppender(context.getTurboFilterList());
+    if (maybeAppender.isPresent()) {
+      return (ListAppender<ILoggingEvent>) requireNonNull(maybeAppender.get());
+    } else {
+      throw new IllegalStateException("Cannot find appender");
+    }
+  }
+}