sentry-cocoa icon indicating copy to clipboard operation
sentry-cocoa copied to clipboard

Fix pre warmed app start measurement

Open philipphofmann opened this issue 3 years ago • 9 comments

Description

Since iOS 15, the system might decide to pre-warm your app before the user tries to open it. In such cases, we can't reliably measure the app start, and we started to drop reporting app start measurements with https://github.com/getsentry/sentry-cocoa/pull/1896. Otherwise, we would get app start times ranging from one minute to even days.

According to a former Apple engineer, you should use MetricKit to collect statistics on app start because MetricKit uses internal OS values, which are not exposed otherwise. MetricKit works on iOS 13 and above. Maybe it's time to replace our own SentryAppStartTracker.

See also https://github.com/getsentry/sentry-cocoa/issues/1661. [Internal Notion page] (https://www.notion.so/sentry/Detecting-iOS-15-App-Prewarming-c892f118bdd34b558eb187796ed5e424) on how to detect pre-warmed app starts with data we can't share in public, and another Notion page for a DACI on how to report pre-warmed app starts again.

Related PRs:

  • [x] https://github.com/getsentry/sentry-cocoa/pull/1896
  • [x] https://github.com/getsentry/sentry-cocoa/pull/1899
  • [x] https://github.com/getsentry/sentry-cocoa/pull/1927
  • [ ] https://github.com/getsentry/sentry-cocoa/pull/1969

philipphofmann avatar Jun 17 '22 08:06 philipphofmann

Can we get values from MetricKit about the startup related to the transaction that launched the app?

bruno-garcia avatar Jun 17 '22 11:06 bruno-garcia

Can we get values from MetricKit about the startup related to the transaction that launched the app?

No, we can't because we don't get launch data in real-time. You get it once per day: see https://github.com/getsentry/sentry-cocoa/issues/1661#issuecomment-1158800905

philipphofmann avatar Jun 17 '22 11:06 philipphofmann

According to the Apple docs

Prewarming an app results in an indeterminate amount of time between when the prewarming phase completes and when the user, or system, fully launches the app. Because of this, use MetricKit to accurately measure user-driven launch and resume times instead of manually signposting various points of the launch sequence.

And

Prewarming executes an app’s launch sequence up until, but not including, when main() calls UIApplicationMain(::::).

So we could check if the runtime init and the process start time are some threshold in the past to assume it is an pre warmed app start. We could then just ditch Pre Main and UIKit and Application Init and create a new app start type pre warmed. MetricKit has a special histogram for pre warmed app starts. Taken from our docs:

philipphofmann avatar Jun 17 '22 12:06 philipphofmann

Prewarming can execute code up to viewDidLoad of a UIViewController, and keep your app in the background. It can pause at any stage from creating the process up to viewDidLoad of a UIViewController or something similar. This is a contradiction to the Apple docs Prewarming executes an app’s launch sequence up until, but not including, when main() calls UIApplicationMain(::::).

I dug into some transactions of customers and found a few transactions similar to this one:

Screen Shot 2022-06-20 at 09 39 34

The above screenshot shows missing instrumentation of around 4 hours in between viewDidLoad and viewWillAppear. This can't be the case if the app was in the foreground because the watchdog would kill the app.

Discover query to reveal such transactions: event.type:transaction measurements.app_start_warm:>500 measurements.app_start_warm:<2000 transaction.duration:>10000

An answer on StackOverflow supports this claim.

More screenshots

Discover query used:event.type:transaction measurements.app_start_warm:>10000

Pausing after process creation

Screen Shot 2022-06-20 at 09 48 49 Screen Shot 2022-06-20 at 09 53 40

Pausing after process creation and runtime init Screen Shot 2022-06-20 at 09 54 16

philipphofmann avatar Jun 20 '22 07:06 philipphofmann

Maybe using __mod_init_func in the data section of Mach-O binary could help. An example of how to use it.

philipphofmann avatar Jun 22 '22 12:06 philipphofmann

It seems like we can use, see https://eisel.me/startup

if ([[NSProcessInfo processInfo].environment[@"ActivePrewarm"] isEqual:@"1"]) {
      // The ActivePrewarm variable indicates whether the app was launched via pre-warming.
      // Based on this, for example, you can choose whether or not to include the pre-main time in your calculation based on that.
}

philipphofmann avatar Jun 30 '22 09:06 philipphofmann

@mitsuhiko, @k-fish, and I agreed on reporting the app start type in the app context as start_type : cold | cold.prewarmed | warm | warm.prewarmed. Internal Notion Page for more context.

philipphofmann avatar Jul 19 '22 09:07 philipphofmann

To sum up: latest sdk version doesn't send bogus app start anymore. The startup time metric is accurate. It doesn't send pre warn info yet. It's the last pending feature we want to add to this.

bruno-garcia avatar Aug 05 '22 18:08 bruno-garcia

This issue has gone three weeks without activity. In another week, I will close it.

But! If you comment or otherwise update it, I will reset the clock, and if you label it Status: Backlog or Status: In Progress, I will leave it alone ... forever!


"A weed is but an unloved flower." ― Ella Wheeler Wilcox 🥀

github-actions[bot] avatar Aug 27 '22 00:08 github-actions[bot]