diff --git a/CHANGELOG.md b/CHANGELOG.md index 361515fa7bf..adf689abbf6 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ - Renamed `enableTimeToFullDisplay` to `enableTimeToFullDisplayTracing` (#3106) - This is an experimental feature and may change at any time without a major revision. + +### Fixes + +- Fix potential unbounded memory growth when starting profiled transactions from non-main contexts (#3135) ## 8.9.0-beta.1 diff --git a/Sentry.xcodeproj/project.pbxproj b/Sentry.xcodeproj/project.pbxproj index 0df123996ad..4847f1f29ff 100644 --- a/Sentry.xcodeproj/project.pbxproj +++ b/Sentry.xcodeproj/project.pbxproj @@ -3112,7 +3112,6 @@ 8454CF8B293EAF9A006AC140 /* SentryMetricProfiler.mm */, 03F84D1127DD414C008FE43F /* SentryProfiler.h */, 03F84D2B27DD4191008FE43F /* SentryProfiler.mm */, - 84A888FC28D9B11700C51DFD /* SentryProfiler+Test.h */, 84A888FC28D9B11700C51DFD /* SentryProfiler+Private.h */, 0354A22A2A134D9C003C3A04 /* SentryProfilerState.h */, 84281C642A57D36100EE88F2 /* SentryProfilerState+ObjCpp.h */, diff --git a/SentryTestUtils/ClearTestState.swift b/SentryTestUtils/ClearTestState.swift index 1771f704951..58be5ab4b58 100644 --- a/SentryTestUtils/ClearTestState.swift +++ b/SentryTestUtils/ClearTestState.swift @@ -42,6 +42,7 @@ class TestCleanup: NSObject { SentryTracer.resetAppStartMeasurementRead() #if os(iOS) || os(macOS) || targetEnvironment(macCatalyst) + SentryProfiler.getCurrent().stop(for: .normal) SentryTracer.resetConcurrencyTracking() #endif } diff --git a/SentryTestUtils/SentryTestUtils-ObjC-BridgingHeader.h b/SentryTestUtils/SentryTestUtils-ObjC-BridgingHeader.h index 112370d7aa2..02ca400b8e4 100644 --- a/SentryTestUtils/SentryTestUtils-ObjC-BridgingHeader.h +++ b/SentryTestUtils/SentryTestUtils-ObjC-BridgingHeader.h @@ -21,6 +21,7 @@ #import "SentryNSTimerFactory.h" #import "SentryNetworkTracker.h" #import "SentryPerformanceTracker+Testing.h" +#import "SentryProfiler+Test.h" #import "SentryRandom.h" #import "SentrySDK+Private.h" #import "SentrySDK+Tests.h" diff --git a/Sources/Sentry/SentryFramesTracker.m b/Sources/Sentry/SentryFramesTracker.m index 0a4043a90e3..5627d3eb8c0 100644 --- a/Sources/Sentry/SentryFramesTracker.m +++ b/Sources/Sentry/SentryFramesTracker.m @@ -123,7 +123,7 @@ - (void)displayLinkCallback } # if SENTRY_TARGET_PROFILING_SUPPORTED - if ([SentryProfiler isRunning]) { + if ([SentryProfiler isCurrentlyProfiling]) { BOOL hasNoFrameRatesYet = self.frameRateTimestamps.count == 0; uint64_t previousFrameRate = self.frameRateTimestamps.lastObject[@"value"].unsignedLongLongValue; @@ -179,7 +179,7 @@ - (void)reportNewFrame # if SENTRY_TARGET_PROFILING_SUPPORTED - (void)recordTimestamp:(uint64_t)timestamp value:(NSNumber *)value array:(NSMutableArray *)array { - BOOL shouldRecord = [SentryProfiler isRunning]; + BOOL shouldRecord = [SentryProfiler isCurrentlyProfiling]; # if defined(TEST) || defined(TESTCI) shouldRecord = YES; # endif diff --git a/Sources/Sentry/SentryNSNotificationCenterWrapper.m b/Sources/Sentry/SentryNSNotificationCenterWrapper.m index f235f2de55f..82fcc68c351 100644 --- a/Sources/Sentry/SentryNSNotificationCenterWrapper.m +++ b/Sources/Sentry/SentryNSNotificationCenterWrapper.m @@ -46,7 +46,7 @@ + (NSNotificationName)willTerminateNotificationName - (void)addObserver:(id)observer selector:(SEL)aSelector name:(NSNotificationName)aName - object:(id)anObject + object:(nullable id)anObject { [NSNotificationCenter.defaultCenter addObserver:observer selector:aSelector @@ -67,7 +67,7 @@ - (void)removeObserver:(id)observer name:(NSNotificationName)aName [NSNotificationCenter.defaultCenter removeObserver:observer name:aName object:nil]; } -- (void)removeObserver:(id)observer name:(NSNotificationName)aName object:(id)anObject +- (void)removeObserver:(id)observer name:(NSNotificationName)aName object:(nullable id)anObject { [NSNotificationCenter.defaultCenter removeObserver:observer name:aName object:anObject]; } @@ -77,7 +77,7 @@ - (void)removeObserver:(id)observer [NSNotificationCenter.defaultCenter removeObserver:observer]; } -- (void)postNotificationName:(NSNotificationName)aName object:(id)anObject +- (void)postNotificationName:(NSNotificationName)aName object:(nullable id)anObject { [NSNotificationCenter.defaultCenter postNotificationName:aName object:anObject]; } diff --git a/Sources/Sentry/SentryProfiler.mm b/Sources/Sentry/SentryProfiler.mm index 344197b6c47..6363cce3d21 100644 --- a/Sources/Sentry/SentryProfiler.mm +++ b/Sources/Sentry/SentryProfiler.mm @@ -15,12 +15,12 @@ # import "SentryEnvelopeItemType.h" # import "SentryEvent+Private.h" # import "SentryFormatter.h" -# import "SentryFramesTracker.h" # import "SentryHub+Private.h" # import "SentryId.h" # import "SentryInternalDefines.h" # import "SentryLog.h" # import "SentryMetricProfiler.h" +# import "SentryNSNotificationCenterWrapper.h" # import "SentryNSProcessInfoWrapper.h" # import "SentryNSTimerFactory.h" # import "SentryProfileTimeseries.h" @@ -28,22 +28,23 @@ # import "SentrySample.h" # import "SentrySamplingProfiler.hpp" # import "SentryScope+Private.h" -# import "SentryScreenFrames.h" # import "SentrySerialization.h" # import "SentrySpanId.h" # import "SentrySystemWrapper.h" # import "SentryThread.h" # import "SentryTime.h" # import "SentryTracer.h" +# import "SentryTracerConcurrency.h" # import "SentryTransaction.h" # import "SentryTransactionContext+Private.h" # import # import -# if TARGET_OS_IOS +# if SENTRY_HAS_UIKIT +# import "SentryScreenFrames.h" # import -# endif +# endif // SENTRY_HAS_UIKIT const int kSentryProfilerFrequencyHz = 101; NSTimeInterval kSentryProfilerTimeoutInterval = 30; @@ -155,7 +156,12 @@ serializedProfileData(NSDictionary *profileData, SentryTransaction *transaction, SentryId *profileID, NSString *truncationReason, NSString *environment, NSString *release, NSDictionary *serializedMetrics, NSArray *debugMeta, - SentryHub *hub) + SentryHub *hub +# if SENTRY_HAS_UIKIT + , + SentryScreenFrames *gpuData +# endif // SENTRY_HAS_UIKIT +) { NSMutableArray *const samples = profileData[@"profile"][@"samples"]; // We need at least two samples to be able to draw a stack frame for any given function: one @@ -231,28 +237,25 @@ auto metrics = serializedMetrics; # if SENTRY_HAS_UIKIT - const auto framesTracker = SentryDependencyContainer.sharedInstance.framesTracker; const auto mutableMetrics = [NSMutableDictionary dictionaryWithDictionary:metrics]; - const auto slowFrames = sliceGPUData(framesTracker.currentFrames.slowFrameTimestamps, - transaction, /*useMostRecentRecording */ NO); + const auto slowFrames + = sliceGPUData(gpuData.slowFrameTimestamps, transaction, /*useMostRecentRecording */ NO); if (slowFrames.count > 0) { mutableMetrics[@"slow_frame_renders"] = @ { @"unit" : @"nanosecond", @"values" : slowFrames }; } - const auto frozenFrames - = sliceGPUData(framesTracker.currentFrames.frozenFrameTimestamps, transaction, - /*useMostRecentRecording */ NO); + const auto frozenFrames = sliceGPUData(gpuData.frozenFrameTimestamps, transaction, + /*useMostRecentRecording */ NO); if (frozenFrames.count > 0) { mutableMetrics[@"frozen_frame_renders"] = @ { @"unit" : @"nanosecond", @"values" : frozenFrames }; } if (slowFrames.count > 0 || frozenFrames.count > 0) { - const auto frameRates - = sliceGPUData(framesTracker.currentFrames.frameRateTimestamps, transaction, - /*useMostRecentRecording */ YES); + const auto frameRates = sliceGPUData(gpuData.frameRateTimestamps, transaction, + /*useMostRecentRecording */ YES); if (frameRates.count > 0) { mutableMetrics[@"screen_frame_rates"] = @ { @"unit" : @"hz", @"values" : frameRates }; } @@ -283,20 +286,62 @@ - (instancetype)initWithHub:(SentryHub *)hub return nil; } + _profileId = [[SentryId alloc] init]; + SENTRY_LOG_DEBUG(@"Initialized new SentryProfiler %@", self); _debugImageProvider = [SentryDependencyContainer sharedInstance].debugImageProvider; _hub = hub; + [self start]; + [self scheduleTimeoutTimer]; + +# if SENTRY_HAS_UIKIT + [SentryDependencyContainer.sharedInstance.notificationCenterWrapper + addObserver:self + selector:@selector(backgroundAbort) + name:UIApplicationWillResignActiveNotification + object:nil]; +# endif // SENTRY_HAS_UIKIT + return self; } +/** + * Schedule a timeout timer on the main thread. + * @warning from NSTimer.h: Timers scheduled in an async context may never fire. + */ +- (void)scheduleTimeoutTimer +{ + __weak SentryProfiler *weakSelf = self; + void (^block)(void) = ^(void) { + if (![weakSelf isRunning]) { + return; + } + + SentryProfiler *strongSelf = weakSelf; + strongSelf->_timeoutTimer = [SentryDependencyContainer.sharedInstance.timerFactory + scheduledTimerWithTimeInterval:kSentryProfilerTimeoutInterval + target:self + selector:@selector(timeoutAbort) + userInfo:nil + repeats:NO]; + }; + + if (NSThread.isMainThread) { + block(); + } else { + dispatch_async(dispatch_get_main_queue(), block); + } +} + # pragma mark - Public -+ (void)startWithHub:(SentryHub *)hub ++ (void)startWithHub:(SentryHub *)hub tracer:(SentryTracer *)tracer { std::lock_guard l(_gProfilerLock); if (_gCurrentProfiler && [_gCurrentProfiler isRunning]) { SENTRY_LOG_DEBUG(@"A profiler is already running."); + trackProfilerForTracer(_gCurrentProfiler, tracer); return; } @@ -306,52 +351,26 @@ + (void)startWithHub:(SentryHub *)hub return; } -# if SENTRY_HAS_UIKIT - [SentryDependencyContainer.sharedInstance.framesTracker resetProfilingTimestamps]; -# endif // SENTRY_HAS_UIKIT - - [_gCurrentProfiler start]; - - _gCurrentProfiler->_timeoutTimer = [SentryDependencyContainer.sharedInstance.timerFactory - scheduledTimerWithTimeInterval:kSentryProfilerTimeoutInterval - target:self - selector:@selector(timeoutAbort) - userInfo:nil - repeats:NO]; -# if SENTRY_HAS_UIKIT - [[NSNotificationCenter defaultCenter] addObserver:self - selector:@selector(backgroundAbort) - name:UIApplicationWillResignActiveNotification - object:nil]; -# endif // SENTRY_HAS_UIKIT -} - -+ (void)stop -{ - std::lock_guard l(_gProfilerLock); - - if (!_gCurrentProfiler) { - SENTRY_LOG_WARN(@"No current global profiler manager to stop."); - return; - } - if (![_gCurrentProfiler isRunning]) { - SENTRY_LOG_WARN(@"Current profiler is not running."); - return; - } - - [self stopProfilerForReason:SentryProfilerTruncationReasonNormal]; + trackProfilerForTracer(_gCurrentProfiler, tracer); } -+ (BOOL)isRunning ++ (BOOL)isCurrentlyProfiling { std::lock_guard l(_gProfilerLock); return [_gCurrentProfiler isRunning]; } -+ (SentryEnvelopeItem *)createProfilingEnvelopeItemForTransaction:(SentryTransaction *)transaction ++ (nullable SentryEnvelopeItem *)createProfilingEnvelopeItemForTransaction: + (SentryTransaction *)transaction { - const auto profileID = [[SentryId alloc] init]; - const auto payload = [self serializeForTransaction:transaction profileID:profileID]; + const auto profiler = profilerForFinishedTracer(transaction.trace); + if (!profiler) { + SENTRY_LOG_WARN(@"Expected a profiler for tracer id %@ but none was found", + transaction.trace.traceId.sentryIdString); + return nil; + } + + const auto payload = [profiler serializeForTransaction:transaction]; # if defined(TEST) || defined(TESTCI) [NSNotificationCenter.defaultCenter postNotificationName:@"SentryProfileCompleteNotification" @@ -359,73 +378,68 @@ + (SentryEnvelopeItem *)createProfilingEnvelopeItemForTransaction:(SentryTransac userInfo:payload]; # endif // defined(TEST) || defined(TESTCI) - return [self envelopeItemForProfileData:payload profileID:profileID]; + const auto JSONData = [SentrySerialization dataWithJSONObject:payload]; + if (JSONData == nil) { + SENTRY_LOG_DEBUG(@"Failed to encode profile to JSON."); + return nil; + } + + const auto header = [[SentryEnvelopeItemHeader alloc] initWithType:SentryEnvelopeItemTypeProfile + length:JSONData.length]; + return [[SentryEnvelopeItem alloc] initWithHeader:header data:JSONData]; } # pragma mark - Private -+ (NSDictionary *)serializeForTransaction:(SentryTransaction *)transaction - profileID:(SentryId *)profileID +- (NSDictionary *)serializeForTransaction:(SentryTransaction *)transaction { - std::lock_guard l(_gProfilerLock); - - if (_gCurrentProfiler == nil) { - SENTRY_LOG_DEBUG(@"No profiler from which to receive data."); - return nil; - } - - return serializedProfileData([_gCurrentProfiler._state copyProfilingData], transaction, - profileID, profilerTruncationReasonName(_gCurrentProfiler->_truncationReason), - _gCurrentProfiler -> _hub.scope.environmentString - ?: _gCurrentProfiler->_hub.getClient.options.environment, - _gCurrentProfiler->_hub.getClient.options.releaseName, - [_gCurrentProfiler->_metricProfiler serializeForTransaction:transaction], - [_gCurrentProfiler->_debugImageProvider getDebugImagesCrashed:NO], - _gCurrentProfiler -> _hub); + return serializedProfileData([self._state copyProfilingData], transaction, self.profileId, + profilerTruncationReasonName(_truncationReason), + _hub.scope.environmentString ?: _hub.getClient.options.environment, + _hub.getClient.options.releaseName, [_metricProfiler serializeForTransaction:transaction], + [_debugImageProvider getDebugImagesCrashed:NO], _hub +# if SENTRY_HAS_UIKIT + , + self._screenFrameData +# endif // SENTRY_HAS_UIKIT + ); } -+ (void)timeoutAbort +- (void)timeoutAbort { - std::lock_guard l(_gProfilerLock); - - if (!_gCurrentProfiler) { - SENTRY_LOG_WARN(@"No current global profiler manager to stop."); - return; - } - if (![_gCurrentProfiler isRunning]) { + if (![self isRunning]) { SENTRY_LOG_WARN(@"Current profiler is not running."); return; } - SENTRY_LOG_DEBUG(@"Stopping profiler %@ due to timeout.", _gCurrentProfiler); - [self stopProfilerForReason:SentryProfilerTruncationReasonTimeout]; + SENTRY_LOG_DEBUG(@"Stopping profiler %@ due to timeout.", self); + [self stopForReason:SentryProfilerTruncationReasonTimeout]; } -+ (void)backgroundAbort +- (void)backgroundAbort { - std::lock_guard l(_gProfilerLock); - - if (!_gCurrentProfiler) { - SENTRY_LOG_WARN(@"No current global profiler manager to stop."); - return; - } - if (![_gCurrentProfiler isRunning]) { + if (![self isRunning]) { SENTRY_LOG_WARN(@"Current profiler is not running."); return; } - SENTRY_LOG_DEBUG(@"Stopping profiler %@ due to timeout.", _gCurrentProfiler); - [self stopProfilerForReason:SentryProfilerTruncationReasonAppMovedToBackground]; + SENTRY_LOG_DEBUG(@"Stopping profiler %@ due to timeout.", self); + [self stopForReason:SentryProfilerTruncationReasonAppMovedToBackground]; } -+ (void)stopProfilerForReason:(SentryProfilerTruncationReason)reason +- (void)stopForReason:(SentryProfilerTruncationReason)reason { - [_gCurrentProfiler->_timeoutTimer invalidate]; - [_gCurrentProfiler stop]; - _gCurrentProfiler->_truncationReason = reason; -# if SENTRY_HAS_UIKIT - [SentryDependencyContainer.sharedInstance.framesTracker resetProfilingTimestamps]; -# endif // SENTRY_HAS_UIKIT + [_timeoutTimer invalidate]; + [_metricProfiler stop]; + _truncationReason = reason; + + if (![self isRunning]) { + SENTRY_LOG_WARN(@"Profiler is not currently running."); + return; + } + + _profiler->stopSampling(); + SENTRY_LOG_DEBUG(@"Stopped profiler %@.", self); } - (void)startMetricProfiler @@ -490,39 +504,10 @@ - (void)start [self startMetricProfiler]; } -- (void)stop -{ - if (_profiler == nullptr) { - SENTRY_LOG_WARN(@"No profiler instance found."); - return; - } - if (!_profiler->isSampling()) { - SENTRY_LOG_WARN(@"Profiler is not currently sampling."); - return; - } - - _profiler->stopSampling(); - [_metricProfiler stop]; - SENTRY_LOG_DEBUG(@"Stopped profiler %@.", self); -} - -+ (SentryEnvelopeItem *)envelopeItemForProfileData:(NSDictionary *)profile - profileID:(SentryId *)profileID -{ - const auto JSONData = [SentrySerialization dataWithJSONObject:profile]; - if (JSONData == nil) { - SENTRY_LOG_DEBUG(@"Failed to encode profile to JSON."); - return nil; - } - - const auto header = [[SentryEnvelopeItemHeader alloc] initWithType:SentryEnvelopeItemTypeProfile - length:JSONData.length]; - return [[SentryEnvelopeItem alloc] initWithHeader:header data:JSONData]; -} - - (BOOL)isRunning { if (_profiler == nullptr) { + SENTRY_LOG_WARN(@"No profiler instance found."); return NO; } return _profiler->isSampling(); diff --git a/Sources/Sentry/SentryScreenFrames.m b/Sources/Sentry/SentryScreenFrames.m index c019a06af98..d62fcb54e9c 100644 --- a/Sources/Sentry/SentryScreenFrames.m +++ b/Sources/Sentry/SentryScreenFrames.m @@ -43,6 +43,17 @@ - (instancetype)initWithTotal:(NSUInteger)total return self; } + +- (nonnull id)copyWithZone:(nullable NSZone *)zone +{ + return [[SentryScreenFrames allocWithZone:zone] initWithTotal:_total + frozen:_frozen + slow:_slow + slowFrameTimestamps:[_slowFrameTimestamps copy] + frozenFrameTimestamps:[_frozenFrameTimestamps copy] + frameRateTimestamps:[_frameRateTimestamps copy]]; +} + # endif // SENTRY_TARGET_PROFILING_SUPPORTED @end diff --git a/Sources/Sentry/SentryTracer.m b/Sources/Sentry/SentryTracer.m index a866617ced0..f9009ff3817 100644 --- a/Sources/Sentry/SentryTracer.m +++ b/Sources/Sentry/SentryTracer.m @@ -151,8 +151,7 @@ - (instancetype)initWithTransactionContext:(SentryTransactionContext *)transacti if (_configuration.profilesSamplerDecision.decision == kSentrySampleDecisionYes) { _isProfiling = YES; _startSystemTime = SentryCurrentDate.systemTime; - [SentryProfiler startWithHub:hub]; - trackTracerWithID(self.traceId); + [SentryProfiler startWithHub:hub tracer:self]; } #endif // SENTRY_TARGET_PROFILING_SUPPORTED @@ -515,13 +514,12 @@ - (void)captureTransactionWithProfile:(SentryTransaction *)transaction { SentryEnvelopeItem *profileEnvelopeItem = [SentryProfiler createProfilingEnvelopeItemForTransaction:transaction]; + if (!profileEnvelopeItem) { [_hub captureTransaction:transaction withScope:_hub.scope]; return; } - stopTrackingTracerWithID(self.traceId, ^{ [SentryProfiler stop]; }); - SENTRY_LOG_DEBUG(@"Capturing transaction with profiling data attached."); [_hub captureTransaction:transaction withScope:_hub.scope @@ -806,9 +804,9 @@ - (NSDate *)originalStartTimestamp } #if SENTRY_TARGET_PROFILING_SUPPORTED && (defined(TEST) || defined(TESTCI)) -// this just calls through to SentryTracerConcurrency.resetConcurrencyTracking(). we have to do this -// through SentryTracer because SentryTracerConcurrency cannot be included in test targets via ObjC -// bridging headers because it contains C++. +// this just calls through to SentryTracerConcurrency.resetConcurrencyTracking(). we have to +// do this through SentryTracer because SentryTracerConcurrency cannot be included in test +// targets via ObjC bridging headers because it contains C++. + (void)resetConcurrencyTracking { resetConcurrencyTracking(); diff --git a/Sources/Sentry/SentryTracerConcurrency.mm b/Sources/Sentry/SentryTracerConcurrency.mm index 7c4fd052338..73aec619826 100644 --- a/Sources/Sentry/SentryTracerConcurrency.mm +++ b/Sources/Sentry/SentryTracerConcurrency.mm @@ -1,41 +1,107 @@ #import "SentryTracerConcurrency.h" -#import "SentryId.h" -#import "SentryLog.h" -#include #if SENTRY_TARGET_PROFILING_SUPPORTED -static NSMutableSet *_gInFlightTraceIDs; +# import "SentryId.h" +# import "SentryLog.h" +# import "SentryProfiler+Private.h" +# import "SentryTracer.h" +# include + +# if SENTRY_HAS_UIKIT +# import "SentryDependencyContainer.h" +# import "SentryFramesTracker.h" +# import "SentryScreenFrames.h" +# endif // SENTRY_HAS_UIKIT + +/** + * a mapping of profilers to the tracers that started them that are still in-flight and will need to + * query them for their profiling data when they finish. this helps resolve the incongruity between + * the different timeout durations between tracers (500s) and profilers (30s), where a transaction + * may start a profiler that then times out, and then a new transaction starts a new profiler, and + * we must keep the aborted one around until its associated transaction finishes. + */ +static NSMutableDictionary *> *_gProfilersToTracers; + +/** provided for fast access to a profiler given a tracer */ +static NSMutableDictionary + *_gTracersToProfilers; + std::mutex _gStateLock; void -trackTracerWithID(SentryId *traceID) +trackProfilerForTracer(SentryProfiler *profiler, SentryTracer *tracer) { std::lock_guard l(_gStateLock); - if (_gInFlightTraceIDs == nil) { - _gInFlightTraceIDs = [NSMutableSet set]; + const auto profilerKey = profiler.profileId.sentryIdString; + const auto tracerKey = tracer.traceId.sentryIdString; + + SENTRY_LOG_DEBUG( + @"Tracking relationship between profiler id %@ and tracer id %@", profilerKey, tracerKey); + + NSCAssert((_gProfilersToTracers == nil && _gTracersToProfilers == nil) + || (_gProfilersToTracers != nil && _gTracersToProfilers != nil), + @"Both structures must be initialized simultaneously."); + + if (_gProfilersToTracers == nil) { + _gProfilersToTracers = [NSMutableDictionary *> dictionaryWithObject:[NSMutableSet setWithObject:tracer] + forKey:profilerKey]; + _gTracersToProfilers = + [NSMutableDictionary + dictionaryWithObject:profiler + forKey:tracerKey]; + return; } - const auto idString = traceID.sentryIdString; - SENTRY_LOG_DEBUG(@"Adding tracer id %@", idString); - [_gInFlightTraceIDs addObject:idString]; + + if (_gProfilersToTracers[profilerKey] == nil) { + _gProfilersToTracers[profilerKey] = [NSMutableSet setWithObject:tracer]; + } else { + [_gProfilersToTracers[profilerKey] addObject:tracer]; + } + + _gTracersToProfilers[tracerKey] = profiler; } -void -stopTrackingTracerWithID(SentryId *traceID, SentryConcurrentTransactionCleanupBlock cleanup) +SentryProfiler *_Nullable profilerForFinishedTracer(SentryTracer *tracer) { std::lock_guard l(_gStateLock); - const auto idString = traceID.sentryIdString; - SENTRY_LOG_DEBUG(@"Removing trace id %@", idString); - [_gInFlightTraceIDs removeObject:idString]; - if (_gInFlightTraceIDs.count == 0) { - SENTRY_LOG_DEBUG(@"Last in flight tracer completed, performing cleanup."); - cleanup(); - } else { - SENTRY_LOG_DEBUG(@"Waiting on %lu other tracers to complete: %@.", _gInFlightTraceIDs.count, - _gInFlightTraceIDs); + NSCAssert(_gTracersToProfilers != nil && _gProfilersToTracers != nil, + @"Structures should have already been initialized by the time they are being queried"); + + const auto tracerKey = tracer.traceId.sentryIdString; + const auto profiler = _gTracersToProfilers[tracerKey]; + + NSCAssert( + profiler != nil, @"Expected a profiler to be associated with tracer id %@.", tracerKey); + if (profiler == nil) { + SENTRY_LOG_WARN(@"Could not find a profiler associated with tracer id %@.", tracerKey); + return nil; + } + + const auto profilerKey = profiler.profileId.sentryIdString; + + [_gTracersToProfilers removeObjectForKey:tracerKey]; + [_gProfilersToTracers[profilerKey] removeObject:tracer]; + if ([_gProfilersToTracers[profilerKey] count] == 0) { + [_gProfilersToTracers removeObjectForKey:profilerKey]; + if ([profiler isRunning]) { + [profiler stopForReason:SentryProfilerTruncationReasonNormal]; + } } + +# if SENTRY_HAS_UIKIT + profiler._screenFrameData = + [SentryDependencyContainer.sharedInstance.framesTracker.currentFrames copy]; + if (_gProfilersToTracers.count == 0) { + [SentryDependencyContainer.sharedInstance.framesTracker resetProfilingTimestamps]; + } +# endif // SENTRY_HAS_UIKIT + + return profiler; } # if defined(TEST) || defined(TESTCI) @@ -43,7 +109,8 @@ resetConcurrencyTracking() { std::lock_guard l(_gStateLock); - [_gInFlightTraceIDs removeAllObjects]; + [_gTracersToProfilers removeAllObjects]; + [_gProfilersToTracers removeAllObjects]; } # endif // defined(TEST) || defined(TESTCI) diff --git a/Sources/Sentry/include/HybridPublic/SentryScreenFrames.h b/Sources/Sentry/include/HybridPublic/SentryScreenFrames.h index a0116b76a31..e113a6dccc4 100644 --- a/Sources/Sentry/include/HybridPublic/SentryScreenFrames.h +++ b/Sources/Sentry/include/HybridPublic/SentryScreenFrames.h @@ -10,6 +10,9 @@ typedef NSArray *> SentryFrameInfoTimeSerie # endif // SENTRY_TARGET_PROFILING_SUPPORTED @interface SentryScreenFrames : NSObject +# if SENTRY_TARGET_PROFILING_SUPPORTED + +# endif // SENTRY_TARGET_PROFILING_SUPPORTED SENTRY_NO_INIT - (instancetype)initWithTotal:(NSUInteger)total frozen:(NSUInteger)frozen slow:(NSUInteger)slow; diff --git a/Sources/Sentry/include/SentryNSNotificationCenterWrapper.h b/Sources/Sentry/include/SentryNSNotificationCenterWrapper.h index 070f03384be..96dca589d97 100644 --- a/Sources/Sentry/include/SentryNSNotificationCenterWrapper.h +++ b/Sources/Sentry/include/SentryNSNotificationCenterWrapper.h @@ -21,17 +21,17 @@ NS_ASSUME_NONNULL_BEGIN - (void)addObserver:(id)observer selector:(SEL)aSelector name:(NSNotificationName)aName - object:(id)anObject; + object:(nullable id)anObject; - (void)addObserver:(id)observer selector:(SEL)aSelector name:(NSNotificationName)aName; -- (void)removeObserver:(id)observer name:(NSNotificationName)aName object:(id)anObject; +- (void)removeObserver:(id)observer name:(NSNotificationName)aName object:(nullable id)anObject; - (void)removeObserver:(id)observer name:(NSNotificationName)aName; - (void)removeObserver:(id)observer; -- (void)postNotificationName:(NSNotificationName)aName object:(id)anObject; +- (void)postNotificationName:(NSNotificationName)aName object:(nullable id)anObject; NS_ASSUME_NONNULL_END diff --git a/Sources/Sentry/include/SentryProfiler+Private.h b/Sources/Sentry/include/SentryProfiler+Private.h index 6f402ca75e4..aa84ef3c3e9 100644 --- a/Sources/Sentry/include/SentryProfiler+Private.h +++ b/Sources/Sentry/include/SentryProfiler+Private.h @@ -7,6 +7,9 @@ @class SentryId; @class SentryProfilerState; @class SentrySample; +# if SENTRY_HAS_UIKIT +@class SentryScreenFrames; +# endif // SENTRY_HAS_UIKIT @class SentryTransaction; NS_ASSUME_NONNULL_BEGIN @@ -14,12 +17,20 @@ NS_ASSUME_NONNULL_BEGIN NSDictionary *serializedProfileData(NSDictionary *profileData, SentryTransaction *transaction, SentryId *profileID, NSString *truncationReason, NSString *environment, NSString *release, NSDictionary *serializedMetrics, - NSArray *debugMeta, SentryHub *hub); + NSArray *debugMeta, SentryHub *hub +# if SENTRY_HAS_UIKIT + , + SentryScreenFrames *gpuData +# endif // SENTRY_HAS_UIKIT +); @interface SentryProfiler () @property (strong, nonatomic) SentryProfilerState *_state; +# if SENTRY_HAS_UIKIT +@property (strong, nonatomic) SentryScreenFrames *_screenFrameData; +# endif // SENTRY_HAS_UIKIT @end diff --git a/Sources/Sentry/include/SentryProfiler.h b/Sources/Sentry/include/SentryProfiler.h index a7e9c01eb4f..04bcaa5e428 100644 --- a/Sources/Sentry/include/SentryProfiler.h +++ b/Sources/Sentry/include/SentryProfiler.h @@ -39,17 +39,30 @@ SENTRY_EXTERN_C_END */ @interface SentryProfiler : NSObject +@property (strong, nonatomic) SentryId *profileId; + /** - * Start the profiler, if it isn't already running. + * Start a profiler, if one isn't already running. */ -+ (void)startWithHub:(SentryHub *)hub; ++ (void)startWithHub:(SentryHub *)hub tracer:(SentryTracer *)tracer; /** * Stop the profiler if it is running. */ -+ (void)stop; +- (void)stopForReason:(SentryProfilerTruncationReason)reason; + +/** + * Whether the profiler instance is currently running. If not, then it probably timed out or aborted + * due to app backgrounding and is being kept alive while its associated transactions finish so they + * can query for its profile data. */ +- (BOOL)isRunning; -+ (BOOL)isRunning; +/** + * Whether there is any profiler that is currently running. A convenience method to query for this + * information from other SDK components that don't have access to specific @c SentryProfiler + * instances. + */ ++ (BOOL)isCurrentlyProfiling; /** * Given a transaction, return an envelope item containing any corresponding profile data to be diff --git a/Sources/Sentry/include/SentryTracerConcurrency.h b/Sources/Sentry/include/SentryTracerConcurrency.h index 9710f5df41d..6c0b60f169e 100644 --- a/Sources/Sentry/include/SentryTracerConcurrency.h +++ b/Sources/Sentry/include/SentryTracerConcurrency.h @@ -2,7 +2,8 @@ #import "SentryProfilingConditionals.h" #import -@class SentryId; +@class SentryProfiler; +@class SentryTracer; #if SENTRY_TARGET_PROFILING_SUPPORTED @@ -10,17 +11,19 @@ NS_ASSUME_NONNULL_BEGIN SENTRY_EXTERN_C_BEGIN -typedef void (^SentryConcurrentTransactionCleanupBlock)(void); - -/** Track the tracer with specified ID to help with operations that need to know about all in-flight - * concurrent tracers. */ -void trackTracerWithID(SentryId *traceID); +/** + * Associate the provided profiler and tracer so that profiling data may be retrieved by the tracer + * when it is ready to transmit its envelope. + */ +void trackProfilerForTracer(SentryProfiler *profiler, SentryTracer *tracer); /** - * Stop tracking the tracer with the specified ID, and if it was the last concurrent tracer in - * flight, perform the cleanup actions. + * Return the profiler instance associated with the tracer. If it was the last tracer for the + * associated profiler, stop that profiler. Copy any recorded @c SentryScreenFrames data into the + * profiler instance, and if this is the last profiler being tracked, reset the + * @c SentryFramesTracker data. */ -void stopTrackingTracerWithID(SentryId *traceID, SentryConcurrentTransactionCleanupBlock cleanup); +SentryProfiler *_Nullable profilerForFinishedTracer(SentryTracer *tracer); # if defined(TEST) || defined(TESTCI) void resetConcurrencyTracking(void); diff --git a/Tests/SentryProfilerTests/SentryProfilerSwiftTests.swift b/Tests/SentryProfilerTests/SentryProfilerSwiftTests.swift index 63939e14e57..b84a9b9f4cc 100644 --- a/Tests/SentryProfilerTests/SentryProfilerSwiftTests.swift +++ b/Tests/SentryProfilerTests/SentryProfilerSwiftTests.swift @@ -278,31 +278,35 @@ class SentryProfilerSwiftTests: XCTestCase { /// profiler B |-------| <- normal finish /// ``` func testConcurrentSpansWithTimeout() throws { + // start span A and mock profile data for it let spanA = try fixture.newTransaction() fixture.currentDateProvider.advanceBy(nanoseconds: 1.toNanoSeconds()) - addMockSamples() + let expectedAddressesA: [NSNumber] = [0x1, 0x2, 0x3] + let expectedThreadMetadataA = ThreadMetadata(id: 1, priority: 2, name: "test-thread1") + let expectedQueueMetadataA = QueueMetadata(address: 3, label: "test-queue1") + addMockSamples(threadMetadata: expectedThreadMetadataA, queueMetadata: expectedQueueMetadataA, addresses: expectedAddressesA) + + // time out profiler for span A fixture.currentDateProvider.advanceBy(nanoseconds: 30.toNanoSeconds()) fixture.timeoutTimerFactory.fire() fixture.currentDateProvider.advanceBy(nanoseconds: 0.5.toNanoSeconds()) + // start span B and mock profile data for it let spanB = try fixture.newTransaction() fixture.currentDateProvider.advanceBy(nanoseconds: 0.5.toNanoSeconds()) - addMockSamples() + let expectedAddressesB: [NSNumber] = [0x7, 0x8, 0x9] + let expectedThreadMetadataB = ThreadMetadata(id: 4, priority: 5, name: "test-thread2") + let expectedQueueMetadataB = QueueMetadata(address: 6, label: "test-queue2") + addMockSamples(threadMetadata: expectedThreadMetadataB, queueMetadata: expectedQueueMetadataB, addresses: expectedAddressesB) + // finish span B and check profile data spanB.finish() - try self.assertValidProfileData() + try self.assertValidProfileData(expectedAddresses: expectedAddressesB, expectedThreadMetadata: [expectedThreadMetadataB], expectedQueueMetadata: [expectedQueueMetadataB]) + // finish span A and check profile data spanA.finish() - try self.assertValidProfileData() - } - - /** - * We received a report of unbounded memory growth from a customer. Was able to reproduce by endlessly starting transactions that go on to timeout, thereby also forcing the profiler to timeout. But, doing it on a nonmain queue meant that the timeout timer in the profiler would never fire. The fix was to schedule that timer on a dispatch to the main queue. - */ - func testRepeatedTransactionTimeoutsFromBgQueue() { - let state = SentryProfilerState() - SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: 1, threadPriority: 2, threadName: "test", queueAddress: 1, queueLabel: "test", addresses: [0x1, 0x2, 0x3]) + try self.assertValidProfileData(expectedAddresses: expectedAddressesA, expectedThreadMetadata: [expectedThreadMetadataA], expectedQueueMetadata: [expectedQueueMetadataA]) } func testProfileTimeoutTimer() throws { @@ -405,13 +409,14 @@ private extension SentryProfilerSwiftTests { return try XCTUnwrap(envelope.event as? Transaction) } - func addMockSamples() { + func addMockSamples(threadMetadata: ThreadMetadata = ThreadMetadata(id: 1, priority: 2, name: "test-thread"), queueMetadata: QueueMetadata = QueueMetadata(address: 3, label: "test-queue"), addresses: [NSNumber] = [0x3, 0x4, 0x5]) { let state = SentryProfiler.getCurrent()._state - SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: 1, threadPriority: 2, threadName: "test-thread", queueAddress: 3, queueLabel: "test-queue", addresses: [0x3, 0x4, 0x5]) fixture.currentDateProvider.advanceBy(nanoseconds: 1) - SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: 1, threadPriority: 2, threadName: "test-thread", queueAddress: 3, queueLabel: "test-queue", addresses: [0x3, 0x4, 0x5]) + SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: threadMetadata.id, threadPriority: threadMetadata.priority, threadName: threadMetadata.name, queueAddress: queueMetadata.address, queueLabel: queueMetadata.label, addresses: addresses) fixture.currentDateProvider.advanceBy(nanoseconds: 1) - SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: 1, threadPriority: 2, threadName: "test-thread", queueAddress: 3, queueLabel: "test-queue", addresses: [0x3, 0x4, 0x5]) + SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: threadMetadata.id, threadPriority: threadMetadata.priority, threadName: threadMetadata.name, queueAddress: queueMetadata.address, queueLabel: queueMetadata.label, addresses: addresses) + fixture.currentDateProvider.advanceBy(nanoseconds: 1) + SentryProfilerMocksSwiftCompatible.appendMockBacktrace(to: state, threadID: threadMetadata.id, threadPriority: threadMetadata.priority, threadName: threadMetadata.name, queueAddress: queueMetadata.address, queueLabel: queueMetadata.label, addresses: addresses) } func performTest(transactionEnvironment: String = kSentryDefaultEnvironment, shouldTimeOut: Bool = false, launchType: SentryAppStartType? = nil, prewarmed: Bool = false) throws { @@ -427,10 +432,18 @@ private extension SentryProfilerSwiftTests { addMockSamples() fixture.currentDateProvider.advance(by: 31) if shouldTimeOut { - fixture.timeoutTimerFactory.fire() + DispatchQueue.main.async { + self.fixture.timeoutTimerFactory.fire() + } } - span.finish() + let exp = expectation(description: "finished span") + DispatchQueue.main.async { + span.finish() + exp.fulfill() + } + + waitForExpectations(timeout: 1) try self.assertValidProfileData(transactionEnvironment: transactionEnvironment, shouldTimeout: shouldTimeOut) } @@ -517,7 +530,18 @@ private extension SentryProfilerSwiftTests { XCTAssertLessThanOrEqual(timestampNumericValue, transactionDuration) } - func assertValidProfileData(transactionEnvironment: String = kSentryDefaultEnvironment, shouldTimeout: Bool = false) throws { + struct ThreadMetadata { + var id: UInt64 + var priority: Int32 + var name: String + } + + struct QueueMetadata { + var address: UInt64 + var label: String + } + + func assertValidProfileData(transactionEnvironment: String = kSentryDefaultEnvironment, shouldTimeout: Bool = false, expectedAddresses: [NSNumber]? = nil, expectedThreadMetadata: [ThreadMetadata]? = nil, expectedQueueMetadata: [QueueMetadata]? = nil) throws { let data = try getLatestProfileData() let profile = try XCTUnwrap(try JSONSerialization.jsonObject(with: data) as? [String: Any]) @@ -566,11 +590,29 @@ private extension SentryProfilerSwiftTests { let sampledProfile = try XCTUnwrap(profile["profile"] as? [String: Any]) let threadMetadata = try XCTUnwrap(sampledProfile["thread_metadata"] as? [String: [String: Any]]) - let queueMetadata = try XCTUnwrap(sampledProfile["queue_metadata"] as? [String: Any]) + let queueMetadata = try XCTUnwrap(sampledProfile["queue_metadata"] as? [String: [String: Any]]) XCTAssertFalse(threadMetadata.isEmpty) - XCTAssertFalse(try threadMetadata.values.compactMap { $0["priority"] }.filter { try XCTUnwrap($0 as? Int) > 0 }.isEmpty) + if let expectedThreadMetadata = expectedThreadMetadata { + try expectedThreadMetadata.forEach { + let actualThreadMetadata = try XCTUnwrap(threadMetadata["\($0.id)"]) + let actualThreadPriority = try XCTUnwrap(actualThreadMetadata["priority"] as? Int32) + XCTAssertEqual(actualThreadPriority, $0.priority) + let actualThreadName = try XCTUnwrap(actualThreadMetadata["name"] as? String) + XCTAssertEqual(actualThreadName, $0.name) + } + } else { + XCTAssertFalse(try threadMetadata.values.compactMap { $0["priority"] }.filter { try XCTUnwrap($0 as? Int) > 0 }.isEmpty) + } XCTAssertFalse(queueMetadata.isEmpty) - XCTAssertFalse(try XCTUnwrap(try XCTUnwrap(queueMetadata.first?.value as? [String: Any])["label"] as? String).isEmpty) + if let expectedQueueMetadata = expectedQueueMetadata { + try expectedQueueMetadata.forEach { + let actualQueueMetadata = try XCTUnwrap(queueMetadata[sentry_formatHexAddressUInt64($0.address)]) + let actualQueueLabel = try XCTUnwrap(actualQueueMetadata["label"] as? String) + XCTAssertEqual(actualQueueLabel, $0.label) + } + } else { + XCTAssertFalse(try XCTUnwrap(try XCTUnwrap(queueMetadata.first?.value)["label"] as? String).isEmpty) + } let samples = try XCTUnwrap(sampledProfile["samples"] as? [[String: Any]]) XCTAssertFalse(samples.isEmpty) diff --git a/Tests/SentryProfilerTests/SentryProfilerTests.mm b/Tests/SentryProfilerTests/SentryProfilerTests.mm index bbad9da551b..0113d0bf210 100644 --- a/Tests/SentryProfilerTests/SentryProfilerTests.mm +++ b/Tests/SentryProfilerTests/SentryProfilerTests.mm @@ -7,6 +7,7 @@ #import "SentryProfilerMocks.h" #import "SentryProfilerState+ObjCpp.h" #import "SentryProfilingConditionals.h" +#import "SentryScreenFrames.h" #import "SentryThread.h" #import "SentryTransaction.h" #import "SentryTransactionContext+Private.h" @@ -189,7 +190,17 @@ - (void)testProfilerMutationDuringSerialization const auto profileID = [[SentryId alloc] init]; const auto serialization = serializedProfileData(profileData, transaction, profileID, profilerTruncationReasonName(SentryProfilerTruncationReasonNormal), @"test", @"someRelease", - @{}, @[], [[SentryHub alloc] initWithClient:nil andScope:nil]); + @{}, @[], [[SentryHub alloc] initWithClient:nil andScope:nil] +# if SENTRY_HAS_UIKIT + , + [[SentryScreenFrames alloc] initWithTotal:5 + frozen:6 + slow:7 + slowFrameTimestamps:@[] + frozenFrameTimestamps:@[] + frameRateTimestamps:@[]] +# endif // SENTRY_HAS_UIKIT + ); // cause the data structures to be modified again: add new addresses { diff --git a/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift b/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift index c4046371f16..ac9dae63516 100644 --- a/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift +++ b/Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift @@ -8,6 +8,8 @@ class SentryFramesTrackerTests: XCTestCase { var displayLinkWrapper: TestDisplayLinkWrapper var queue: DispatchQueue + lazy var hub = TestHub(client: nil, andScope: nil) + lazy var tracer = SentryTracer(transactionContext: TransactionContext(name: "test transaction", operation: "test operation"), hub: hub) init() { displayLinkWrapper = TestDisplayLinkWrapper() @@ -25,15 +27,13 @@ class SentryFramesTrackerTests: XCTestCase { #if os(iOS) || os(macOS) || targetEnvironment(macCatalyst) // the profiler must be running for the frames tracker to record frame rate info etc, validated in assertProfilingData() - SentryProfiler.start(with: TestHub(client: nil, andScope: nil)) + SentryProfiler.start(with: fixture.hub, tracer: fixture.tracer) #endif } override func tearDown() { super.tearDown() -#if os(iOS) || os(macOS) || targetEnvironment(macCatalyst) - SentryProfiler.stop() -#endif + clearTestState() } func testIsNotRunning_WhenNotStarted() { diff --git a/Tests/SentryTests/Transaction/SentryTracerObjCTests.m b/Tests/SentryTests/Transaction/SentryTracerObjCTests.m index 1f04fb2a853..a9c009899a2 100644 --- a/Tests/SentryTests/Transaction/SentryTracerObjCTests.m +++ b/Tests/SentryTests/Transaction/SentryTracerObjCTests.m @@ -79,15 +79,15 @@ - (void)testConcurrentTracerProfiling XCTestExpectation *exp = [self expectationWithDescription:@"finishes tracers"]; dispatch_after( dispatch_time(DISPATCH_TIME_NOW, (int64_t)(1 * NSEC_PER_SEC)), dispatch_get_main_queue(), ^{ - XCTAssert([SentryProfiler isRunning]); + XCTAssert([SentryProfiler isCurrentlyProfiling]); [tracer1 finish]; - XCTAssert([SentryProfiler isRunning]); + XCTAssert([SentryProfiler isCurrentlyProfiling]); [tracer2 finish]; - XCTAssertFalse([SentryProfiler isRunning]); + XCTAssertFalse([SentryProfiler isCurrentlyProfiling]); [exp fulfill]; });