Skip to content

Commit

Permalink
Fix high percentage of slow frames
Browse files Browse the repository at this point in the history 
The SentryFramesTracker didn't handle fps changes from
the CADisplayLink. This is fixed now by calculating the
actual frame rate as pointed out by the docs.

Fixes GH-1881, Fixes GH-1165
  • Loading branch information
@philipphofmann
philipphofmann committed Jun 24, 2022
1 parent 840f876 commit 24255b8
Show file tree
Hide file tree
Showing 12 changed files with 138 additions and 72 deletions.
16 changes: 10 additions & 6 deletions .github/workflows/saucelabs-UI-tests.yml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -49,27 +49,31 @@ jobs:
run-ui-tests-with-sauce:
name: Run UI Tests for iOS ${{ matrix.iOS }} on Sauce Labs
name: Run UI Tests for iOS ${{ matrix.suite }} on Sauce Labs
runs-on: ubuntu-latest
needs: build-ui-tests
strategy:
fail-fast: false
matrix:
include:
- xcode: "13.2"
iOS: 15
suite: "iOS-15"

# We want to test the frame tracker at 120 fps
- xcode: "13.2"
iOS: 14
suite: "iPhone-13-Pro"

- xcode: "13.2"
iOS: 13
suite: "iOS-14"

- xcode: "13.2"
suite: "iOS-13"

# iOS 12 has a failing test that we need to fix https://github.com/getsentry/sentry-cocoa/issues/1566
# iOS 11 keeps timing out and we don't know how to fix it.

- xcode: "12.5.1"
iOS: 10
suite: "iOS-10"

steps:
- uses: actions/checkout@v3
Expand All @@ -85,4 +89,4 @@ jobs:
env:
SAUCE_USERNAME: ${{ secrets.SAUCE_USERNAME }}
SAUCE_ACCESS_KEY: ${{ secrets.SAUCE_ACCESS_KEY }}
run: for i in {1..5}; do saucectl run --select-suite iOS-${{ matrix.iOS }} && break ; done
run: for i in {1..5}; do saucectl run --select-suite ${{ matrix.suite }} && break ; done
5 changes: 5 additions & 0 deletions .sauce/config.yml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,11 @@ suites:
devices:
- name: "iPhone.*"
platformVersion: "15.4"

- name: "iPhone-13-Pro"
devices:
- name: "iPhone 13 Pro"
platformVersion: "15.5"

- name: "iOS-14"
devices:
Expand Down
6 changes: 6 additions & 0 deletions CHANGELOG.md
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,11 @@
# Changelog

## Unreleased

### Fixes

- Fix high percentage of slow frames (#1915)

## 7.18.0

### Features
Expand Down
20 changes: 14 additions & 6 deletions Samples/iOS-Swift/iOS-Swift/Base.lproj/Main.storyboard
View file
Original file line number Diff line number Diff line change
@@ -1,9 +1,9 @@
<?xml version="1.0" encoding="UTF-8"?>
<document type="com.apple.InterfaceBuilder3.CocoaTouch.Storyboard.XIB" version="3.0" toolsVersion="19529" targetRuntime="iOS.CocoaTouch" propertyAccessControl="none" useAutolayout="YES" useTraitCollections="YES" useSafeAreas="YES" colorMatched="YES" initialViewController="5CD-RQ-aBU">
<document type="com.apple.InterfaceBuilder3.CocoaTouch.Storyboard.XIB" version="3.0" toolsVersion="20037" targetRuntime="iOS.CocoaTouch" propertyAccessControl="none" useAutolayout="YES" useTraitCollections="YES" useSafeAreas="YES" colorMatched="YES" initialViewController="5CD-RQ-aBU">
<device id="retina6_1" orientation="portrait" appearance="light"/>
<dependencies>
<deployment identifier="iOS"/>
<plugIn identifier="com.apple.InterfaceBuilder.IBCocoaTouchPlugin" version="19519"/>
<plugIn identifier="com.apple.InterfaceBuilder.IBCocoaTouchPlugin" version="20020"/>
<capability name="Safe area layout guides" minToolsVersion="9.0"/>
<capability name="System colors in document resources" minToolsVersion="11.0"/>
<capability name="documents saved in the Xcode 8 format" minToolsVersion="8.0"/>
Expand All @@ -18,7 +18,7 @@
<autoresizingMask key="autoresizingMask" widthSizable="YES" heightSizable="YES"/>
<subviews>
<stackView opaque="NO" contentMode="scaleAspectFit" axis="vertical" distribution="fillProportionally" translatesAutoresizingMaskIntoConstraints="NO" id="480-5y-FtF">
<rect key="frame" x="8" y="263" width="398" height="424.5"/>
<rect key="frame" x="8" y="252.5" width="398" height="445"/>
<subviews>
<stackView opaque="NO" contentMode="scaleToFill" distribution="fillProportionally" alignment="top" translatesAutoresizingMaskIntoConstraints="NO" id="VbH-LD-DBn">
<rect key="frame" x="0.0" y="0.0" width="398" height="300"/>
Expand Down Expand Up @@ -185,29 +185,36 @@
</subviews>
</stackView>
<stackView opaque="NO" contentMode="scaleToFill" axis="vertical" translatesAutoresizingMaskIntoConstraints="NO" id="UrL-kT-AJU">
<rect key="frame" x="0.0" y="300" width="398" height="124.5"/>
<rect key="frame" x="0.0" y="300" width="398" height="145"/>
<subviews>
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" text="DSN " textAlignment="natural" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="m3h-wb-Xfa">
<rect key="frame" x="8" y="32" width="382" height="20.5"/>
<fontDescription key="fontDescription" type="system" pointSize="17"/>
<nil key="textColor"/>
<nil key="highlightedColor"/>
</label>
<textField opaque="NO" contentMode="scaleToFill" contentHorizontalAlignment="left" contentVerticalAlignment="center" borderStyle="roundedRect" textAlignment="natural" minimumFontSize="17" clearButtonMode="whileEditing" translatesAutoresizingMaskIntoConstraints="NO" id="L2a-LY-eQ7">
<textField opaque="NO" contentMode="scaleToFill" ambiguous="YES" contentHorizontalAlignment="left" contentVerticalAlignment="center" borderStyle="roundedRect" textAlignment="natural" minimumFontSize="17" clearButtonMode="whileEditing" translatesAutoresizingMaskIntoConstraints="NO" id="L2a-LY-eQ7">
<rect key="frame" x="8" y="52.5" width="382" height="34"/>
<fontDescription key="fontDescription" type="system" pointSize="14"/>
<textInputTraits key="textInputTraits"/>
<connections>
<action selector="dsnChanged:" destination="BYZ-38-t0r" eventType="editingChanged" id="PSj-ja-pxV"/>
</connections>
</textField>
<button opaque="NO" contentMode="scaleToFill" contentHorizontalAlignment="left" contentVerticalAlignment="center" buttonType="system" lineBreakMode="middleTruncation" translatesAutoresizingMaskIntoConstraints="NO" id="piA-94-ut3">
<button opaque="NO" contentMode="scaleToFill" ambiguous="YES" contentHorizontalAlignment="left" contentVerticalAlignment="center" buttonType="system" lineBreakMode="middleTruncation" translatesAutoresizingMaskIntoConstraints="NO" id="piA-94-ut3">
<rect key="frame" x="8" y="86.5" width="382" height="30"/>
<state key="normal" title="Reset DSN"/>
<connections>
<action selector="resetDSN:" destination="BYZ-38-t0r" eventType="touchUpInside" id="Mc6-d3-jaa"/>
</connections>
</button>
<label opaque="NO" userInteractionEnabled="NO" contentMode="left" horizontalHuggingPriority="251" verticalHuggingPriority="251" text="Frames" textAlignment="natural" lineBreakMode="tailTruncation" baselineAdjustment="alignBaselines" adjustsFontSizeToFit="NO" translatesAutoresizingMaskIntoConstraints="NO" id="Lcm-n2-ys4" userLabel="frames">
<rect key="frame" x="8" y="116.5" width="382" height="20.5"/>
<accessibility key="accessibilityConfiguration" identifier="framesStatsLabel"/>
<fontDescription key="fontDescription" type="system" pointSize="17"/>
<nil key="textColor"/>
<nil key="highlightedColor"/>
</label>
</subviews>
<edgeInsets key="layoutMargins" top="32" left="8" bottom="8" right="8"/>
</stackView>
Expand All @@ -227,6 +234,7 @@
<outlet property="anrFillingRunLoopButton" destination="TSF-10-5ts" id="Qp6-8q-IPH"/>
<outlet property="anrFullyBlockingButton" destination="Yi7-GN-26l" id="tMf-U3-onN"/>
<outlet property="dsnTextField" destination="L2a-LY-eQ7" id="TWn-0u-2v7"/>
<outlet property="framesLabel" destination="Lcm-n2-ys4" id="7mO-bc-HWw"/>
</connections>
</viewController>
<placeholder placeholderIdentifier="IBFirstResponder" id="dkx-z0-nzr" sceneMemberID="firstResponder"/>
Expand Down
9 changes: 9 additions & 0 deletions Samples/iOS-Swift/iOS-Swift/ViewController.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ class ViewController: UIViewController {
@IBOutlet weak var dsnTextField: UITextField!
@IBOutlet weak var anrFullyBlockingButton: UIButton!
@IBOutlet weak var anrFillingRunLoopButton: UIButton!
@IBOutlet weak var framesLabel: UILabel!

private let dispatchQueue = DispatchQueue(label: "ViewController")

Expand Down Expand Up @@ -45,6 +46,14 @@ class ViewController: UIViewController {

}

override func viewDidAppear(_ animated: Bool) {
if #available(iOS 10.0, *) {
Timer.scheduledTimer(withTimeInterval: 0.5, repeats: true) { _ in
self.framesLabel.text = "Frames Total:\(PrivateSentrySDKOnly.currentScreenFrames.total) Slow:\(PrivateSentrySDKOnly.currentScreenFrames.slow) Frozen:\(PrivateSentrySDKOnly.currentScreenFrames.frozen)"
}
}
}

@IBAction func addBreadcrumb(_ sender: Any) {
let crumb = Breadcrumb(level: SentryLevel.info, category: "Debug")
crumb.message = "tapped addBreadcrumb"
Expand Down
20 changes: 20 additions & 0 deletions Samples/iOS-Swift/iOS-SwiftUITests/LaunchUITests.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ class LaunchUITests: XCTestCase {
app.launch()

waitForExistenseOfMainScreen()
checkSlowAndFrozenFrames()
}

override func tearDown() {
Expand Down Expand Up @@ -70,6 +71,25 @@ class LaunchUITests: XCTestCase {
XCTAssertTrue(app.buttons["captureMessageButton"].waitForExistence(), "Home Screen doesn't exist.")
}

private func checkSlowAndFrozenFrames() {
let frameStatsLabel = app.staticTexts["framesStatsLabel"]
XCTAssertTrue(frameStatsLabel.waitForExistence(), "Frame statistics message not found.")

let frameStatsAsStringArray = frameStatsLabel.label.components(separatedBy: CharacterSet.decimalDigits.inverted)
let frameStats = frameStatsAsStringArray.filter { $0 != "" }.map { Int($0) }

XCTAssertEqual(3, frameStats.count)
guard let totalFrames = frameStats[0] else { XCTFail("No total frames found."); return }
guard let slowFrames = frameStats[1] else { XCTFail("No slow frames found."); return }
guard let frozenFrames = frameStats[1] else { XCTFail("No frozen frames found."); return }

let slowFramesPercentage = Double(slowFrames) / Double(totalFrames)
XCTAssertTrue(0.5 > slowFramesPercentage, "Too many slow frames.")

let frozenFramesPercentage = Double(frozenFrames) / Double(totalFrames)
XCTAssertTrue(0.5 > frozenFramesPercentage, "Too many frozen frames.")
}

private func assertApp() {
let confirmation = app.staticTexts["ASSERT_MESSAGE"]
let errorMessage = app.staticTexts["ASSERT_ERROR"]
Expand Down
27 changes: 14 additions & 13 deletions Sources/Sentry/SentryFramesTracker.m
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
#import "SentryFramesTracker.h"
#import "SentryDisplayLinkWrapper.h"
#import <SentryLog.h>
#import <SentryScreenFrames.h>
#include <stdatomic.h>

Expand All @@ -19,7 +20,6 @@
SentryFramesTracker ()

@property (nonatomic, strong, readonly) SentryDisplayLinkWrapper *displayLinkWrapper;
@property (nonatomic, assign, readonly) CFTimeInterval slowFrameThreshold;
@property (nonatomic, assign) CFTimeInterval previousFrameTimestamp;

@end
Expand Down Expand Up @@ -52,17 +52,6 @@ - (instancetype)initWithDisplayLinkWrapper:(SentryDisplayLinkWrapper *)displayLi
if (self = [super init]) {
_isRunning = NO;
_displayLinkWrapper = displayLinkWrapper;

// If we can't get the frame rate we assume it is 60.
double maximumFramesPerSecond = 60.0;
if (@available(iOS 10.3, tvOS 10.3, macCatalyst 13.0, *)) {
maximumFramesPerSecond = (double)UIScreen.mainScreen.maximumFramesPerSecond;
}

// Most frames take just a few microseconds longer than the optimal caculated duration.
// Therefore we substract one, because otherwise almost all frames would be slow.
_slowFrameThreshold = 1 / (maximumFramesPerSecond - 1);

[self resetFrames];
}
return self;
Expand Down Expand Up @@ -99,10 +88,22 @@ - (void)displayLinkCallback
return;
}

// Calculate the actual frame rate as pointed out by the Apple docs:
// https://developer.apple.com/documentation/quartzcore/cadisplaylink?language=objc The actual
// frame rate can change at any time by setting preferredFramesPerSecond or due to promotion
// display, low power mode, critical thermal state, and accessibility settings. Therefore we
// need to check the frame rate for every callback.
double actualFramesPerSecond
= 1 / (self.displayLinkWrapper.targetTimestamp - self.displayLinkWrapper.timestamp);

// Most frames take just a few microseconds longer than the optimal caculated duration.
// Therefore we substract one, because otherwise almost all frames would be slow.
CFTimeInterval slowFrameThreshold = 1 / (actualFramesPerSecond - 1);

CFTimeInterval frameDuration = lastFrameTimestamp - self.previousFrameTimestamp;
self.previousFrameTimestamp = lastFrameTimestamp;

if (frameDuration > self.slowFrameThreshold && frameDuration <= SentryFrozenFrameThreshold) {
if (frameDuration > slowFrameThreshold && frameDuration <= SentryFrozenFrameThreshold) {
atomic_fetch_add_explicit(&_slowFrames, 1, SentryFramesMemoryOrder);
}

Expand Down
2 changes: 2 additions & 0 deletions Sources/Sentry/include/SentryDisplayLinkWrapper.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,8 @@ NS_ASSUME_NONNULL_BEGIN

@property (readonly, nonatomic) CFTimeInterval timestamp;

@property (readonly, nonatomic) CFTimeInterval targetTimestamp;

- (void)linkWithTarget:(id)target selector:(SEL)sel;

- (void)invalidate;
Expand Down
5 changes: 5 additions & 0 deletions Sources/Sentry/include/SentryDisplayLinkWrapper.m
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,11 @@ - (CFTimeInterval)timestamp
return displayLink.timestamp;
}

- (CFTimeInterval)targetTimestamp
{
return displayLink.targetTimestamp;
}

- (void)linkWithTarget:(id)target selector:(SEL)sel
{
displayLink = [CADisplayLink displayLinkWithTarget:target selector:sel];
Expand Down
31 changes: 13 additions & 18 deletions Tests/SentryTests/Integrations/Performance/FramesTracking/SentryFramesTrackerTests.swift
View file
Original file line number Diff line number Diff line change
Expand Up @@ -47,12 +47,9 @@ class SentryFramesTrackerTests: XCTestCase {
sut.start()

fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.slowFrameThreshold + 0.001
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.slowFrameThreshold
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.frozenFrameThreshold
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.slowFrame()
fixture.displayLinkWrapper.normalFrame()
fixture.displayLinkWrapper.almostFrozenFrame()

let currentFrames = sut.currentFrames
XCTAssertEqual(2, currentFrames.slow)
Expand All @@ -65,10 +62,8 @@ class SentryFramesTrackerTests: XCTestCase {
sut.start()

fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.frozenFrameThreshold + 0.001
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.frozenFrameThreshold
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.slowFrame()
fixture.displayLinkWrapper.frozenFrame()

let currentFrames = sut.currentFrames
XCTAssertEqual(1, currentFrames.slow)
Expand All @@ -91,16 +86,14 @@ class SentryFramesTrackerTests: XCTestCase {

let frames: UInt = 600_000
for _ in 0 ..< frames {
fixture.displayLinkWrapper.internalTimestamp += TestData.slowFrameThreshold + 0.001
fixture.displayLinkWrapper.call()

fixture.displayLinkWrapper.internalTimestamp += TestData.frozenFrameThreshold + 0.001
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.normalFrame()
fixture.displayLinkWrapper.slowFrame()
fixture.displayLinkWrapper.frozenFrame()
}

group.wait()
currentFrames = sut.currentFrames
XCTAssertEqual(2 * frames, currentFrames.total)
XCTAssertEqual(3 * frames, currentFrames.total)
XCTAssertEqual(frames, currentFrames.slow)
XCTAssertEqual(frames, currentFrames.frozen)
}
Expand All @@ -112,10 +105,12 @@ class SentryFramesTrackerTests: XCTestCase {
let frames: UInt = 1_000
self.measure {
for _ in 0 ..< frames {
fixture.displayLinkWrapper.call()
fixture.displayLinkWrapper.internalTimestamp += TestData.slowFrameThreshold
fixture.displayLinkWrapper.normalFrame()
}
}

XCTAssertEqual(0, sut.currentFrames.slow)
XCTAssertEqual(0, sut.currentFrames.frozen)
}

private func assertPreviousCountBiggerThanCurrent(_ group: DispatchGroup, count: @escaping () -> UInt) {
Expand Down
Loading

0 comments on commit 24255b8

Please sign in to comment.