impr: Capture trace based profiles on a BG Thread #4377
Conversation
Serializing and capturing a profile can run on the main thread and block it for a couple of milliseconds. Therefore, we move this to a background thread to avoid potentially blocking the main thread.
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #4377 +/- ##
=============================================
+ Coverage 91.294% 91.299% +0.005%
=============================================
Files 609 610 +1
Lines 49519 49539 +20
Branches 17822 17841 +19
=============================================
+ Hits 45208 45229 +21
+ Misses 4218 4217 -1
Partials 93 93
... and 3 files with indirect coverage changes Continue to review full report in Codecov by Sentry.
|
Performance metrics 🚀
|
| Revision | Plain | With Sentry | Diff |
|---|---|---|---|
| 25d925a | 1232.89 ms | 1248.41 ms | 15.52 ms |
| 2911760 | 1217.84 ms | 1232.48 ms | 14.64 ms |
| e998fd0 | 1241.49 ms | 1262.63 ms | 21.14 ms |
| 39b1c35 | 1235.90 ms | 1257.37 ms | 21.47 ms |
| 236d8a8 | 1232.33 ms | 1255.55 ms | 23.22 ms |
| d8eb419 | 1221.91 ms | 1253.62 ms | 31.71 ms |
| 5d6ce0e | 1206.72 ms | 1228.67 ms | 21.95 ms |
| e02eb74 | 1221.81 ms | 1258.58 ms | 36.77 ms |
| 1bbcb9c | 1214.25 ms | 1230.04 ms | 15.79 ms |
| 649d940 | 1227.06 ms | 1245.19 ms | 18.13 ms |
App size
| Revision | Plain | With Sentry | Diff |
|---|---|---|---|
| 25d925a | 21.58 KiB | 418.82 KiB | 397.24 KiB |
| 2911760 | 21.58 KiB | 697.69 KiB | 676.11 KiB |
| e998fd0 | 21.58 KiB | 414.59 KiB | 393.01 KiB |
| 39b1c35 | 22.85 KiB | 408.88 KiB | 386.03 KiB |
| 236d8a8 | 21.58 KiB | 418.70 KiB | 397.12 KiB |
| d8eb419 | 22.85 KiB | 408.87 KiB | 386.02 KiB |
| 5d6ce0e | 22.85 KiB | 405.38 KiB | 382.53 KiB |
| e02eb74 | 21.58 KiB | 713.54 KiB | 691.95 KiB |
| 1bbcb9c | 20.76 KiB | 426.10 KiB | 405.34 KiB |
| 649d940 | 21.58 KiB | 695.36 KiB | 673.78 KiB |
Co-authored-by: Dhiogo Brustolin <dhiogo.brustolin@sentry.io>
|
I'm still waiting for @armcknight to approve this so we can avoid shooting ourselves in the foot. |
There was a problem hiding this comment.
Could you be more specific about how you tested this? I just tried looking at a manual transaction with trace-based profiling on main vs this branch and the profiles look different. I can't get a launch profile to show up when running from this branch.
I tried comparing the differences between main and this branch with continuous profiling but I'm not even seeing what I expect on main so i need to ask the team what's going on there.
At a minimum for anything profiling right now you have to check what it looks like on main against your changes for:
- trace-based
- regular transaction
- launch
- continuous
- regular transaction
- launch
Trace-based regular txn on main (https://sentry-sdks.sentry.io/profiling/profile/sentry-cocoa/cdc0737ef92245a0b14dcdb40c5d68c3/flamegraph/?colorCoding=by%20system%20vs%20application%20frame&fov=0%2C0%2C3822472960%2C19&query=&sorting=call%20order&tid=259&view=top%20down):
|
Hmm, weird, I didn't test it in great detail as I didn't expect that when all the tests are green, such a small change can have such a big impact. @armcknight, do you have a clue about what could cause this? I will look into this tomorrow. |
|
@philipphofmann my guess is that you aren't dispatching the right call to the bg queue, and so it captures a set of profiling data much earlier than it marks the end of the transaction. You may need to look for a more granular point in that process, or create one by refactoring. |
|
I found the problem. This PR only impacts trace based profiles, as only the SentryTracer uses I tested this for manual transactions, UIViewController transactions and app start transactions.
|
Sources/Sentry/Profiling/SentryCaptureTransactionWithProfile.mm
Outdated
Show resolved
Hide resolved
There was a problem hiding this comment.
Really nice test report! ✨ Looking at the actual profile durations in them, it seems the same, and it's the transaction that is actually more variable. I think that variability is not due to this change but is coming from preexisting behavior in the SDK so i'm not worried about it.
A comment on the tests you added, but otherwise things look good here, so when you get that ironed out, feel free to ship it.
Also regarding my earlier comment on continuous profiling, it looks like there's some delay with data coming in, being aggregated, or becoming accessible.
If and when you get around to bg'ing the continuous serialization function (maybe in a separate PR?), test it by looking at https://sentry-sdks.sentry.io/profiling/?project=5428557&statsPeriod=1m&tab=flamegraph:
Ups, sorry, that's not the goal of this PR. I only want to capture trace-based profiles on a BG thread. I updated the description and title. |
📜 Description
Serializing and capturing trace based profiles can run on the main thread and block it for a couple of milliseconds. Therefore, we move this to a background thread to avoid potentially blocking the main thread.
💡 Motivation and Context
This came up while investigating profiles for potentially slowing down UIViewControllers.
💚 How did you test it?
Unit test and checking if the profile is still correctly attached to UIViewController transactions with our iOS-Swift sample app.
📝 Checklist
You have to check all boxes before merging:
sendDefaultPIIis enabled.🔮 Next steps