Merge branch 'main' into markushi/feat/log-timber-tags

Author: markushi

CHANGELOG.md

@@ -1,14 +1,19 @@
 # Changelog
 
-## Unreleased
+## 8.25.0
 
 ### Fixes
 
 - [ANR] Removed AndroidTransactionProfiler lock ([#4817](https://github.com/getsentry/sentry-java/pull/4817))
+- Avoid ExecutorService for DefaultCompositePerformanceCollector timeout ([#4841](https://github.com/getsentry/sentry-java/pull/4841))
+  - This avoids infinite data collection for never stopped transactions, leading to OOMs
+- Fix wrong .super() call in SentryTimberTree ([#4844](https://github.com/getsentry/sentry-java/pull/4844))
 
 ### Improvements
 
 - [ANR] Defer some class availability checks ([#4825](https://github.com/getsentry/sentry-java/pull/4825))
+- Collect PerformanceCollectionData only for sampled transactions ([#4834](https://github.com/getsentry/sentry-java/pull/4834))
+  - **Breaking change**: Transactions with a deferred sampling decision (`sampled == null`) won't be collecting any performance data anymore (CPU, RAM, slow/frozen frames).
 - Report Timber.tag() as `timber.tag` log attribute ([#4845](https://github.com/getsentry/sentry-java/pull/4845))
 
 ### Dependencies

gradle.properties

@@ -11,7 +11,7 @@ org.jetbrains.dokka.experimental.gradle.pluginMode=V2Enabled
 android.useAndroidX=true
 
 # Release information
-versionName=8.24.0
+versionName=8.25.0
 
 # Override the SDK name on native crashes on Android
 sentryAndroidSdkName=sentry.native.android

sentry-android-timber/src/main/java/io/sentry/android/timber/SentryTimberTree.kt

@@ -68,7 +68,7 @@ public class SentryTimberTree(
 
   /** Log an info message with optional format args. */
   override fun i(message: String?, vararg args: Any?) {
-    super.d(message, *args)
+    super.i(message, *args)
     logWithSentry(Log.INFO, null, message, *args)
   }
 

sentry-android-timber/src/test/java/io/sentry/android/timber/SentryTimberTreeTest.kt

@@ -1,5 +1,6 @@
 package io.sentry.android.timber
 
+import android.util.Log
 import io.sentry.Breadcrumb
 import io.sentry.Scopes
 import io.sentry.SentryLevel
@@ -23,18 +24,19 @@ import timber.log.Timber
 
 class SentryTimberTreeTest {
   private class Fixture {
-    val scopes = mock<Scopes>()
-    val logs = mock<ILoggerApi>()
-
-    init {
-      whenever(scopes.logger()).thenReturn(logs)
-    }
+    lateinit var scopes: Scopes
+    lateinit var logs: ILoggerApi
 
     fun getSut(
       minEventLevel: SentryLevel = SentryLevel.ERROR,
       minBreadcrumbLevel: SentryLevel = SentryLevel.INFO,
       minLogsLevel: SentryLogLevel = SentryLogLevel.INFO,
-    ): SentryTimberTree = SentryTimberTree(scopes, minEventLevel, minBreadcrumbLevel, minLogsLevel)
+    ): SentryTimberTree {
+      logs = mock<ILoggerApi>()
+      scopes = mock<Scopes>()
+      whenever(scopes.logger()).thenReturn(logs)
+      return SentryTimberTree(scopes, minEventLevel, minBreadcrumbLevel, minLogsLevel)
+    }
   }
 
   private val fixture = Fixture()
@@ -139,6 +141,56 @@ class SentryTimberTreeTest {
     verify(fixture.scopes).captureEvent(check { assertEquals("tag", it.getTag("TimberTag")) })
   }
 
+  @Test
+  fun `Tree captures an event with TimberTag tag for debug events`() {
+    val sut = fixture.getSut(minEventLevel = SentryLevel.INFO)
+    Timber.plant(sut)
+    // only available thru static class
+    Timber.tag("infoTag").i("message")
+    verify(fixture.scopes).captureEvent(check { assertEquals("infoTag", it.getTag("TimberTag")) })
+  }
+
+  @Test
+  fun `Tree captures an event with chained tag usage`() {
+    val sut = fixture.getSut(minEventLevel = SentryLevel.INFO)
+    Timber.plant(sut)
+    // only available thru static class
+    Timber.tag("infoTag").log(Log.INFO, "message")
+    verify(fixture.scopes).captureEvent(check { assertEquals("infoTag", it.getTag("TimberTag")) })
+  }
+
+  @Test
+  fun `Tree properly propagates all levels`() {
+    val levels =
+      listOf(
+        Pair(Log.DEBUG, SentryLevel.DEBUG),
+        Pair(Log.VERBOSE, SentryLevel.DEBUG),
+        Pair(Log.INFO, SentryLevel.INFO),
+        Pair(Log.WARN, SentryLevel.WARNING),
+        Pair(Log.ERROR, SentryLevel.ERROR),
+        Pair(Log.ASSERT, SentryLevel.FATAL),
+      )
+
+    for (level in levels) {
+      Timber.uprootAll()
+
+      val logLevel = level.first
+      val sentryLevel = level.second
+
+      val sut = fixture.getSut(minEventLevel = sentryLevel)
+      Timber.plant(sut)
+      // only available thru static class
+      Timber.tag("tag").log(logLevel, "message")
+      verify(fixture.scopes)
+        .captureEvent(
+          check {
+            assertEquals("tag", it.getTag("TimberTag"))
+            assertEquals(sentryLevel, it.level)
+          }
+        )
+    }
+  }
+
   @Test
   fun `Tree captures an event without TimberTag tag`() {
     val sut = fixture.getSut()

sentry/src/main/java/io/sentry/DefaultCompositePerformanceCollector.java

@@ -8,7 +8,7 @@
 import java.util.Timer;
 import java.util.TimerTask;
 import java.util.concurrent.ConcurrentHashMap;
-import java.util.concurrent.RejectedExecutionException;
+import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicBoolean;
 import org.jetbrains.annotations.ApiStatus;
 import org.jetbrains.annotations.NotNull;
@@ -20,8 +20,7 @@ public final class DefaultCompositePerformanceCollector implements CompositePerf
   private static final long TRANSACTION_COLLECTION_TIMEOUT_MILLIS = 30000;
   private final @NotNull AutoClosableReentrantLock timerLock = new AutoClosableReentrantLock();
   private volatile @Nullable Timer timer = null;
-  private final @NotNull Map<String, List<PerformanceCollectionData>> performanceDataMap =
-      new ConcurrentHashMap<>();
+  private final @NotNull Map<String, CompositeData> compositeDataMap = new ConcurrentHashMap<>();
   private final @NotNull List<IPerformanceSnapshotCollector> snapshotCollectors;
   private final @NotNull List<IPerformanceContinuousCollector> continuousCollectors;
   private final boolean hasNoCollectors;
@@ -65,23 +64,11 @@ public void start(final @NotNull ITransaction transaction) {
       collector.onSpanStarted(transaction);
     }
 
-    if (!performanceDataMap.containsKey(transaction.getEventId().toString())) {
-      performanceDataMap.put(transaction.getEventId().toString(), new ArrayList<>());
-      // We schedule deletion of collected performance data after a timeout
-      try {
-        options
-            .getExecutorService()
-            .schedule(() -> stop(transaction), TRANSACTION_COLLECTION_TIMEOUT_MILLIS);
-      } catch (RejectedExecutionException e) {
-        options
-            .getLogger()
-            .log(
-                SentryLevel.ERROR,
-                "Failed to call the executor. Performance collector will not be automatically finished. Did you call Sentry.close()?",
-                e);
-      }
+    final @NotNull String id = transaction.getEventId().toString();
+    if (!compositeDataMap.containsKey(id)) {
+      compositeDataMap.put(id, new CompositeData(transaction));
     }
-    start(transaction.getEventId().toString());
+    start(id);
   }
 
   @Override
@@ -95,8 +82,10 @@ public void start(final @NotNull String id) {
       return;
     }
 
-    if (!performanceDataMap.containsKey(id)) {
-      performanceDataMap.put(id, new ArrayList<>());
+    if (!compositeDataMap.containsKey(id)) {
+      // Transactions are added in start(ITransaction). If we are here, it means we don't come from
+      // a transaction
+      compositeDataMap.put(id, new CompositeData(null));
     }
     if (!isStarted.getAndSet(true)) {
       try (final @NotNull ISentryLifecycleToken ignored = timerLock.acquire()) {
@@ -118,6 +107,7 @@ public void run() {
         // and collect() calls.
         // This way ICollectors that collect average stats based on time intervals, like
         // AndroidCpuCollector, can have an actual time interval to evaluate.
+        final @NotNull List<ITransaction> timedOutTransactions = new ArrayList<>();
         TimerTask timerTask =
             new TimerTask() {
               @Override
@@ -129,16 +119,31 @@ public void run() {
                 if (now - lastCollectionTimestamp <= 10) {
                   return;
                 }
+                timedOutTransactions.clear();
+
                 lastCollectionTimestamp = now;
                 final @NotNull PerformanceCollectionData tempData =
-                    new PerformanceCollectionData(new SentryNanotimeDate().nanoTimestamp());
+                    new PerformanceCollectionData(options.getDateProvider().now().nanoTimestamp());
 
+                // Enrich tempData using collectors
                 for (IPerformanceSnapshotCollector collector : snapshotCollectors) {
                   collector.collect(tempData);
                 }
 
-                for (List<PerformanceCollectionData> data : performanceDataMap.values()) {
-                  data.add(tempData);
+                // Add the enriched tempData to all transactions/profiles/objects that collect data.
+                // Then Check if that object timed out.
+                for (CompositeData data : compositeDataMap.values()) {
+                  if (data.addDataAndCheckTimeout(tempData)) {
+                    // timed out
+                    if (data.transaction != null) {
+                      timedOutTransactions.add(data.transaction);
+                    }
+                  }
+                }
+                // Stop timed out transactions outside compositeDataMap loop, as stop() modifies the
+                // map
+                for (final @NotNull ITransaction t : timedOutTransactions) {
+                  stop(t);
                 }
               }
             };
@@ -183,13 +188,14 @@ public void onSpanFinished(@NotNull ISpan span) {
 
   @Override
   public @Nullable List<PerformanceCollectionData> stop(final @NotNull String id) {
-    final @Nullable List<PerformanceCollectionData> data = performanceDataMap.remove(id);
+    final @Nullable CompositeData data = compositeDataMap.remove(id);
+    options.getLogger().log(SentryLevel.DEBUG, "stop collecting performance info for " + id);
 
-    // close if they are no more running requests
-    if (performanceDataMap.isEmpty()) {
+    // close if there are no more running requests
+    if (compositeDataMap.isEmpty()) {
       close();
     }
-    return data;
+    return data != null ? data.dataList : null;
   }
 
   @Override
@@ -198,7 +204,7 @@ public void close() {
         .getLogger()
         .log(SentryLevel.DEBUG, "stop collecting all performance info for transactions");
 
-    performanceDataMap.clear();
+    compositeDataMap.clear();
     for (final @NotNull IPerformanceContinuousCollector collector : continuousCollectors) {
       collector.clear();
     }
@@ -211,4 +217,30 @@ public void close() {
       }
     }
   }
+
+  private class CompositeData {
+    private final @NotNull List<PerformanceCollectionData> dataList;
+    private final @Nullable ITransaction transaction;
+    private final long startTimestamp;
+
+    private CompositeData(final @Nullable ITransaction transaction) {
+      this.dataList = new ArrayList<>();
+      this.transaction = transaction;
+      this.startTimestamp = options.getDateProvider().now().nanoTimestamp();
+    }
+
+    /**
+     * Adds the data to the internal list of PerformanceCollectionData. Then it checks if data
+     * collection timed out (for transactions only).
+     *
+     * @return true if data collection timed out (for transactions only).
+     */
+    boolean addDataAndCheckTimeout(final @NotNull PerformanceCollectionData data) {
+      dataList.add(data);
+      return transaction != null
+          && options.getDateProvider().now().nanoTimestamp()
+              > startTimestamp
+                  + TimeUnit.MILLISECONDS.toNanos(TRANSACTION_COLLECTION_TIMEOUT_MILLIS);
+    }
+  }
 }

sentry/src/main/java/io/sentry/SentryTracer.java

@@ -77,7 +77,9 @@ public SentryTracer(
     this.name = context.getName();
     this.instrumenter = context.getInstrumenter();
     this.scopes = scopes;
-    this.compositePerformanceCollector = compositePerformanceCollector;
+    // Let's collect performance data (cpu, ram, frames) only when the transaction is sampled
+    this.compositePerformanceCollector =
+        Boolean.TRUE.equals(isSampled()) ? compositePerformanceCollector : null;
     this.transactionNameSource = context.getTransactionNameSource();
     this.transactionOptions = transactionOptions;
 
@@ -90,9 +92,9 @@ public SentryTracer(
     }
 
     // We are currently sending the performance data only in profiles, but we are always sending
-    // performance measurements.
-    if (compositePerformanceCollector != null) {
-      compositePerformanceCollector.start(this);
+    // performance measurements (frames data in spans).
+    if (this.compositePerformanceCollector != null) {
+      this.compositePerformanceCollector.start(this);
     }
 
     if (transactionOptions.getIdleTimeout() != null