feat: Add frames delay to transactions

CHANGELOG.md

@@ -4,6 +4,7 @@
 
 ## Features
 
+- Add frames delay to transactions (#3487)
 - Add slow and frozen frames to spans (#3450, #3478)
 
 ## 8.17.1

Sentry.xcodeproj/project.pbxproj

@@ -81,6 +81,8 @@
 		622C08DB29E554B9002571D4 /* SentrySpanContext+Private.h in Headers */ = {isa = PBXBuildFile; fileRef = 622C08D929E554B9002571D4 /* SentrySpanContext+Private.h */; };
 		623C45B02A651D8200D9E88B /* SentryCoreDataTracker+Test.m in Sources */ = {isa = PBXBuildFile; fileRef = 623C45AF2A651D8200D9E88B /* SentryCoreDataTracker+Test.m */; };
 		627E7589299F6FE40085504D /* SentryInternalDefines.h in Headers */ = {isa = PBXBuildFile; fileRef = 627E7588299F6FE40085504D /* SentryInternalDefines.h */; };
+		62862B1C2B1DDBC8009B16E3 /* SentryDelayedFrame.h in Headers */ = {isa = PBXBuildFile; fileRef = 62862B1B2B1DDBC8009B16E3 /* SentryDelayedFrame.h */; };
+		62862B1E2B1DDC35009B16E3 /* SentryDelayedFrame.m in Sources */ = {isa = PBXBuildFile; fileRef = 62862B1D2B1DDC35009B16E3 /* SentryDelayedFrame.m */; };
 		62885DA729E946B100554F38 /* TestConncurrentModifications.swift in Sources */ = {isa = PBXBuildFile; fileRef = 62885DA629E946B100554F38 /* TestConncurrentModifications.swift */; };
 		62950F1029E7FE0100A42624 /* SentryTransactionContextTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 62950F0F29E7FE0100A42624 /* SentryTransactionContextTests.swift */; };
 		629690532AD3E060000185FA /* SentryReachabilitySwiftTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 629690522AD3E060000185FA /* SentryReachabilitySwiftTests.swift */; };
@@ -91,6 +93,8 @@
 		62B86CFC29F052BB008F3947 /* SentryTestLogConfig.m in Sources */ = {isa = PBXBuildFile; fileRef = 62B86CFB29F052BB008F3947 /* SentryTestLogConfig.m */; };
 		62C25C862B075F4900C68CBD /* TestOptions.swift in Sources */ = {isa = PBXBuildFile; fileRef = 62C25C852B075F4900C68CBD /* TestOptions.swift */; };
 		62C3168B2B1F865A000D7031 /* SentryTimeSwiftTests.swift in Sources */ = {isa = PBXBuildFile; fileRef = 62C3168A2B1F865A000D7031 /* SentryTimeSwiftTests.swift */; };
+		62C316812B1F2E93000D7031 /* SentryDelayedFramesTracker.h in Headers */ = {isa = PBXBuildFile; fileRef = 62C316802B1F2E93000D7031 /* SentryDelayedFramesTracker.h */; };
+		62C316832B1F2EA1000D7031 /* SentryDelayedFramesTracker.m in Sources */ = {isa = PBXBuildFile; fileRef = 62C316822B1F2EA1000D7031 /* SentryDelayedFramesTracker.m */; };
 		62E081A929ED4260000F69FC /* SentryBreadcrumbDelegate.h in Headers */ = {isa = PBXBuildFile; fileRef = 62E081A829ED4260000F69FC /* SentryBreadcrumbDelegate.h */; };
 		62E081AB29ED4322000F69FC /* SentryBreadcrumbTestDelegate.swift in Sources */ = {isa = PBXBuildFile; fileRef = 62E081AA29ED4322000F69FC /* SentryBreadcrumbTestDelegate.swift */; };
 		62F226B729A37C120038080D /* SentryBooleanSerialization.m in Sources */ = {isa = PBXBuildFile; fileRef = 62F226B629A37C120038080D /* SentryBooleanSerialization.m */; };
@@ -995,6 +999,8 @@
 		623C45AE2A651C4500D9E88B /* SentryCoreDataTracker+Test.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = "SentryCoreDataTracker+Test.h"; sourceTree = "<group>"; };
 		623C45AF2A651D8200D9E88B /* SentryCoreDataTracker+Test.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = "SentryCoreDataTracker+Test.m"; sourceTree = "<group>"; };
 		627E7588299F6FE40085504D /* SentryInternalDefines.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryInternalDefines.h; path = include/SentryInternalDefines.h; sourceTree = "<group>"; };
+		62862B1B2B1DDBC8009B16E3 /* SentryDelayedFrame.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryDelayedFrame.h; path = include/SentryDelayedFrame.h; sourceTree = "<group>"; };
+		62862B1D2B1DDC35009B16E3 /* SentryDelayedFrame.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryDelayedFrame.m; sourceTree = "<group>"; };
 		62885DA629E946B100554F38 /* TestConncurrentModifications.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = TestConncurrentModifications.swift; sourceTree = "<group>"; };
 		62950F0F29E7FE0100A42624 /* SentryTransactionContextTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryTransactionContextTests.swift; sourceTree = "<group>"; };
 		629690522AD3E060000185FA /* SentryReachabilitySwiftTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryReachabilitySwiftTests.swift; sourceTree = "<group>"; };
@@ -1004,6 +1010,8 @@
 		62B86CFB29F052BB008F3947 /* SentryTestLogConfig.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryTestLogConfig.m; sourceTree = "<group>"; };
 		62C25C852B075F4900C68CBD /* TestOptions.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = TestOptions.swift; sourceTree = "<group>"; };
 		62C3168A2B1F865A000D7031 /* SentryTimeSwiftTests.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryTimeSwiftTests.swift; sourceTree = "<group>"; };
+		62C316802B1F2E93000D7031 /* SentryDelayedFramesTracker.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryDelayedFramesTracker.h; path = include/SentryDelayedFramesTracker.h; sourceTree = "<group>"; };
+		62C316822B1F2EA1000D7031 /* SentryDelayedFramesTracker.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryDelayedFramesTracker.m; sourceTree = "<group>"; };
 		62E081A829ED4260000F69FC /* SentryBreadcrumbDelegate.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; name = SentryBreadcrumbDelegate.h; path = include/SentryBreadcrumbDelegate.h; sourceTree = "<group>"; };
 		62E081AA29ED4322000F69FC /* SentryBreadcrumbTestDelegate.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SentryBreadcrumbTestDelegate.swift; sourceTree = "<group>"; };
 		62F226B629A37C120038080D /* SentryBooleanSerialization.m */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.objc; path = SentryBooleanSerialization.m; sourceTree = "<group>"; };
@@ -2943,6 +2951,10 @@
 				7B6C5EDD264E8DF00010D138 /* SentryFramesTracker.m */,
 				7B7A599426B692540060A676 /* SentryScreenFrames.h */,
 				7B7A599626B692F00060A676 /* SentryScreenFrames.m */,
+				62862B1B2B1DDBC8009B16E3 /* SentryDelayedFrame.h */,
+				62862B1D2B1DDC35009B16E3 /* SentryDelayedFrame.m */,
+				62C316802B1F2E93000D7031 /* SentryDelayedFramesTracker.h */,
+				62C316822B1F2EA1000D7031 /* SentryDelayedFramesTracker.m */,
 			);
 			name = FramesTracking;
 			sourceTree = "<group>";
@@ -3573,6 +3585,7 @@
 				63B818F91EC34639002FDF4C /* SentryDebugMeta.h in Headers */,
 				6360850D1ED2AFE100E8599E /* SentryBreadcrumb.h in Headers */,
 				7BAF3DD92440AEC8008A5414 /* SentryRequestManager.h in Headers */,
+				62862B1C2B1DDBC8009B16E3 /* SentryDelayedFrame.h in Headers */,
 				627E7589299F6FE40085504D /* SentryInternalDefines.h in Headers */,
 				7BE3C77B2446111500A38442 /* SentryRateLimitParser.h in Headers */,
 				84A888FD28D9B11700C51DFD /* SentryProfiler+Private.h in Headers */,
@@ -3628,6 +3641,7 @@
 				63FE718720DA4C1100CDBAE8 /* SentryCrashReportVersion.h in Headers */,
 				0A56DA5F28ABA01B00C400D5 /* SentryTransactionContext+Private.h in Headers */,
 				8E7C98312693E1CC00E6336C /* SentryTraceHeader.h in Headers */,
+				62C316812B1F2E93000D7031 /* SentryDelayedFramesTracker.h in Headers */,
 				7BBD18912449BE9000427C76 /* SentryDefaultRateLimits.h in Headers */,
 				7B8713AE26415ADF006D6004 /* SentryAppStartTrackingIntegration.h in Headers */,
 				7B7D873224864BB900D2ECFF /* SentryCrashMachineContextWrapper.h in Headers */,
@@ -4136,6 +4150,7 @@
 				63FE712920DA4C1000CDBAE8 /* SentryCrashCPU_arm.c in Sources */,
 				03F84D3427DD4191008FE43F /* SentryThreadMetadataCache.cpp in Sources */,
 				7B88F30024BC5A7D00ADF90A /* SentrySdkInfo.m in Sources */,
+				62862B1E2B1DDC35009B16E3 /* SentryDelayedFrame.m in Sources */,
 				84AC61D729F75A98009EEF61 /* SentryDispatchFactory.m in Sources */,
 				15360CD62432832400112302 /* SentryAutoSessionTrackingIntegration.m in Sources */,
 				7B63459F280EBA7200CFA05A /* SentryUIEventTracker.m in Sources */,
@@ -4229,6 +4244,7 @@
 				03F84D3827DD4191008FE43F /* SentryBacktrace.cpp in Sources */,
 				63FE712720DA4C1000CDBAE8 /* SentryCrashThread.c in Sources */,
 				7B127B0F27CF6F4700A71ED2 /* SentryANRTrackingIntegration.m in Sources */,
+				62C316832B1F2EA1000D7031 /* SentryDelayedFramesTracker.m in Sources */,
 				D8BFE37329A3782F002E73F3 /* SentryTimeToDisplayTracker.m in Sources */,
 				15360CCF2432777500112302 /* SentrySessionTracker.m in Sources */,
 				6334314320AD9AE40077E581 /* SentryMechanism.m in Sources */,

SentryTestUtils/TestDisplayLinkWrapper.swift

@@ -1,8 +1,6 @@
 import Foundation
 
 #if os(iOS) || os(tvOS) || targetEnvironment(macCatalyst)
-/// The smallest magnitude of time that is significant to how frames are classified as normal/slow/frozen.
-let timeEpsilon = 0.001
 
 public enum GPUFrame {
     case normal
@@ -25,10 +23,12 @@ public class TestDisplayLinkWrapper: SentryDisplayLinkWrapper {
     public var currentFrameRate: FrameRate = .low
 
     private let frozenFrameThreshold = 0.7
-    private let slowestSlowFrameDuration: Double
-    private let fastestFrozenFrameDuration: Double
+    public let slowestSlowFrameDuration: Double
+    public let fastestFrozenFrameDuration: Double
 
     public var dateProvider: TestCurrentDateProvider
+    /// The smallest magnitude of time that is significant to how frames are classified as normal/slow/frozen.
+    public let timeEpsilon = 0.001
 
     public init(dateProvider: TestCurrentDateProvider = TestCurrentDateProvider()) {
         self.dateProvider = dateProvider

Sources/Sentry/SentryDelayedFrame.m

@@ -0,0 +1,25 @@
+#import "SentryDelayedFrame.h"
+
+#if SENTRY_HAS_UIKIT
+
+NS_ASSUME_NONNULL_BEGIN
+
+@implementation SentryDelayedFrame
+
+- (instancetype)initWithStartTimestamp:(uint64_t)startSystemTimestamp
+                      expectedDuration:(CFTimeInterval)expectedDuration
+                        actualDuration:(CFTimeInterval)actualDuration
+{
+    if (self = [super init]) {
+        _startSystemTimestamp = startSystemTimestamp;
+        _expectedDuration = expectedDuration;
+        _actualDuration = actualDuration;
+    }
+    return self;
+}
+
+@end
+
+NS_ASSUME_NONNULL_END
+
+#endif // SENTRY_HAS_UIKIT

Sources/Sentry/SentryDelayedFramesTracker.m

@@ -0,0 +1,196 @@
+#import "SentryDelayedFramesTracker.h"
+
+#if SENTRY_HAS_UIKIT
+
+#    import "SentryCurrentDateProvider.h"
+#    import "SentryDelayedFrame.h"
+#    import "SentryLog.h"
+#    import "SentryTime.h"
+
+NS_ASSUME_NONNULL_BEGIN
+
+@interface
+SentryDelayedFramesTracker ()
+
+@property (nonatomic, assign) CFTimeInterval keepDelayedFramesDuration;
+@property (nonatomic, strong, readonly) SentryCurrentDateProvider *dateProvider;
+@property (nonatomic, strong) NSMutableArray<SentryDelayedFrame *> *delayedFrames;
+
+@end
+
+@implementation SentryDelayedFramesTracker
+
+- (instancetype)initWithKeepDelayedFramesDuration:(CFTimeInterval)keepDelayedFramesDuration
+                                     dateProvider:(SentryCurrentDateProvider *)dateProvider
+{
+    if (self = [super init]) {
+        _keepDelayedFramesDuration = keepDelayedFramesDuration;
+        _dateProvider = dateProvider;
+        [self resetDelayedFramesTimeStamps];
+    }
+    return self;
+}
+
+- (void)resetDelayedFramesTimeStamps
+{
+    _delayedFrames = [NSMutableArray array];
+    SentryDelayedFrame *initialFrame =
+        [[SentryDelayedFrame alloc] initWithStartTimestamp:[self.dateProvider systemTime]
+                                          expectedDuration:0
+                                            actualDuration:0];
+    [_delayedFrames addObject:initialFrame];
+}
+
+- (void)recordDelayedFrame:(uint64_t)startSystemTimestamp
+          expectedDuration:(CFTimeInterval)expectedDuration
+            actualDuration:(CFTimeInterval)actualDuration
+{
+    @synchronized(self.delayedFrames) {
+        [self removeOldDelayedFrames];
+
+        SentryDelayedFrame *delayedFrame =
+            [[SentryDelayedFrame alloc] initWithStartTimestamp:startSystemTimestamp
+                                              expectedDuration:expectedDuration
+                                                actualDuration:actualDuration];
+        [self.delayedFrames addObject:delayedFrame];
+    }
+}
+
+/**
+ * Removes delayed frame that are older than current time minus `keepDelayedFramesDuration`.
+ * @note Make sure to call this in a @synchronized block.
+ */
+- (void)removeOldDelayedFrames
+{
+    u_int64_t transactionMaxDurationNS = timeIntervalToNanoseconds(_keepDelayedFramesDuration);
+
+    uint64_t removeFramesBeforeSystemTimeStamp
+        = _dateProvider.systemTime - transactionMaxDurationNS;
+    if (_dateProvider.systemTime < transactionMaxDurationNS) {
+        removeFramesBeforeSystemTimeStamp = 0;
+    }
+
+    NSUInteger left = 0;
+    NSUInteger right = self.delayedFrames.count;
+
+    while (left < right) {
+        NSUInteger mid = (left + right) / 2;
+        SentryDelayedFrame *midFrame = self.delayedFrames[mid];
+
+        uint64_t frameEndSystemTimeStamp
+            = midFrame.startSystemTimestamp + timeIntervalToNanoseconds(midFrame.actualDuration);
+        if (frameEndSystemTimeStamp >= removeFramesBeforeSystemTimeStamp) {
+            right = mid;
+        } else {
+            left = mid + 1;
+        }
+    }
+
+    [self.delayedFrames removeObjectsInRange:NSMakeRange(0, left)];
+}
+
+- (CFTimeInterval)getFramesDelay:(uint64_t)startSystemTimestamp
+              endSystemTimestamp:(uint64_t)endSystemTimestamp
+                       isRunning:(BOOL)isRunning
+              thisFrameTimestamp:(CFTimeInterval)thisFrameTimestamp
+          previousFrameTimestamp:(CFTimeInterval)previousFrameTimestamp
+              slowFrameThreshold:(CFTimeInterval)slowFrameThreshold
+{
+    CFTimeInterval cantCalculateFrameDelayReturnValue = -1.0;
+
+    if (isRunning == NO) {
+        SENTRY_LOG_DEBUG(@"Not calculating frames delay because frames tracker isn't running.");
+        return cantCalculateFrameDelayReturnValue;
+    }
+
+    if (startSystemTimestamp >= endSystemTimestamp) {
+        SENTRY_LOG_DEBUG(@"Not calculating frames delay because startSystemTimestamp is before  "
+                         @"endSystemTimestamp");
+        return cantCalculateFrameDelayReturnValue;
+    }
+
+    if (endSystemTimestamp > self.dateProvider.systemTime) {
+        SENTRY_LOG_DEBUG(
+            @"Not calculating frames delay because endSystemTimestamp is in the future.");
+        return cantCalculateFrameDelayReturnValue;
+    }
+
+    if (previousFrameTimestamp < 0) {
+        SENTRY_LOG_DEBUG(@"Not calculating frames delay because no frames yet recorded.");
+        return cantCalculateFrameDelayReturnValue;
+    }
+
+    NSArray<SentryDelayedFrame *> *frames;
+    @synchronized(self.delayedFrames) {
+        uint64_t oldestDelayedFrameStartTimestamp = UINT64_MAX;
+        SentryDelayedFrame *oldestDelayedFrame = self.delayedFrames.firstObject;
+        if (oldestDelayedFrame != nil) {
+            oldestDelayedFrameStartTimestamp = oldestDelayedFrame.startSystemTimestamp;
+        }
+
+        if (oldestDelayedFrameStartTimestamp > startSystemTimestamp) {
+            SENTRY_LOG_DEBUG(@"Not calculating frames delay because the record of delayed frames "
+                             @"doesn't go back enough in time.");
+            return cantCalculateFrameDelayReturnValue;
+        }
+
+        // Copy as late as possible to avoid allocating unnecessary memory.
+        frames = self.delayedFrames.copy;
+    }
+
+    // Check if there is an delayed frame going on but not recorded yet.
+    CFTimeInterval frameDuration = thisFrameTimestamp - previousFrameTimestamp;
+    CFTimeInterval ongoingDelayedFrame = 0.0;
+    if (frameDuration > slowFrameThreshold) {
+        ongoingDelayedFrame = frameDuration - slowFrameThreshold;
+    }
+
+    CFTimeInterval delay = ongoingDelayedFrame;
+
+    // We need to calculate the intersections of the queried TimestampInterval
+    // (startSystemTimestamp - endSystemTimestamp) with the recorded frame delays. Doing that
+    // with NSDateInterval makes things easier. Therefore, we convert the system timestamps to
+    // NSDate objects, although they don't represent the correct dates. We only need to know how
+    // long the intersections are to calculate the frame delay and not precisely when.
+
+    NSDate *startDate = [NSDate
+        dateWithTimeIntervalSinceReferenceDate:nanosecondsToTimeInterval(startSystemTimestamp)];
+    NSDate *endDate = [NSDate
+        dateWithTimeIntervalSinceReferenceDate:nanosecondsToTimeInterval(endSystemTimestamp)];
+    NSDateInterval *queryDateInterval = [[NSDateInterval alloc] initWithStartDate:startDate
+                                                                          endDate:endDate];
+
+    // Iterate in reverse order, as younger frame delays are more likely to match the queried
+    // period.
+    for (SentryDelayedFrame *frame in frames.reverseObjectEnumerator) {
+
+        uint64_t frameEndSystemTimeStamp
+            = frame.startSystemTimestamp + timeIntervalToNanoseconds(frame.actualDuration);
+        if (frameEndSystemTimeStamp < startSystemTimestamp) {
+            break;
+        }
+
+        CFTimeInterval delayStartTime
+            = nanosecondsToTimeInterval(frame.startSystemTimestamp) + frame.expectedDuration;
+        NSDate *frameDelayStartDate =
+            [NSDate dateWithTimeIntervalSinceReferenceDate:delayStartTime];
+
+        NSDateInterval *frameDelayDateInterval = [[NSDateInterval alloc]
+            initWithStartDate:frameDelayStartDate
+                     duration:(frame.actualDuration - frame.expectedDuration)];
+
+        if ([queryDateInterval intersectsDateInterval:frameDelayDateInterval]) {
+            NSDateInterval *intersection =
+                [queryDateInterval intersectionWithDateInterval:frameDelayDateInterval];
+            delay = delay + intersection.duration;
+        }
+    }
+
+    return delay;
+}
+
+@end
+
+NS_ASSUME_NONNULL_END
+
+#endif // SENTRY_HAS_UIKIT

Sources/Sentry/SentryDependencyContainer.m

@@ -26,6 +26,7 @@
 #import <SentrySwizzleWrapper.h>
 #import <SentrySysctl.h>
 #import <SentryThreadWrapper.h>
+#import <SentryTracer.h>
 
 #if SENTRY_HAS_UIKIT
 #    import "SentryFramesTracker.h"
@@ -268,7 +269,9 @@ - (SentryFramesTracker *)framesTracker
         @synchronized(sentryDependencyContainerLock) {
             if (_framesTracker == nil) {
                 _framesTracker = [[SentryFramesTracker alloc]
-                    initWithDisplayLinkWrapper:[[SentryDisplayLinkWrapper alloc] init]];
+                    initWithDisplayLinkWrapper:[[SentryDisplayLinkWrapper alloc] init]
+                                  dateProvider:self.dateProvider
+                     keepDelayedFramesDuration:SENTRY_AUTO_TRANSACTION_MAX_DURATION];
             }
         }
     }