fix: missing GPU frame info in profiler #2823

armcknight · 2023-03-22T01:51:51Z

📜 Description

We never installed a default frames tracker for the profiler, so it wasn't getting GPU frame render information.

Also, only process frame rate info if there are slow/frozen frames to report. Otherwise it's uneeded.

💡 Motivation and Context

💚 How did you test it?

Added a UI test that triggers an ANR inside of a profiled transaction to force slow and frozen frames. Then it inspects the profile payload, via a new way to get the payload data out of the profiler: a notification is posted when testing, which is observed in iOS-Swift.ViewController, which serializes the dictionary to JSON data, base64 encodes that into a string and presents that string in an alert text field, which the UI test can extract to perform assertions.

📝 Checklist

You have to check all boxes before merging:

I reviewed the submitted code.
I added tests to verify the changes.
No new PII added or SDK only sends newly added PII if sendDefaultPII is enabled.
I updated the docs if needed.
Review from the native team if needed.
No breaking change or entry added to the changelog.
No breaking change for hybrid SDKs or communicated to hybrid SDKs.

🔮 Next steps

github-actions · 2023-03-22T02:06:17Z

Performance metrics 🚀

	Plain	With Sentry	Diff
Startup time	1207.53 ms	1226.98 ms	19.45 ms
Size	20.76 KiB	426.11 KiB	405.34 KiB

Baseline results on branch: main

Startup times

Revision	Plain	With Sentry	Diff
`06548c0`	1226.71 ms	1252.37 ms	25.66 ms
`e79ead7`	1233.39 ms	1255.52 ms	22.13 ms
`0dedab7`	1221.26 ms	1235.34 ms	14.08 ms
`7bc3c0d`	1212.35 ms	1228.94 ms	16.59 ms
`371db89`	1226.40 ms	1251.54 ms	25.14 ms
`fb53d97`	1235.00 ms	1241.88 ms	6.88 ms
`f8fc36d`	1226.31 ms	1247.80 ms	21.49 ms
`7bc3c0d`	1261.16 ms	1278.38 ms	17.22 ms
`9e96fd6`	1207.20 ms	1229.40 ms	22.20 ms
`25bcc50`	1240.47 ms	1254.70 ms	14.23 ms

App size

Revision	Plain	With Sentry	Diff
`06548c0`	20.76 KiB	427.36 KiB	406.59 KiB
`e79ead7`	20.76 KiB	426.11 KiB	405.35 KiB
`0dedab7`	20.76 KiB	420.00 KiB	399.24 KiB
`7bc3c0d`	20.76 KiB	427.35 KiB	406.59 KiB
`371db89`	20.76 KiB	427.31 KiB	406.55 KiB
`fb53d97`	20.76 KiB	425.80 KiB	405.04 KiB
`f8fc36d`	20.76 KiB	419.70 KiB	398.94 KiB
`7bc3c0d`	20.76 KiB	427.36 KiB	406.59 KiB
`9e96fd6`	20.76 KiB	425.80 KiB	405.04 KiB
`25bcc50`	20.76 KiB	427.22 KiB	406.46 KiB

Previous results on branch: armcknight/fix/missing-gpu-info

Startup times

Revision	Plain	With Sentry	Diff
`d202858`	1196.83 ms	1223.08 ms	26.25 ms
`140f023`	1229.08 ms	1242.74 ms	13.66 ms
`3615850`	1247.86 ms	1258.02 ms	10.16 ms
`65b562a`	1212.49 ms	1229.80 ms	17.31 ms
`605f5f2`	1221.88 ms	1243.28 ms	21.40 ms
`04edf4f`	1220.84 ms	1239.48 ms	18.64 ms
`7c05bd4`	1215.57 ms	1221.06 ms	5.49 ms
`76d39ec`	1254.88 ms	1264.16 ms	9.29 ms
`9fcbe52`	1213.29 ms	1230.42 ms	17.13 ms
`decef4a`	1211.80 ms	1248.58 ms	36.78 ms

App size

Revision	Plain	With Sentry	Diff
`d202858`	20.76 KiB	426.17 KiB	405.41 KiB
`140f023`	20.76 KiB	425.93 KiB	405.17 KiB
`3615850`	20.76 KiB	425.99 KiB	405.23 KiB
`65b562a`	20.76 KiB	425.93 KiB	405.17 KiB
`605f5f2`	20.76 KiB	425.93 KiB	405.17 KiB
`04edf4f`	20.76 KiB	425.92 KiB	405.16 KiB
`7c05bd4`	20.76 KiB	426.11 KiB	405.34 KiB
`76d39ec`	20.76 KiB	426.17 KiB	405.41 KiB
`9fcbe52`	20.76 KiB	425.93 KiB	405.17 KiB
`decef4a`	20.76 KiB	425.93 KiB	405.17 KiB

codecov · 2023-03-22T02:21:28Z

Codecov Report

Merging #2823 (affd5e4) into main (1bbcb9c) will increase coverage by 0.01%.
The diff coverage is 100.00%.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #2823      +/-   ##
==========================================
+ Coverage   81.33%   81.35%   +0.01%     
==========================================
  Files         258      258              
  Lines       24144    24158      +14     
  Branches    10714    10721       +7     
==========================================
+ Hits        19638    19654      +16     
+ Misses       4011     4008       -3     
- Partials      495      496       +1

Impacted Files	Coverage Δ
Sources/Sentry/SentryProfiler.mm	`83.36% <100.00%> (+0.14%)`	⬆️

... and 6 files with indirect coverage changes

Continue to review full report in Codecov by Sentry.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 1bbcb9c...affd5e4. Read the comment docs.

philipphofmann · 2023-03-22T15:57:54Z

@armcknight, CI is pretty unhappy. Please fix it so that I can give you a review tomorrow 😀.

philipphofmann

Almost LGTM.

I never thought about using the NSNotificationCenter to publish test data to UITests. It kind of feels hacky, but it's pragmatic, and if it works, why not 😄. Worth considering when writing UITests next time @brustolin.

On the other hand, I'm a bit surprised that we need a UITest to test this. IMO, unit or integration tests would have also been sufficient. If this was hard to achieve, I think it's a code smell for the testability of the SentryProfiler, and we should consider refactoring it a bit to make it testable. We don't need to address this in that PR, but some food for thought, @armcknight.

philipphofmann · 2023-03-23T17:15:13Z

Samples/iOS-Swift/iOS-Swift.xcodeproj/project.pbxproj

@@ -1378,7 +1378,7 @@
 				MARKETING_VERSION = 7.27.0;
 				PRODUCT_BUNDLE_IDENTIFIER = "io.sentry.sample.iOS-Swift";
 				PRODUCT_NAME = "$(TARGET_NAME)";
-				PROVISIONING_PROFILE_SPECIFIER = "match AppStore io.sentry.sample.iOS-Swift";
+				PROVISIONING_PROFILE_SPECIFIER = "match Development io.sentry.sample.iOS-Swift";


m: Did you change this on purpose? I guess that could be the reason that compiling for SauceLabs fails https://github.com/getsentry/sentry-cocoa/actions/runs/4496592755/jobs/7926403399?pr=2823

Yes, because I needed the sample app to build under the TEST configuration, and the signing settings were all mixed up for that config. So that was causing saucelabs build failures, see this earlier build before I fixed the codesign settings: https://github.com/getsentry/sentry-cocoa/actions/runs/4496464429/jobs/7911150807?pr=2823#step:9:366

We had a mix of distribution/development signing settings in the TEST configs (screenshot) and specified "development" for the fastlane build, which I believe would be the correct signing setting for a CI test run, vs pulling in the production key material.

The mismatch between the distribution identity setting and development parameter in the fastfile is the mismatch that actually caused the failure.

Missed the settings for iOS-SwiftClip, which is what was causing the failure you linked. Fixed in 3827dee

Thanks for the clarification.

philipphofmann · 2023-03-23T19:14:59Z

Samples/iOS-Swift/iOS-Swift/ViewController.swift

+        guard span == nil else { return }
+        span = SentrySDK.startTransaction(name: "Manual Transaction", operation: "Manual Operation")
+
+        NotificationCenter.default.addObserver(forName: profilerNotification, object: nil, queue: nil) { note in


m: I think it would be better to subscribe to this in viewWillAppear and unsubscribe in viewWillDisappear. Otherwise, we add an observer every time you click the button.

Yeah I think this would be fine.

Actually I did this so that we don't get an arbitrary amount of unexpected alerts popping up for e.g. a profiled launch span, so i think we should leave as-is. I have a guard on line 153 that prevents multiple subscriptions, and we remove the observer again on line 167.

Samples/iOS-Swift/iOS-Swift/ViewController.swift

Samples/iOS-Swift/iOS-SwiftUITests/LaunchUITests.swift

philipphofmann · 2023-03-23T19:23:51Z

Sources/Sentry/SentryProfiler.mm

-        = processFrameRates(_gCurrentFramesTracker.currentFrames.frameRateTimestamps, transaction);
-    if (frameRates.count > 0) {
-        metrics[@"screen_frame_rates"] = @{ @"unit" : @"hz", @"values" : frameRates };
+    if (slowFrames.count > 0 || frozenFrames.count > 0) {


m: I would expect a change in a unit test when changing this logic. Is this covered?

I don't think it is covered. I still have a todo list to add additional tests for the degenerate cases:

no slow/frozen GPU timestamps in a profile

there were slow/frozen frames, but fell outside of a transaction's start/end

armcknight · 2023-03-24T19:24:15Z

On the other hand, I'm a bit surprised that we need a UITest to test this. IMO, unit or integration tests would have also been sufficient. If this was hard to achieve, I think it's a code smell for the testability of the SentryProfiler, and we should consider refactoring it a bit to make it testable.

@philipphofmann This is a tricky part to test, here's why: we have to have an actual app running to integration test the frames tracker. We currently don't run the unit tests on a device (although I fixed that in a local branch for some benchmarking work–I had to add a test harness dummy iOS app to the Sentry project and designate it as the host for the unit tests).

We actually did make this part of the profiler more unit testable in one way, by adding the test frames tracker and mock calls here: https://github.com/getsentry/sentry-cocoa/pull/2493/files#diff-b341a165bb5e23dbf87f2cbbcd39bdf0dbef45c3e57a46e8cda4d49bd4019a0eR90-R97. But in that changeset, where I made the frames tracker injectable so we could mock it in tests, I forgot to inject the default impl for production purposes. DI is indeed messier for SentryProfiler since it's currently a static implementation with global state, instead of an instance that would be init'd with a parameter list forcing callsites to provide the default instance of a frame tracker etc.

…s if there are slow/frozen frames

philipphofmann

LGTM, but CI complains quite a bit.

Let's not discuss the testability problem in this PR. Let's have a chat about it via a call. That would be easier.

…ng in UI test run videos

armcknight requested review from philipphofmann and brustolin as code owners March 22, 2023 01:51

armcknight force-pushed the armcknight/fix/missing-gpu-info branch from 34bf217 to 25a15f5 Compare March 22, 2023 19:24

philipphofmann reviewed Mar 23, 2023

View reviewed changes

armcknight mentioned this pull request Mar 23, 2023

test: make all buttons visible/tappable #2828

Merged

armcknight and others added 10 commits March 24, 2023 11:59

install a default frames tracker in profiler; only process frame rate…

0846356

…s if there are slow/frozen frames

test that frame information is included in a real-world test scenario

1ee086b

changelog

36b218a

Format code

3bc409f

update comment

87facdf

uncomment compilation gates

42849f2

fix builds without uikit

767adb1

swiftlint checks

4ab6009

use Test configuration to build UI tests for saucelabs

62cab75

fix signing settings for iOS-Swift and its ui tests

7a241f5

armcknight force-pushed the armcknight/fix/missing-gpu-info branch from 3827dee to 7a241f5 Compare March 24, 2023 19:59

armcknight added 7 commits March 24, 2023 15:41

also check for frame rates; try waiting for each xcuielement's existence

2942a5c

fixup! use Test configuration to build UI tests for saucelabs

0af2c1e

fix changelog

8bfd8ed

fix paths

7802ab1

exclude from iOS 12 or earlier

3e2413d

use the right variable

472f279

correctly skip ios 12

6e7f22e

philipphofmann approved these changes Mar 27, 2023

View reviewed changes

armcknight added 2 commits March 27, 2023 16:34

highlight buttons that are tapped so it's more obvious what's happeni…

3afac6e

…ng in UI test run videos

display the name of the currently running UI test in iOS-Swift

eea2221

armcknight added 3 commits March 27, 2023 16:47

split profiling test into separate xctestcase

43332e5

fix swiftlint issue

86f2c35

only run on iOS 15+

affd5e4

armcknight merged commit e5ac362 into main Mar 28, 2023

armcknight deleted the armcknight/fix/missing-gpu-info branch March 28, 2023 03:06

armcknight mentioned this pull request Mar 30, 2023

ref: mock clock for GPU metrics tests and fix slicing logic #2842

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: missing GPU frame info in profiler #2823

fix: missing GPU frame info in profiler #2823

armcknight commented Mar 22, 2023

github-actions bot commented Mar 22, 2023 •

edited

Loading

Baseline results on branch: main

Startup times

App size

Previous results on branch: armcknight/fix/missing-gpu-info

Startup times

App size

codecov bot commented Mar 22, 2023 •

edited

Loading

philipphofmann commented Mar 22, 2023

philipphofmann left a comment •

edited

Loading

philipphofmann Mar 23, 2023

armcknight Mar 24, 2023

armcknight Mar 24, 2023

philipphofmann Mar 27, 2023

philipphofmann Mar 23, 2023

armcknight Mar 24, 2023

armcknight Mar 24, 2023 •

edited

Loading

philipphofmann Mar 23, 2023

armcknight Mar 24, 2023

armcknight commented Mar 24, 2023 •

edited

Loading

philipphofmann left a comment •

edited

Loading

fix: missing GPU frame info in profiler #2823

fix: missing GPU frame info in profiler #2823

Conversation

armcknight commented Mar 22, 2023

📜 Description

💡 Motivation and Context

💚 How did you test it?

📝 Checklist

🔮 Next steps

github-actions bot commented Mar 22, 2023 • edited Loading

Performance metrics 🚀

Baseline results on branch: main

Startup times

App size

Previous results on branch: armcknight/fix/missing-gpu-info

Startup times

App size

codecov bot commented Mar 22, 2023 • edited Loading

Codecov Report

philipphofmann commented Mar 22, 2023

philipphofmann left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

armcknight Mar 24, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

armcknight commented Mar 24, 2023 • edited Loading

philipphofmann left a comment • edited Loading

Choose a reason for hiding this comment

github-actions bot commented Mar 22, 2023 •

edited

Loading

codecov bot commented Mar 22, 2023 •

edited

Loading

philipphofmann left a comment •

edited

Loading

armcknight Mar 24, 2023 •

edited

Loading

armcknight commented Mar 24, 2023 •

edited

Loading

philipphofmann left a comment •

edited

Loading