capture zenith logs on test failure

Author: rfresh2

src/test/java/com/zenith/ConnectIntegTest.java

@@ -3,18 +3,18 @@
 import com.zenith.util.Wait;
 import com.zenith.util.config.Config;
 import org.junit.jupiter.api.Test;
+import org.junit.jupiter.api.extension.ExtendWith;
 import org.testcontainers.containers.GenericContainer;
 import org.testcontainers.junit.jupiter.Container;
 import org.testcontainers.junit.jupiter.Testcontainers;
 import org.testcontainers.utility.DockerImageName;
 
-import java.nio.file.Files;
-import java.nio.file.Path;
 import java.time.Duration;
 
 import static org.junit.jupiter.api.Assertions.assertTrue;
 
 @Testcontainers(disabledWithoutDocker = true)
+@ExtendWith(TestLogCaptureJunitExtension.class)
 public class ConnectIntegTest {
 
     @Container
@@ -49,18 +49,6 @@ public void connectTest() {
 
         Proxy.getInstance().connectAndCatchExceptions();
 
-        assertTrue(Proxy.getInstance().isConnected(), () -> {
-            String zenithLog = "";
-            try {
-                zenithLog = Files.readString(Path.of("log/latest.log"));
-            } catch (Exception e) {
-                zenithLog = e.getMessage();
-            }
-            return "Failed to connect to local mc server: \n"
-                    + minecraftServer.getLogs()
-                    + "\n"
-                    + zenithLog;
-            }
-        );
+        assertTrue(Proxy.getInstance().isConnected(), "Failed to connect to local mc server");
     }
 }

src/test/java/com/zenith/TestLogCapture.java

@@ -0,0 +1,69 @@
+package com.zenith;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.classic.spi.ThrowableProxyUtil;
+
+import java.time.Instant;
+import java.time.ZoneOffset;
+import java.time.format.DateTimeFormatter;
+import java.util.concurrent.ConcurrentLinkedDeque;
+import java.util.concurrent.atomic.AtomicLong;
+
+public final class TestLogCapture {
+    private static final int MAX_ENTRIES = 20_000;
+    private static final DateTimeFormatter TS_FORMATTER = DateTimeFormatter.ISO_OFFSET_DATE_TIME.withZone(ZoneOffset.UTC);
+    private static final AtomicLong SEQUENCE = new AtomicLong();
+    private static final ConcurrentLinkedDeque<Entry> ENTRIES = new ConcurrentLinkedDeque<>();
+    private static final Object TRIM_LOCK = new Object();
+
+    private TestLogCapture() {}
+
+    public static long checkpoint() {
+        return SEQUENCE.get();
+    }
+
+    public static String dumpSince(final long checkpoint) {
+        var builder = new StringBuilder();
+        for (var entry : ENTRIES) {
+            if (entry.sequence <= checkpoint) continue;
+            builder.append(entry.text);
+        }
+        return builder.isEmpty() ? "<no Zenith logs captured>" : builder.toString();
+    }
+
+    static void append(final ILoggingEvent event) {
+        var sequence = SEQUENCE.incrementAndGet();
+        var text = format(event);
+        ENTRIES.addLast(new Entry(sequence, text));
+
+        if (ENTRIES.size() <= MAX_ENTRIES) return;
+        synchronized (TRIM_LOCK) {
+            while (ENTRIES.size() > MAX_ENTRIES) {
+                ENTRIES.pollFirst();
+            }
+        }
+    }
+
+    private static String format(final ILoggingEvent event) {
+        var timestamp = TS_FORMATTER.format(Instant.ofEpochMilli(event.getTimeStamp()));
+        var builder = new StringBuilder(256)
+            .append("[")
+            .append(timestamp)
+            .append("] [")
+            .append(event.getLoggerName())
+            .append("] [")
+            .append(event.getLevel())
+            .append("] [")
+            .append(event.getThreadName())
+            .append("] ")
+            .append(event.getFormattedMessage())
+            .append('\n');
+        var throwableProxy = event.getThrowableProxy();
+        if (throwableProxy != null) {
+            builder.append(ThrowableProxyUtil.asString(throwableProxy));
+        }
+        return builder.toString();
+    }
+
+    private record Entry(long sequence, String text) {}
+}

src/test/java/com/zenith/TestLogCaptureAppender.java

@@ -0,0 +1,11 @@
+package com.zenith;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.AppenderBase;
+
+public class TestLogCaptureAppender extends AppenderBase<ILoggingEvent> {
+    @Override
+    protected void append(final ILoggingEvent eventObject) {
+        TestLogCapture.append(eventObject);
+    }
+}

src/test/java/com/zenith/TestLogCaptureJunitExtension.java

@@ -0,0 +1,40 @@
+package com.zenith;
+
+import org.junit.jupiter.api.extension.BeforeEachCallback;
+import org.junit.jupiter.api.extension.ExtensionContext;
+import org.junit.jupiter.api.extension.TestWatcher;
+
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentMap;
+
+public class TestLogCaptureJunitExtension implements BeforeEachCallback, TestWatcher {
+    private static final ConcurrentMap<String, Long> CHECKPOINTS = new ConcurrentHashMap<>();
+
+    @Override
+    public void beforeEach(final ExtensionContext context) {
+        CHECKPOINTS.put(context.getUniqueId(), TestLogCapture.checkpoint());
+    }
+
+    @Override
+    public void testFailed(final ExtensionContext context, final Throwable cause) {
+        var checkpoint = CHECKPOINTS.remove(context.getUniqueId());
+        if (checkpoint == null)
+            return;
+
+        var testName = context.getDisplayName();
+        var logs = TestLogCapture.dumpSince(checkpoint);
+        System.err.println("\n=== test failed: " + testName + " ===");
+        System.err.println(logs);
+        System.err.println("===\n");
+    }
+
+    @Override
+    public void testSuccessful(final ExtensionContext context) {
+        CHECKPOINTS.remove(context.getUniqueId());
+    }
+
+    @Override
+    public void testAborted(final ExtensionContext context, final Throwable cause) {
+        CHECKPOINTS.remove(context.getUniqueId());
+    }
+}

src/test/resources/logback-test.xml

@@ -28,9 +28,16 @@
         <appender-ref ref="TERMINAL"/>
         <discardingThreshold>0</discardingThreshold>
     </appender>
+    <appender name="TEST_CAPTURE" class="com.zenith.TestLogCaptureAppender">
+        <filter class="com.zenith.terminal.logback.LogSourceFilter"/>
+        <filter class="ThresholdFilter">
+            <level>INFO</level>
+        </filter>
+    </appender>
+
 
     <root>
-        <!--        allow logs from other libs to also go to stdout-->
         <appender-ref ref="ASYNC_TERMINAL"/>
+        <appender-ref ref="TEST_CAPTURE"/>
     </root>
 </configuration>