Update dropwizard3 to use logback13, correct logback13 issues

dropwizard3/build.gradle.kts

@@ -26,15 +26,15 @@ dependencies {
     implementation("jakarta.servlet:jakarta.servlet-api:4.0.4")
 
     implementation("com.newrelic.agent.java:newrelic-api:9.1.0")
-    includeInJar(project(":logback")) {
+    includeInJar(project(":logback13")) {
         isTransitive = false
     }
 
     testImplementation("org.junit.jupiter:junit-jupiter:5.6.2")
     testImplementation("org.mockito:mockito-core:3.4.4")
     testImplementation("org.mockito:mockito-junit-jupiter:3.4.4")
     testImplementation("org.hamcrest:hamcrest:2.2")
-    testImplementation(project(":logback"))
+    testImplementation(project(":logback13"))
     testImplementation(project(":core-test"))
 }
 

dropwizard3/src/main/java/com/newrelic/logging/dropwizard3/NewRelicAsyncAppenderFactory.java

@@ -7,7 +7,7 @@
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.AsyncAppenderBase;
 import com.fasterxml.jackson.annotation.JsonTypeName;
-import com.newrelic.logging.logback.NewRelicAsyncAppender;
+import com.newrelic.logging.logback13.NewRelicAsyncAppender;
 import io.dropwizard.logging.common.async.AsyncLoggingEventAppenderFactory;
 
 @JsonTypeName("newrelic")

dropwizard3/src/main/java/com/newrelic/logging/dropwizard3/NewRelicJsonLayoutFactory.java

@@ -8,7 +8,7 @@
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.LayoutBase;
 import com.fasterxml.jackson.annotation.JsonTypeName;
-import com.newrelic.logging.logback.NewRelicJsonLayout;
+import com.newrelic.logging.logback13.NewRelicJsonLayout;
 import io.dropwizard.logging.common.layout.DiscoverableLayoutFactory;
 
 import java.util.TimeZone;

dropwizard3/src/test/java/com/newrelic/logging/dropwizard3/NewRelicAppenderFactoryTest.java

@@ -19,7 +19,7 @@
 import com.google.common.collect.ImmutableMap;
 import com.newrelic.api.agent.Agent;
 import com.newrelic.logging.core.LogAsserts;
-import com.newrelic.logging.logback.NewRelicAsyncAppender;
+import com.newrelic.logging.logback13.NewRelicAsyncAppender;
 import io.dropwizard.logging.common.AbstractOutputStreamAppenderFactory;
 import io.dropwizard.logging.common.async.AsyncLoggingEventAppenderFactory;
 import io.dropwizard.logging.common.filter.NullLevelFilterFactory;
@@ -32,6 +32,7 @@
 import org.junit.jupiter.api.Timeout;
 import org.junit.jupiter.api.io.TempDir;
 import org.mockito.Mockito;
+import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
 
 import java.io.BufferedReader;
@@ -52,6 +53,7 @@ class NewRelicAppenderFactoryTest {
     @SuppressWarnings("WeakerAccess")
     @TempDir
     Path tempDir;
+    private LoggerContext context;
     private AsyncAppender appender;
     private LoggingEvent event;
     private AbstractOutputStreamAppenderFactory<ILoggingEvent> appenderFactory;
@@ -206,6 +208,7 @@ private void givenALoggingEvent() {
         event = new LoggingEvent();
         event.setMessage("test_error_message");
         event.setLevel(Level.ERROR);
+        event.setLoggerContext(context);
     }
 
     private void givenALoggingEventWithMDCEnabled() {
@@ -238,8 +241,6 @@ private void givenALoggingEventWithCallerData() {
     }
 
     private void givenARedirectedAppender() {
-        LoggerContext context = new LoggerContext();
-
         Appender<ILoggingEvent> baseAppender = appenderFactory.build(
                 context,
                 "app name",
@@ -311,6 +312,10 @@ void setUp() throws Exception {
         outputStream = new PipedOutputStream();
         PipedInputStream inputStream = new PipedInputStream(outputStream);
         bufferedReader = new BufferedReader(new InputStreamReader(inputStream, StandardCharsets.UTF_8));
+
+        //Set up a new logger context
+        context = (LoggerContext) LoggerFactory.getILoggerFactory();
+        context.reset();
     }
 
     @AfterEach

logback13/src/main/java/com/newrelic/logging/logback13/NewRelicJsonLayout.java

@@ -17,6 +17,7 @@
 import com.fasterxml.jackson.core.JsonGenerator;
 import com.newrelic.logging.core.ElementName;
 import com.fasterxml.jackson.core.JsonFactory;
+import com.newrelic.logging.core.LogExtensionConfig;
 import org.slf4j.MDC;
 import org.slf4j.Marker;
 import org.slf4j.helpers.NOPMDCAdapter;
@@ -26,6 +27,8 @@
 import java.util.List;
 import java.util.Map;
 
+import static com.newrelic.logging.logback13.NewRelicAsyncAppender.NEW_RELIC_PREFIX;
+
 /**
  * A custom layout that formats {@link ILoggingEvent} log events as JSON objects.
  * Adds standard log fields and enriches logs with linking metadata.
@@ -74,12 +77,18 @@ private void writeToGenerator(ILoggingEvent eventObject, JsonGenerator generator
             String value;
 
             for (Map.Entry<String, String> entry : mdcPropertyMap.entrySet()) {
-                if (entry.getValue() == null) {
+                if (entry.getValue() == null || entry.getValue().isEmpty()) {
                     continue;
                 }
                 key = entry.getKey();
                 value = entry.getValue();
-                generator.writeStringField(key, value);
+                //Before writing to the generator, strip the temporary NR prefix.
+                //Suppress user-defined context keys unless configured to send mdc values.
+                if (key.startsWith(NEW_RELIC_PREFIX)) {
+                    generator.writeStringField(key.substring(NEW_RELIC_PREFIX.length()), value);
+                } else if (LogExtensionConfig.shouldAddMDC()) {
+                    generator.writeStringField(key, value);
+                }
             }
         }
 

logback13/src/test/java/com/newrelic/logging/logback13/NewRelicLogback13Tests.java

@@ -10,9 +10,13 @@
 import ch.qos.logback.classic.LoggerContext;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.core.OutputStreamAppender;
+import com.google.common.collect.ImmutableMap;
+import com.newrelic.api.agent.Agent;
+import com.newrelic.logging.core.LogAsserts;
 import org.junit.jupiter.api.AfterEach;
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
+import org.mockito.Mockito;
 import org.slf4j.LoggerFactory;
 import org.slf4j.MDC;
 import org.slf4j.Marker;
@@ -83,17 +87,24 @@ void shouldWrapJsonConsoleAppenderCorrectly() throws InterruptedException, IOExc
     }
 
     @Test
-    void shouldAllWorkCorrectlyWithoutMDC() throws InterruptedException {
+    void shouldAllWorkCorrectlyWithoutMDC() throws Exception {
+        //pump the agent data in - it should still be present in the wrapped event even if MDC is not used by the caller.
+        givenMockAgentData();
+
         logger.info("Very interesting test message, no MDC");
         Thread.sleep(100);
         String output = getLogOutput();
 
+        //the log message itself should be there...
         assertTrue(output.contains("Very interesting test message, no MDC"));
         assertFalse(output.contains(CONTEXT_PREFIX));
+        //...and so should the agent metadata.
+        assertOutputContainsAgentData(output);
     }
 
     @Test
-    void shouldAppendCallerDataToJsonCorrectly() throws InterruptedException {
+    void shouldAppendCallerDataToJsonCorrectly() throws Exception {
+        givenMockAgentData();
         appender.setIncludeCallerData(true);
         logger.info("Test message with Caller Data");
 
@@ -104,10 +115,13 @@ void shouldAppendCallerDataToJsonCorrectly() throws InterruptedException {
         assertTrue(output.contains("method.name"));
         assertTrue(output.contains("line.number"));
         assertTrue(output.contains("Test message with Caller Data"));
+        assertOutputContainsAgentData(output);
     }
 
     @Test
-    void shouldAppendMDCArgsToJsonWhenEnabled() throws InterruptedException {
+    void shouldAppendMDCArgsToJsonWhenEnabled() throws Exception {
+        System.setProperty("newrelic.log_extension.add_mdc", "true");
+        givenMockAgentData();
         MDC.put("userId", "user-123");
         MDC.put("sessionId", "session-456");
 
@@ -118,11 +132,13 @@ void shouldAppendMDCArgsToJsonWhenEnabled() throws InterruptedException {
         assertTrue(output.contains("\"context.userId\":\"user-123\""));
         assertTrue(output.contains("\"context.sessionId\":\"session-456\""));
         assertTrue(output.contains("Logging with MDC enabled"));
+        assertOutputContainsAgentData(output);
     }
 
     @Test
-    void shouldNotAppendMDCArgsToJsonWhenMDCIsDisabled() throws InterruptedException {
-        NewRelicAsyncAppender.isNoOpMDC = true;
+    void shouldNotAppendMDCArgsToJsonWhenMDCIsDisabled() throws Exception {
+        System.setProperty("newrelic.log_extension.add_mdc", "false");
+        givenMockAgentData();
         MDC.put("userId", "user-123");
         MDC.clear();
 
@@ -132,7 +148,7 @@ void shouldNotAppendMDCArgsToJsonWhenMDCIsDisabled() throws InterruptedException
 
         assertTrue(output.contains("Logging with MDC disabled"));
         assertFalse(output.contains("\"context.userId\":\"user-123\""));
-        assertFalse(output.contains("NewRelic:"));
+        assertOutputContainsAgentData(output);
     }
 
     @Test
@@ -231,7 +247,19 @@ void shouldLogDifferentLevelsCorrectly() throws InterruptedException {
     }
 
     private String getLogOutput() {
-        return outputStream.toString().trim();
+        return outputStream.toString().trim() + "\n";
+    }
+
+    private void givenMockAgentData() {
+        Agent mockAgent = Mockito.mock(Agent.class);
+        Mockito.when(mockAgent.getLinkingMetadata()).thenReturn(ImmutableMap.of("some.key", "some.value", "other.key", "other.value"));
+        NewRelicAsyncAppender.agentSupplier = () -> mockAgent;
     }
 
+    private void assertOutputContainsAgentData(String output) throws IOException{
+        LogAsserts.assertFieldValues(output, ImmutableMap.of(
+                "some.key", "some.value",
+                "other.key", "other.value"
+        ));
+    }
 }