From cd53084d104d3b6eb8eb33330ed1e2a28eeb4d3f Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Fri, 6 Oct 2023 09:12:34 +0200 Subject: [PATCH 1/5] fix: Crash in SentryTracer when cancelling timer 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 --- Sources/Sentry/SentryTracer.m | 15 +++++-- .../Transaction/SentryTracerTests.swift | 41 +++++++++++++++++++ 2 files changed, 53 insertions(+), 3 deletions(-) diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index 8f327550109..ddb44a581f9 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,12 @@ - (void)deadlineTimerFired - (void)cancelDeadlineTimer { - [self.deadlineTimer invalidate]; - self.deadlineTimer = nil; + // 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:^{ + [self.deadlineTimer invalidate]; + self.deadlineTimer = nil; + }]; } - (id)getActiveSpan diff --git a/Tests/SentryTests/Transaction/SentryTracerTests.swift b/Tests/SentryTests/Transaction/SentryTracerTests.swift index e8c347daaba..b187cd979d8 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,44 @@ 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 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() From 509a8b045e88863a87ec5063574a259e4f48d468 Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Fri, 6 Oct 2023 09:16:09 +0200 Subject: [PATCH 2/5] add changelog entry --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 643ca3d5459..325eba05006 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,7 @@ - App hang with race condition for tick counter (#3290) - Remove "duplicate library" warning (#3312) - Remove unnecessaries build settings (#3325) +- Crash in SentryTracer when cancelling timer #3333 ## 8.13.0 From 5326485eedf75c2d37fbc252cc35cfa18cebe34c Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Fri, 6 Oct 2023 09:48:49 +0200 Subject: [PATCH 3/5] fix failing test --- SentryTestUtils/TestSentryDispatchQueueWrapper.swift | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/SentryTestUtils/TestSentryDispatchQueueWrapper.swift b/SentryTestUtils/TestSentryDispatchQueueWrapper.swift index 44d22183cf9..c9573f84517 100644 --- a/SentryTestUtils/TestSentryDispatchQueueWrapper.swift +++ b/SentryTestUtils/TestSentryDispatchQueueWrapper.swift @@ -23,25 +23,27 @@ public class TestSentryDispatchQueueWrapper: SentryDispatchQueueWrapper { dispatchAsyncInvocations.invocations.last?() } - public var blockOnMainInvocations = Invocations<() -> Void>() + // Keeping track of the blocks can lead to memory leaks. Therefore, + // we only keep track of the number of invocations. + public var blockOnMainInvocations = Invocations() public var blockBeforeMainBlock: () -> Bool = { true } public override func dispatch(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(block) + blockOnMainInvocations.record(Void()) if blockBeforeMainBlock() { block() } } public override func dispatchAsync(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(block) + blockOnMainInvocations.record(Void()) if blockBeforeMainBlock() { block() } } public override func dispatchSync(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(block) + blockOnMainInvocations.record(Void()) if blockBeforeMainBlock() { block() } From 65391b9867c748f2f6ee57a4f986feafc4c7a3af Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Wed, 11 Oct 2023 18:05:32 +0200 Subject: [PATCH 4/5] remove potential retain cycle --- SentryTestUtils/Invocations.swift | 6 +++ .../TestSentryDispatchQueueWrapper.swift | 10 ++--- Sources/Sentry/SentryTracer.m | 11 +++++- .../Transaction/SentryTracerTests.swift | 38 +++++++++++++++++++ 4 files changed, 57 insertions(+), 8 deletions(-) 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/SentryTestUtils/TestSentryDispatchQueueWrapper.swift b/SentryTestUtils/TestSentryDispatchQueueWrapper.swift index c9573f84517..44d22183cf9 100644 --- a/SentryTestUtils/TestSentryDispatchQueueWrapper.swift +++ b/SentryTestUtils/TestSentryDispatchQueueWrapper.swift @@ -23,27 +23,25 @@ public class TestSentryDispatchQueueWrapper: SentryDispatchQueueWrapper { dispatchAsyncInvocations.invocations.last?() } - // Keeping track of the blocks can lead to memory leaks. Therefore, - // we only keep track of the number of invocations. - public var blockOnMainInvocations = Invocations() + public var blockOnMainInvocations = Invocations<() -> Void>() public var blockBeforeMainBlock: () -> Bool = { true } public override func dispatch(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(Void()) + blockOnMainInvocations.record(block) if blockBeforeMainBlock() { block() } } public override func dispatchAsync(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(Void()) + blockOnMainInvocations.record(block) if blockBeforeMainBlock() { block() } } public override func dispatchSync(onMainQueue block: @escaping () -> Void) { - blockOnMainInvocations.record(Void()) + blockOnMainInvocations.record(block) if blockBeforeMainBlock() { block() } diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index ddb44a581f9..af8e53cbb07 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -272,11 +272,18 @@ - (void)deadlineTimerFired - (void)cancelDeadlineTimer { + // 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:^{ - [self.deadlineTimer invalidate]; - self.deadlineTimer = nil; + if (weakSelf == nil) { + SENTRY_LOG_DEBUG(@"WeakSelf is nil. Not invalidating deadlineTimer."); + return; + } + [weakSelf.deadlineTimer invalidate]; + weakSelf.deadlineTimer = nil; }]; } diff --git a/Tests/SentryTests/Transaction/SentryTracerTests.swift b/Tests/SentryTests/Transaction/SentryTracerTests.swift index b187cd979d8..bfbe11babbc 100644 --- a/Tests/SentryTests/Transaction/SentryTracerTests.swift +++ b/Tests/SentryTests/Transaction/SentryTracerTests.swift @@ -193,6 +193,44 @@ class SentryTracerTests: XCTestCase { 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? + + // 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? + sut.finish() + } + startTracer() + + // The TestHub keeps a reference to the tracer in capturedEventsWithScopes. + // We have to clear the captured events so the tracer gets deallocated. + fixture.hub.capturedEventsWithScopes.removeAll() + + 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 } From 0aeff0a71b61799713e9672d8e00758b6d5844c6 Mon Sep 17 00:00:00 2001 From: Philipp Hofmann Date: Thu, 12 Oct 2023 08:58:59 +0200 Subject: [PATCH 5/5] fix test --- Tests/SentryTests/SentryTests-Bridging-Header.h | 1 + Tests/SentryTests/Transaction/SentryTracerTests.swift | 11 ++++++++--- 2 files changed, 9 insertions(+), 3 deletions(-) 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 bfbe11babbc..45ce7d2fde0 100644 --- a/Tests/SentryTests/Transaction/SentryTracerTests.swift +++ b/Tests/SentryTests/Transaction/SentryTracerTests.swift @@ -207,18 +207,23 @@ class SentryTracerTests: XCTestCase { } 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() - // The TestHub keeps a reference to the tracer in capturedEventsWithScopes. - // We have to clear the captured events so the tracer gets deallocated. - fixture.hub.capturedEventsWithScopes.removeAll() + XCTAssertNil(weakSut, "sut was not deallocated") fixture.timerFactory.fire()