Improve log flushing and add test

Author: adinauer

sentry-logback/src/test/kotlin/io/sentry/logback/SentryAppenderTest.kt

@@ -14,8 +14,10 @@ import io.sentry.ITransportFactory
 import io.sentry.InitPriority
 import io.sentry.Sentry
 import io.sentry.SentryLevel
+import io.sentry.SentryLogLevel
 import io.sentry.SentryOptions
 import io.sentry.checkEvent
+import io.sentry.checkLogs
 import io.sentry.test.initForTest
 import io.sentry.transport.ITransport
 import org.mockito.kotlin.any
@@ -40,7 +42,7 @@ import kotlin.test.assertNull
 import kotlin.test.assertTrue
 
 class SentryAppenderTest {
-    private class Fixture(dsn: String? = "http://key@localhost/proj", minimumBreadcrumbLevel: Level? = null, minimumEventLevel: Level? = null, contextTags: List<String>? = null, encoder: Encoder<ILoggingEvent>? = null, sendDefaultPii: Boolean = false, options: SentryOptions = SentryOptions(), startLater: Boolean = false) {
+    private class Fixture(dsn: String? = "http://key@localhost/proj", minimumBreadcrumbLevel: Level? = null, minimumEventLevel: Level? = null, minimumLevel: Level? = null, contextTags: List<String>? = null, encoder: Encoder<ILoggingEvent>? = null, sendDefaultPii: Boolean = false, enableLogs: Boolean = false, options: SentryOptions = SentryOptions(), startLater: Boolean = false) {
         val logger: Logger = LoggerFactory.getLogger(SentryAppenderTest::class.java)
         val loggerContext = LoggerFactory.getILoggerFactory() as LoggerContext
         val transportFactory = mock<ITransportFactory>()
@@ -54,10 +56,12 @@ class SentryAppenderTest {
             this.encoder = encoder
             options.dsn = dsn
             options.isSendDefaultPii = sendDefaultPii
+            options.logs.isEnabled = enableLogs
             contextTags?.forEach { options.addContextTag(it) }
             appender.setOptions(options)
             appender.setMinimumBreadcrumbLevel(minimumBreadcrumbLevel)
             appender.setMinimumEventLevel(minimumEventLevel)
+            appender.setMinimumLevel(minimumLevel)
             appender.context = loggerContext
             appender.setTransportFactory(transportFactory)
             encoder?.context = loggerContext
@@ -312,6 +316,76 @@ class SentryAppenderTest {
         )
     }
 
+    @Test
+    fun `converts trace log level to Sentry log level`() {
+        fixture = Fixture(minimumLevel = Level.TRACE, enableLogs = true)
+        fixture.logger.trace("testing trace level")
+
+        Sentry.flush(1000)
+
+        verify(fixture.transport).send(
+            checkLogs { logs ->
+                assertEquals(SentryLogLevel.TRACE, logs.items.first().level)
+            }
+        )
+    }
+
+    @Test
+    fun `converts debug log level to Sentry log level`() {
+        fixture = Fixture(minimumLevel = Level.DEBUG, enableLogs = true)
+        fixture.logger.debug("testing debug level")
+
+        Sentry.flush(1000)
+
+        verify(fixture.transport).send(
+            checkLogs { logs ->
+                assertEquals(SentryLogLevel.DEBUG, logs.items.first().level)
+            }
+        )
+    }
+
+    @Test
+    fun `converts info log level to Sentry log level`() {
+        fixture = Fixture(minimumLevel = Level.INFO, enableLogs = true)
+        fixture.logger.info("testing info level")
+
+        Sentry.flush(1000)
+
+        verify(fixture.transport).send(
+            checkLogs { logs ->
+                assertEquals(SentryLogLevel.INFO, logs.items.first().level)
+            }
+        )
+    }
+
+    @Test
+    fun `converts warn log level to Sentry log level`() {
+        fixture = Fixture(minimumLevel = Level.WARN, enableLogs = true)
+        fixture.logger.warn("testing warn level")
+
+        Sentry.flush(1000)
+
+        verify(fixture.transport).send(
+            checkLogs { logs ->
+                assertEquals(SentryLogLevel.WARN, logs.items.first().level)
+            }
+        )
+    }
+
+    @Test
+    fun `converts error log level to Sentry log level`() {
+        fixture = Fixture(minimumLevel = Level.ERROR, enableLogs = true)
+        fixture.logger.error("testing error level")
+
+        Sentry.flush(1000)
+
+        verify(fixture.transport).send(
+            checkLogs { logs ->
+                assertEquals(SentryLogLevel.ERROR, logs.items.first().level)
+            }
+        )
+    }
+
     @Test
     fun `attaches thread information`() {
         fixture = Fixture(minimumEventLevel = Level.WARN)

sentry-test-support/src/main/kotlin/io/sentry/Assertions.kt

@@ -18,6 +18,20 @@ fun checkEvent(predicate: (SentryEvent) -> Unit): SentryEnvelope {
     }
 }
 
+/**
+ * Verifies is [SentryEnvelope] contains log events matching a predicate.
+ */
+fun checkLogs(predicate: (SentryLogEvents) -> Unit): SentryEnvelope {
+    return check {
+        val events: SentryLogEvents? = it.items.first().getLogs(JsonSerializer(SentryOptions.empty()))
+        if (events != null) {
+            predicate(events)
+        } else {
+            throw SkipError("event is null")
+        }
+    }
+}
+
 fun checkTransaction(predicate: (SentryTransaction) -> Unit): SentryEnvelope {
     return check {
         val transaction = it.items.first().getTransaction(JsonSerializer(SentryOptions.empty()))

sentry/src/main/java/io/sentry/logger/LoggerBatchProcessor.java

@@ -4,15 +4,18 @@
 import io.sentry.ISentryExecutorService;
 import io.sentry.ISentryLifecycleToken;
 import io.sentry.SentryExecutorService;
+import io.sentry.SentryLevel;
 import io.sentry.SentryLogEvent;
 import io.sentry.SentryLogEvents;
 import io.sentry.SentryOptions;
+import io.sentry.transport.ReusableCountLatch;
 import io.sentry.util.AutoClosableReentrantLock;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.Queue;
 import java.util.concurrent.ConcurrentLinkedQueue;
 import java.util.concurrent.Future;
+import java.util.concurrent.TimeUnit;
 import org.jetbrains.annotations.NotNull;
 import org.jetbrains.annotations.Nullable;
 
@@ -30,6 +33,8 @@ public final class LoggerBatchProcessor implements ILoggerBatchProcessor {
       new AutoClosableReentrantLock();
   private volatile boolean hasScheduled = false;
 
+  private final @NotNull ReusableCountLatch pendingCount = new ReusableCountLatch();
+
   public LoggerBatchProcessor(
       final @NotNull SentryOptions options, final @NotNull ISentryClient client) {
     this.options = options;
@@ -40,6 +45,7 @@ public LoggerBatchProcessor(
 
   @Override
   public void add(final @NotNull SentryLogEvent logEvent) {
+    pendingCount.increment();
     queue.offer(logEvent);
     maybeSchedule(false, false);
   }
@@ -78,6 +84,12 @@ private void maybeSchedule(boolean forceSchedule, boolean immediately) {
   @Override
   public void flush(long timeoutMillis) {
     maybeSchedule(true, true);
+    try {
+      pendingCount.waitTillZero(timeoutMillis, TimeUnit.MILLISECONDS);
+    } catch (InterruptedException e) {
+      options.getLogger().log(SentryLevel.ERROR, "Failed to flush log events", e);
+      Thread.currentThread().interrupt();
+    }
   }
 
   private void flush() {
@@ -108,6 +120,9 @@ private void flushBatch() {
 
     if (!logEvents.isEmpty()) {
       client.captureBatchedLogEvents(new SentryLogEvents(logEvents));
+      for (int i = 0; i < logEvents.size(); i++) {
+        pendingCount.decrement();
+      }
     }
   }