From fb7eecf9963493f7ab399d17ca257f835d5cfc3f Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Thu, 12 Oct 2023 10:13:42 +0200 Subject: [PATCH] fix: Crash in SentryTracer when cancelling timer (#3333) The SentryTracer starts the timer for the deadline on the main thread and invalidates the timer, not necessarily on the main thread, but invalidate has to be called on the same thread on which the timer was started. This is fixed by starting and invalidating the NSTimer on the main thread. Fixes GH-3320 Co-authored-by: Andrew McKnight --- CHANGELOG.md | 1 + SentryTestUtils/Invocations.swift | 6 ++ Sources/Sentry/SentryTracer.m | 22 ++++- .../SentryTests/SentryTests-Bridging-Header.h | 1 + .../Transaction/SentryTracerTests.swift | 84 +++++++++++++++++++ 5 files changed, 111 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 160edcea216..191c0f85d38 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,7 @@ - Remove "duplicate library" warning (#3312) - Fix multiple issues in Reachability (#3338) - Remove unnecessary build settings (#3325) +- Crash in SentryTracer when cancelling timer (#3333) ## 8.13.0 diff --git a/SentryTestUtils/Invocations.swift b/SentryTestUtils/Invocations.swift index 3baa3147ea0..d39f5f14f1a 100644 --- a/SentryTestUtils/Invocations.swift +++ b/SentryTestUtils/Invocations.swift @@ -46,4 +46,10 @@ public class Invocations { self._invocations.append(invocation) } } + + public func removeAll() { + queue.async(flags: .barrier) { + self._invocations.removeAll() + } + } } diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index 8f327550109..af8e53cbb07 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -235,11 +235,16 @@ - (void)cancelIdleTimeout - (void)startDeadlineTimer { __weak SentryTracer *weakSelf = self; - [SentryThreadWrapper onMainThread:^{ + [_configuration.dispatchQueueWrapper dispatchOnMainQueue:^{ 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]; }]; }]; @@ -267,8 +272,19 @@ - (void)deadlineTimerFired - (void)cancelDeadlineTimer { - [self.deadlineTimer invalidate]; - self.deadlineTimer = nil; + // If the main thread is busy the tracer could be dealloc ated in between. + __weak SentryTracer *weakSelf = self; + + // 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 + [_configuration.dispatchQueueWrapper dispatchOnMainQueue:^{ + if (weakSelf == nil) { + SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not invalidating deadlineTimer."); + return; + } + [weakSelf.deadlineTimer invalidate]; + weakSelf.deadlineTimer = nil; + }]; } - (id)getActiveSpan diff --git a/Tests/SentryTests/SentryTests-Bridging-Header.h b/Tests/SentryTests/SentryTests-Bridging-Header.h index bca2e15232c..1dc1af4ee23 100644 --- a/Tests/SentryTests/SentryTests-Bridging-Header.h +++ b/Tests/SentryTests/SentryTests-Bridging-Header.h @@ -181,6 +181,7 @@ #import "SentryThreadWrapper.h" #import "SentryTime.h" #import "SentryTraceContext.h" +#import "SentryTracer+Private.h" #import "SentryTracer+Test.h" #import "SentryTransaction.h" #import "SentryTransactionContext+Private.h" diff --git a/Tests/SentryTests/Transaction/SentryTracerTests.swift b/Tests/SentryTests/Transaction/SentryTracerTests.swift index e8c347daaba..45ce7d2fde0 100644 --- a/Tests/SentryTests/Transaction/SentryTracerTests.swift +++ b/Tests/SentryTests/Transaction/SentryTracerTests.swift @@ -93,6 +93,7 @@ class SentryTracerTests: XCTestCase { customSamplingContext: [:], configuration: SentryTracerConfiguration(block: { $0.waitForChildren = waitForChildren + $0.dispatchQueueWrapper = self.dispatchQueue $0.timerFactory = self.timerFactory })) return tracer @@ -160,7 +161,9 @@ class SentryTracerTests: XCTestCase { } func testDeadlineTimer_FinishesTransactionAndChildren() { + fixture.dispatchQueue.blockBeforeMainBlock = { true } let sut = fixture.getSut() + let child1 = sut.startChild(operation: fixture.transactionOperation) let child2 = sut.startChild(operation: fixture.transactionOperation) let child3 = sut.startChild(operation: fixture.transactionOperation) @@ -176,6 +179,87 @@ class SentryTracerTests: XCTestCase { XCTAssertEqual(child2.status, .deadlineExceeded) XCTAssertEqual(child3.status, .ok) } + + func testDeadlineTimer_StartedAndCancelledOnMainThread() { + fixture.dispatchQueue.blockBeforeMainBlock = { true } + + let sut = fixture.getSut() + let child1 = sut.startChild(operation: fixture.transactionOperation) + + fixture.timerFactory.fire() + + XCTAssertEqual(sut.status, .deadlineExceeded) + XCTAssertEqual(child1.status, .deadlineExceeded) + XCTAssertEqual(2, fixture.dispatchQueue.blockOnMainInvocations.count, "The NSTimer must be started and cancelled on the main thread.") + } + + func testCancelDeadlineTimer_TracerDeallocated() { + var invocations = 0 + fixture.dispatchQueue.blockBeforeMainBlock = { + // The second invocation the block for invalidating the timer + // which we want to call manually below. + if invocations == 1 { + return false + } + + invocations += 1 + return true + } + + var timer: Timer? + weak var weakSut: SentryTracer? + + // Added internal function so the tracer gets deallocated after executing this function. + func startTracer() { + let sut = fixture.getSut() + + timer = Dynamic(sut).deadlineTimer.asObject as! Timer? + weakSut = sut + + // The TestHub keeps a reference to the tracer in capturedEventsWithScopes. + // We set it to nil to avoid that. + sut.hub = nil + sut.finish() + } + startTracer() + + XCTAssertNil(weakSut, "sut was not deallocated") + + fixture.timerFactory.fire() + + let invalidateTimerBlock = fixture.dispatchQueue.blockOnMainInvocations.last + if invalidateTimerBlock != nil { + invalidateTimerBlock!() + } + + // Ensure the timer was not invalidated + XCTAssertTrue(timer?.isValid ?? false) + } + + func testDeadlineTimer_WhenCancelling_IsInvalidated() { + fixture.dispatchQueue.blockBeforeMainBlock = { true } + + let sut = fixture.getSut() + let timer: Timer? = Dynamic(sut).deadlineTimer + _ = sut.startChild(operation: fixture.transactionOperation) + + fixture.timerFactory.fire() + + XCTAssertNil(Dynamic(sut).deadlineTimer.asObject, "DeadlineTimer should be nil.") + XCTAssertFalse(timer?.isValid ?? true) + } + + func testDeadlineTimer_FiresAfterTracerDeallocated() { + fixture.dispatchQueue.blockBeforeMainBlock = { true } + + // Added internal function so the tracer gets deallocated after executing this function. + func startTracer() { + _ = fixture.getSut() + } + startTracer() + + fixture.timerFactory.fire() + } func testFramesofSpans_SetsDebugMeta() { let sut = fixture.getSut()