fix: Deadline timeout crash in SentryTracer

CHANGELOG.md

@@ -16,6 +16,7 @@
 
 - Fix rare memory access issue for auto tracing (#4894). For more details, see issue [#4887](https://github.com/getsentry/sentry-cocoa/issues/4887).
 - Move assignment of file IO span origin outside of block (#4888)
+- Deadline timeout crash in SentryTracer (#4911)
 
 ## 8.45.0
 

Sources/Sentry/SentryTracer.m

@@ -9,7 +9,6 @@
 #import "SentryInternalDefines.h"
 #import "SentryLog.h"
 #import "SentryNSDictionarySanitize.h"
-#import "SentryNSTimerFactory.h"
 #import "SentryNoOpSpan.h"
 #import "SentryOptions+Private.h"
 #import "SentryProfilingConditionals.h"
@@ -72,7 +71,6 @@
  * @c -[finish] doesn't necessarily lead to finishing the tracer, because it could still wait for
  * child spans to finish if @c waitForChildren is @c YES . */
 @property (nonatomic) BOOL wasFinishCalled;
-@property (nonatomic, nullable, strong) NSTimer *deadlineTimer;
 @property (nonnull, strong) SentryTracerConfiguration *configuration;
 @property (nonatomic, strong) SentryDispatchQueueWrapper *dispatchQueue;
 @property (nonatomic, strong) SentryDebugImageProvider *debugImageProvider;
@@ -91,10 +89,11 @@
     SentryAppStartMeasurement *appStartMeasurement;
 #endif // SENTRY_HAS_UIKIT
     NSMutableDictionary<NSString *, SentryMeasurementValue *> *_measurements;
+    NSObject *_dispatchTimeoutLock;
     dispatch_block_t _idleTimeoutBlock;
+    dispatch_block_t _deadlineTimeoutBlock;
     NSMutableArray<id<SentrySpan>> *_children;
     BOOL _startTimeChanged;
-    NSObject *_idleTimeoutLock;
 
 #if SENTRY_HAS_UIKIT
     NSUInteger initTotalFrames;
@@ -147,10 +146,6 @@
     _measurements = [[NSMutableDictionary alloc] init];
     self.finishStatus = kSentrySpanStatusUndefined;
 
-    if (_configuration.timerFactory == nil) {
-        _configuration.timerFactory = [[SentryNSTimerFactory alloc] init];
-    }
-
 #if SENTRY_HAS_UIKIT
     [hub configureScope:^(SentryScope *scope) {
         if (scope.currentScreen != nil) {
@@ -165,13 +160,13 @@
 
 #endif // SENTRY_HAS_UIKIT
 
-    _idleTimeoutLock = [[NSObject alloc] init];
+    _dispatchTimeoutLock = [[NSObject alloc] init];
     if ([self hasIdleTimeout]) {
-        [self dispatchIdleTimeout];
+        [self startIdleTimeout];
     }
 
     if ([self isAutoGeneratedTransaction]) {
-        [self startDeadlineTimer];
+        [self startDeadlineTimeout];
     }
 
 #if SENTRY_HAS_UIKIT
@@ -213,80 +208,71 @@
         sentry_discardProfilerForTracer(self.internalID);
     }
 #endif // SENTRY_TARGET_PROFILING_SUPPORTED
+    [self cancelDeadlineTimeout];
 }
 
 - (nullable SentryTracer *)tracer
 {
     return self;
 }
 
-- (void)dispatchIdleTimeout
-{
-    @synchronized(_idleTimeoutLock) {
-        if (_idleTimeoutBlock != NULL) {
-            [_dispatchQueue dispatchCancel:_idleTimeoutBlock];
-        }
-        __weak SentryTracer *weakSelf = self;
-        _idleTimeoutBlock = [_dispatchQueue createDispatchBlock:^{
-            if (weakSelf == nil) {
-                SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not doing anything.");
-                return;
-            }
-            [weakSelf finishInternal];
-        }];
-
-        if (_idleTimeoutBlock == NULL) {
-            SENTRY_LOG_WARN(@"Couldn't create idle time out block. Can't schedule idle timeout. "
-                            @"Finishing transaction");
-            // If the transaction has no children, the SDK will discard it.
-            [self finishInternal];
-        } else {
-            [_dispatchQueue dispatchAfter:_configuration.idleTimeout block:_idleTimeoutBlock];
-        }
-    }
-}
+#pragma mark - Timeouts
 
 - (BOOL)hasIdleTimeout
 {
     return _configuration.idleTimeout > 0;
 }
 
-- (BOOL)isAutoGeneratedTransaction
+- (void)startIdleTimeout
 {
-    return _configuration.waitForChildren || [self hasIdleTimeout];
+    __weak SentryTracer *weakSelf = self;
+    dispatch_block_t newBlock = [_dispatchQueue createDispatchBlock:^{
+        if (weakSelf == nil) {
+            SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not doing anything.");
+            return;
+        }
+        [weakSelf finishInternal];
+    }];
+
+    @synchronized(_dispatchTimeoutLock) {
+        [self dispatchTimeout:_idleTimeoutBlock
+                     newBlock:newBlock
+                     interval:_configuration.idleTimeout];
+        _idleTimeoutBlock = newBlock;
+    }
 }
 
 - (void)cancelIdleTimeout
 {
-    @synchronized(_idleTimeoutLock) {
+    @synchronized(_dispatchTimeoutLock) {
         if ([self hasIdleTimeout]) {
-            [SentryDependencyContainer.sharedInstance.dispatchQueueWrapper
-                dispatchCancel:_idleTimeoutBlock];
+            [_dispatchQueue dispatchCancel:_idleTimeoutBlock];
         }
     }
 }
 
-- (void)startDeadlineTimer
+- (void)startDeadlineTimeout
 {
     __weak SentryTracer *weakSelf = self;
-    [_dispatchQueue dispatchAsyncOnMainQueue:^{
-        weakSelf.deadlineTimer = [weakSelf.configuration.timerFactory
-            scheduledTimerWithTimeInterval:SENTRY_AUTO_TRANSACTION_DEADLINE
-                                   repeats:NO
-                                     block:^(NSTimer *_Nonnull timer) {
-                                         if (weakSelf == nil) {
-                                             SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not calling "
-                                                              @"deadlineTimerFired.");
-                                             return;
-                                         }
-                                         [weakSelf deadlineTimerFired];
-                                     }];
+    dispatch_block_t newBlock = [_dispatchQueue createDispatchBlock:^{
+        if (weakSelf == nil) {
+            SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not doing anything.");
+            return;
+        }
+        [weakSelf deadlineTimeoutExceeded];
     }];
+
+    @synchronized(_dispatchTimeoutLock) {
+        [self dispatchTimeout:_deadlineTimeoutBlock
+                     newBlock:newBlock
+                     interval:SENTRY_AUTO_TRANSACTION_DEADLINE];
+        _deadlineTimeoutBlock = newBlock;
+    }
 }
 
-- (void)deadlineTimerFired
+- (void)deadlineTimeoutExceeded
 {
-    SENTRY_LOG_DEBUG(@"Sentry tracer deadline fired");
+    SENTRY_LOG_DEBUG(@"Sentry tracer deadline exceeded");
     @synchronized(self) {
         // This try to minimize a race condition with a proper call to `finishInternal`.
         if (self.isFinished) {
@@ -305,25 +291,38 @@
     [self finishInternal];
 }
 
-- (void)cancelDeadlineTimer
+- (void)cancelDeadlineTimeout
 {
-    if (self.deadlineTimer == nil) {
-        return;
+    @synchronized(_dispatchTimeoutLock) {
+        if (_deadlineTimeoutBlock != NULL) {
+            [_dispatchQueue dispatchCancel:_deadlineTimeoutBlock];
+            _deadlineTimeoutBlock = NULL;
+        }
     }
+}
 
-    // If the main thread is busy the tracer could be deallocated in between.
-    __weak SentryTracer *weakSelf = self;
+- (void)dispatchTimeout:(dispatch_block_t)currentBlock
+               newBlock:(dispatch_block_t)newBlock
+               interval:(NSTimeInterval)timeInterval
+{
+    if (currentBlock != NULL) {
+        [_dispatchQueue dispatchCancel:currentBlock];
+    }
 
-    // The timer must be invalidated from the thread on which the timer was installed, see
-    // https://developer.apple.com/documentation/foundation/nstimer/1415405-invalidate#1770468
-    [_dispatchQueue dispatchAsyncOnMainQueue:^{
-        if (weakSelf == nil) {
-            SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not invalidating deadlineTimer.");
-            return;
-        }
-        [weakSelf.deadlineTimer invalidate];
-        weakSelf.deadlineTimer = nil;
-    }];
+    if (newBlock == NULL) {
+        SENTRY_LOG_WARN(@"Couldn't create dispatch after block. Finishing transaction.");
+        // If the transaction has no children, the SDK will discard it.
+        [self finishInternal];
+    } else {
+        [_dispatchQueue dispatchAfter:timeInterval block:newBlock];
+    }
+}
+
+#pragma mark - Tracer
+
+- (BOOL)isAutoGeneratedTransaction
+{
+    return _configuration.waitForChildren || [self hasIdleTimeout];
 }
 
 - (id<SentrySpan>)getActiveSpan
@@ -499,7 +498,7 @@
             SENTRY_LOG_DEBUG(
                 @"Span with id %@ isn't waiting on children and needs idle timeout dispatched.",
                 self.spanId.sentrySpanIdString);
-            [self dispatchIdleTimeout];
+            [self startIdleTimeout];
             return;
         }
 
@@ -575,7 +574,7 @@
 - (BOOL)finishTracer:(SentrySpanStatus)unfinishedSpansFinishStatus shouldCleanUp:(BOOL)shouldCleanUp
 {
     if (shouldCleanUp) {
-        [self cancelDeadlineTimer];
+        [self cancelDeadlineTimeout];
     }
 
     if (self.isFinished) {

Sources/Sentry/SentryUIEventTrackerTransactionMode.m

@@ -49,7 +49,7 @@
     if (sameAction) {
         SENTRY_LOG_DEBUG(@"Dispatching idle timeout for transaction with span id %@",
             currentActiveTransaction.spanId.sentrySpanIdString);
-        [currentActiveTransaction dispatchIdleTimeout];
+        [currentActiveTransaction startIdleTimeout];
         return;
     }
 

Sources/Sentry/include/SentryTracer.h

@@ -90,7 +90,7 @@ static const NSTimeInterval SENTRY_AUTO_TRANSACTION_MAX_DURATION = 500.0;
  */
 + (nullable SentryTracer *)getTracer:(id<SentrySpan>)span;
 
-- (void)dispatchIdleTimeout;
+- (void)startIdleTimeout;
 
 /**
  * This method is designed to be used when the app crashes. It finishes the transaction and stores

Sources/Sentry/include/SentryTracerConfiguration.h

@@ -9,7 +9,6 @@
 NS_ASSUME_NONNULL_BEGIN
 
 @class SentryDispatchQueueWrapper;
-@class SentryNSTimerFactory;
 @class SentrySamplerDecision;
 
 @interface SentryTracerConfiguration : NSObject
@@ -49,11 +48,6 @@ NS_ASSUME_NONNULL_BEGIN
  */
 @property (nonatomic) NSTimeInterval idleTimeout;
 
-/**
- * A writer around NSTimer, to make it testable
- */
-@property (nonatomic, strong, nullable) SentryNSTimerFactory *timerFactory;
-
 + (SentryTracerConfiguration *)configurationWithBlock:
     (void (^)(SentryTracerConfiguration *configuration))block;
 

Tests/SentryProfilerTests/SentryProfileTestFixture.swift

@@ -108,7 +108,6 @@ class SentryProfileTestFixture {
                         $0.idleTimeout = idleTimeout
                     }
                     $0.waitForChildren = true
-                    $0.timerFactory = self.timeoutTimerFactory
                 }))
         }
 

Tests/SentryTests/Integrations/Performance/UIViewController/SentryTimeToDisplayTrackerTest.swift

@@ -9,28 +9,26 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
 
     private class Fixture {
         let dateProvider: TestCurrentDateProvider = TestCurrentDateProvider()
-        lazy var timerFactory = TestSentryNSTimerFactory(currentDateProvider: dateProvider)
-
+        let dispatchQueue = TestSentryDispatchQueueWrapper()
         var displayLinkWrapper = TestDisplayLinkWrapper()
         var framesTracker: SentryFramesTracker
 
         init() {
-            framesTracker = SentryFramesTracker(displayLinkWrapper: displayLinkWrapper, dateProvider: dateProvider, dispatchQueueWrapper: TestSentryDispatchQueueWrapper(),
+            framesTracker = SentryFramesTracker(displayLinkWrapper: displayLinkWrapper, dateProvider: dateProvider, dispatchQueueWrapper: dispatchQueue,
                                                 notificationCenter: TestNSNotificationCenterWrapper(), keepDelayedFramesDuration: 0)
             SentryDependencyContainer.sharedInstance().framesTracker = framesTracker
             framesTracker.start()
         }
 
         func getSut(name: String, waitForFullDisplay: Bool) -> SentryTimeToDisplayTracker {
-            return SentryTimeToDisplayTracker(name: name, waitForFullDisplay: waitForFullDisplay, dispatchQueueWrapper: SentryDispatchQueueWrapper())
+            return SentryTimeToDisplayTracker(name: name, waitForFullDisplay: waitForFullDisplay, dispatchQueueWrapper: dispatchQueue)
         }
 
         func getTracer() throws -> SentryTracer {
             let options = Options()
             let hub = TestHub(client: SentryClient(options: options, fileManager: try TestFileManager(options: options), deleteOldEnvelopeItems: false), andScope: nil)
             return SentryTracer(transactionContext: TransactionContext(operation: "ui.load"), hub: hub, configuration: SentryTracerConfiguration(block: {
                 $0.waitForChildren = true
-                $0.timerFactory = self.timerFactory
             }))
         }
     }
@@ -40,7 +38,7 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
     override func setUp() {
         super.setUp()
         SentryDependencyContainer.sharedInstance().dateProvider = fixture.dateProvider
-        SentryDependencyContainer.sharedInstance().dispatchQueueWrapper = TestSentryDispatchQueueWrapper()
+        SentryDependencyContainer.sharedInstance().dispatchQueueWrapper = fixture.dispatchQueue
     }
 
     override func tearDown() {
@@ -279,8 +277,8 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
 
         fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11))
 
-        // Timeout for tracer times out
-        try fixture.timerFactory.fire()
+        // Deadline timeout for tracer times out
+        fixture.dispatchQueue.invokeLastDispatchAfter()
 
         fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 12))
         sut.reportFullyDisplayed()
@@ -329,8 +327,8 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
 
         fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11))
 
-        // Timeout for tracer times out
-        try fixture.timerFactory.fire()
+        // Deadline timeout for tracer times out
+        fixture.dispatchQueue.invokeLastDispatchAfter()
 
         fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 12))
         sut.reportFullyDisplayed()