RN Bundle Load Impact on Cold Starts [Android/Hermes]

RN Bundle Load Impact on Cold Starts [Android/Hermes]

This document provides analysis and root cause of the impact of the React Native initialization and JavaScript Bundle load on Android. For prior information related to this matter, you can refer to the Find Landing Page RN Performance Deep Dive. If you prefer to skip directly to the conclusions related to the impact of the Hermes precompilation, please refer to Root Cause / Solution section.

Background / Problem

Data collected after FLP Experiment Weblab Latency Analysis Android: Find Page CX on React Native Experiment Writeup [DRAFT] suggested the experience with React Native enabled (T1) has worsened cold start performance compared to its Native counterpart (C). Specifically, the performance has worsened 3.6x at P90 (5.7s vs 1.5s) where the major contributor is from the “start” leg (1800ms vs 86ms). The “start” leg corresponds to the timing between the Native initialization of React Native until JS from the RN bundle is executed.

End-to-End Latency Analysis

For this end-to-end latency analysis we leveraged Systrace tool. For more information on how to run it or how to read a systrace please refer to https://reactnative.dev/docs/profiling. The article also explains the main threads of interest when profiling React Native: the UI thread (which has package name or the name UI Thread), mqt_js, and mqt_native_modules.

  • UI Thread. This is where standard android measure/layout/draw happens. The thread name on the right will be your package name (in our case amazon.mp3) or UI Thread. The events that you see on this thread should look something like this and have to do with Choreographer, traversals, and DispatchUI:

  • JS Thread. This is where JavaScript is executed. The thread name will be either mqt_js or <...> depending on how cooperative the kernel on your device is being. To identify it if it doesn’t have a name, look for things like JSCall, Bridge.executeJSCall, etc:

  • Native Modules Thread. This is where native module calls (e.g. the UIManager) are executed. The thread name will be either mqt_native_modules or <...>. To identify it in the latter case, look for things like NativeCall, callJavaModuleMethod, and onBatchComplete:

  • Render Thread. If you’re using Android L (5.0) and up, you will also have a render thread in your application. This thread generates the actual OpenGL commands used to draw your UI. The thread name will be either RenderThread or <...>. To identify it in the latter case, look for things like DrawFrame and queueBuffer

Here’s a screenshot of the end-to-end cold start latency collected via Systrace using a Pixel 3A device and app built in release mode. The trace is available here pixel_3a_rn_cold_start.perfetto-trace:

Latency Breakdown

Here’s another representation through a diagram of the cold start flow on Android and the three key threads involved: create_react_co, mqt_js and mqt_native_modu Edit link

RN Prewarming

We start the bridge prewarming very early on in the application lifecycle, as early as we can basically, 165ms from the onCreate call. The prewarming is achieved via the call to createReactContexInBackground, which as name suggests, is triggered in the background.

RN Asynchronous initialization

Initialization on create_react_context ** thread

The create_react_context thread contains the initialization of the React Context, which happens right after invoking the prewarming call. This includes the loading of react native libraries as well as the JS bundle load, only taking roughly 150ms:

Initialization on mqt_js thread

Following the JS bundle load, the mqt_js threads appears to be busy executing / parsing the contents of the bundle for a significant amount of time, as shown by screenshot below in our local device this takes approximately 5.3s:

Initialization on mqt_native_modules

Following the mqt_js initialization the native modules gets initialized on the mqt_native_modules thread. At the end of this, taking roughly 1s, a callback onBatchCompleteUI is invoked which will trigger rendering.

Native Rendering

The RN rendering gets translated to Native and still takes approximately 0.5s:

Root Cause / Solution

We conducted a comparison of the RN initialization time among two other applications, namely, the DF greenfield app and a pure RN vanilla app. This analysis aimed to determine whether these apps were also experiencing a similarly prolonged initialization time. The RN initialization time was computed as the time difference between the ReactNativeJS: Running "<bundle name>" and the earliest time the RN was invoked. In the case of our brownfield application, would correspond to the prewarming call, in the case of greenfield / vanilla app corresponds to the main React Native Activity creation. For raw data refer to Appendix A: App Start Time Raw Data from logs.

RN initialization time

Amazon Music (brownfield)

5.3s

DragonField (greenfield)

0.58s

Vanilla RN app

0.087s

As indicated in the table above, we exclusively observed the elevated initialization time in the case of the AM (brownfield app). This led to the investigation in figuring out the differences between the greenfield and brownfield app (since vanilla app was close enough to DF). After multiple attempts, which included trying to replace the content of the Amazon Music (brownfield) app with the logic from the DragonFly (greenfield) app, and still encountering the same latency issue, we resorted to decompiling the APK using apktool. During this process, we observed a difference in the JS bundle between the two apps. Specifically, when decompiling the DragonFly Greenfield app and examining the index.android.bundle, it became apparent that it was precompiled (to Hermes bytecode), while the one used in our brownfield app was in plain text format (see index.android.bundle).

Upon re-building the brownfield app with the Hermes bytecode bundle, we witnessed a significant improvement in React Native (RN) initialization time. For more info related to Hermes please refer to https://engineering.fb.com/2019/07/12/android/hermes/. After this change the Find Landing Page page loads have decreased from roughly ~5.3 seconds to ~1.2 seconds, and the startup phase duration has gone down from about ~4 seconds to approximately ~400 milliseconds. For full data refer to Appendix B: FLP page load times with Hermes bytecode bundle vs plain text bundle. Summary table:

Non-Hermes precompiled Bundle

Hermes precompiled Bundle

pageLoad totalDurationMs

5.3s

1.2s

pieceDuration: Start leg

4.27s

0.37s

pieceDuration: rendering leg

0.5s

0.458s

Here’s an updated end-to-end screenshot view from systrace after using the Hermes precompiled bundle, showing an end-to-end improvement of roughly ~4s:

Trace available here pixel_3a_rn_cold_start_hermes_precompiled.perfetto-trace Corresponding FLP pageLoad event: 10-30 17:38:06.150 8390 8467 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = **1290ms** | [pieceDurations: START: **398ms**, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 185ms, PROCESSING: 232ms, RENDERING: 471ms]

Next Steps

The following are some next possible steps:

  • Profiling of React Native bundle load time via a latencyInfo event that can be monitored and alarmed on

  • Investigating availability of React Native New Architecture and analyze its impact on Cold Starts

  • Verify impact of Hermes precompilation on iOS

Resources

FAQs

FAQ-1: What is Hermes?

Hermes is an open source JavaScript engine optimized for mobile apps. Using Hermes will result in improved start-up time, decreased memory usage, and smaller app size when compared to JavaScriptCore. Commonly, a JavaScript engine will parse the JavaScript source after it is loaded, generating bytecode. This step delays the start of JavaScript execution. To skip this step, Hermes uses an ahead-of-time compiler, which runs as part of the mobile application build process. As a result, more time can be spent optimizing the bytecode, so the bytecode is smaller and more efficient. For additional info please refer to https://engineering.fb.com/2019/07/12/android/hermes/

FAQ-2: Why don’t have the same problem on iOS?

Data collected on iOS (see app version: v23.13.0.167951+: Find Page CX on React Native Experiment Writeup [DRAFT]) suggested that the impact on cold start was significantly smaller on iOS compared to Android. The “start” leg only increased from 56ms (C treatment) to 245ms (T1 treatment), but the overall totalDuration of the FLP pageLoad was actually lower in the T1 treatment (1066ms vs 3732ms).

However, even though we are not seeing a significant impact on cold starts, we still should pursue enabling similar fix as we did for Android, so that iOS can also leverage a Hermes bytecode precompiled bundle.

FAQ-3: Why are we recreating the fragment each time on Android?

This is by Android’s lifecycle design, each fragment is destroyed when the user moves to a different page. See https://developer.android.com/guide/fragments/lifecycle. Base on local data, it suggests fragment recreation (newInstance→onResume) only taking <30ms so it’s very small contribution to the overall latency.

10-23 13:08:43.323 14698 14698 E AmznMusic_GenericReactFragment: newInstance
10-23 13:08:43.330 14698 14698 E AmznMusic_GenericReactFragment: onCreate
10-23 13:08:43.332 14698 14698 E AmznMusic_GenericReactFragment: onCreateView
10-23 13:08:43.346 14698 14698 E AmznMusic_GenericReactFragment: onResume

Appendix A: App Start Time Raw Data from logs

Device: Pixel 3A Number of iterations: 5x Methodology: cold starting the app via force-stop command and looking at log time difference, see each individual case for specific details

Amazon Music App (brownfield integration)

Methodology: Time difference between ReactNativeJS: "DragonFly" and the RN bridge [PrimaryReactInitializer.initializeBridge](https://code.amazon.com/packages/DigitalMusicAndroid3P/blobs/561eb35445ddd13a260cfacfa6f83194152a98e8/--/android/src/main/java/com/amazon/mp3/reactnative/PrimaryReactInitializer.kt#L54)

  • Average: 5.26s

  • Times: [5.3s, 5.28s, 5.225, 5.244, 5.238s]

10-23 14:06:26.955 20525 20525 E AmznMusic_PrimaryReactInitializer: ALC React Native bridge initialization via createReactContextInBackground started 10-23 14:06:28.450 20525 20525 E AmznMusic_GenericReactExperienceInitializer: createRNFragment INITIAL_PROP_NATIVE_NAVIGATION_START_TIME 1698084388450 10-23 14:06:28.451 20525 20525 E AmznMusic_GenericReactFragment: newInstance 10-23 14:06:28.458 20525 20525 E AmznMusic_GenericReactFragment: onCreate 10-23 14:06:28.459 20525 20525 E AmznMusic_GenericReactFragment: onCreateView 10-23 14:06:28.469 20525 20525 E AmznMusic_GenericReactFragment: onResume 10-23 14:06:32.353 20525 20613 I ReactNativeJS: Running "DragonFly

10-23 14:12:48.382 21608 21608 E AmznMusic_PrimaryReactInitializer: ALC React Native bridge initialization via createReactContextInBackground started 10-23 14:12:49.807 21608 21608 E AmznMusic_GenericReactExperienceInitializer: createRNFragment INITIAL_PROP_NATIVE_NAVIGATION_START_TIME 1698084769807 10-23 14:12:49.807 21608 21608 E AmznMusic_GenericReactFragment: ALC newInstance 10-23 14:12:49.813 21608 21608 E AmznMusic_GenericReactFragment: ALC onCreate 10-23 14:12:49.816 21608 21608 E AmznMusic_GenericReactFragment: onCreateView 10-23 14:12:49.826 21608 21608 E AmznMusic_GenericReactFragment: onResume 10-23 14:12:53.662 21608 21702 I ReactNativeJS: Running "DragonFly

10-23 14:14:15.792 22279 22279 E AmznMusic_PrimaryReactInitializer: ALC React Native bridge initialization via createReactContextInBackground started 10-23 14:14:17.278 22279 22279 E AmznMusic_GenericReactExperienceInitializer: createRNFragment 10-23 14:14:17.278 22279 22279 E AmznMusic_GenericReactFragment: newInstance 10-23 14:14:17.286 22279 22279 E AmznMusic_GenericReactFragment: ALC onCreate 10-23 14:14:17.289 22279 22279 E AmznMusic_GenericReactFragment: onCreateView 10-23 14:14:17.301 22279 22279 E AmznMusic_GenericReactFragment: onResume 10-23 14:14:21.017 22279 22375 I ReactNativeJS: Running "DragonFly

10-23 14:15:08.588 22935 22935 E AmznMusic_PrimaryReactInitializer: ALC React Native bridge initialization via createReactContextInBackground started 10-23 14:15:10.026 22935 22935 E AmznMusic_GenericReactExperienceInitializer: createRNFragment 10-23 14:15:10.026 22935 22935 E AmznMusic_GenericReactFragment-ALC: ALC newInstance 10-23 14:15:10.031 22935 22935 E AmznMusic_GenericReactFragment-ALC: ALC onCreate 10-23 14:15:10.034 22935 22935 E AmznMusic_GenericReactFragment-ALC: onCreateView 10-23 14:15:10.044 22935 22935 E AmznMusic_GenericReactFragment-ALC: ALC onResume 10-23 14:15:13.832 22935 23030 I ReactNativeJS: Running "DragonFly

10-23 14:20:44.877 23716 23716 E AmznMusic_PrimaryReactInitializer: React Native bridge initialization via createReactContextInBackground started 10-23 14:20:45.547 6293 6293 I WearableService: onCreate: Wearable Services not starting. Wear is not available on this device. 10-23 14:20:46.312 23716 23716 E AmznMusic_GenericReactExperienceInitializer: createRNFragment 10-23 14:20:46.313 23716 23716 E AmznMusic_GenericReactFragment: ALC newInstance 10-23 14:20:46.319 23716 23716 E AmznMusic_GenericReactFragment: ALC onCreate 10-23 14:20:46.327 23716 23716 E AmznMusic_GenericReactFragment: onCreateView 10-23 14:20:46.335 23716 23716 E AmznMusic_GenericReactFragment: ALC onResume 10-23 14:20:50.115 23716 23805 I ReactNativeJS: Running "DragonFly

DragonFly greenfield app

Built the DragonFly app using yarn android --variant=release command to ensure release variant was built.

Methodology: Time difference between ReactNativeJS: "DragonFly" and MainActivity.onCreate

  • Average: 579.4ms

  • Times: [582ms, 584ms, 580ms, 573ms, 578ms]

10-23 13:47:38.908 19301 19301 E ALC : onCreate 10-23 13:47:39.490 19301 19327 I ReactNativeJS: Running "DragonFly"

10-23 13:49:07.056 19544 19544 E ALC : onCreate 10-23 13:49:07.640 19544 19570 I ReactNativeJS: Running "DragonFly"

10-23 13:49:22.805 19613 19613 E ALC : onCreate 10-23 13:49:23.385 19613 19639 I ReactNativeJS: Running "DragonFly"

10-23 13:50:24.437 19778 19778 E ALC : onCreate 10-23 13:50:25.010 19778 19804 I ReactNativeJS: Running "DragonFly"

10-23 13:50:49.791 19846 19846 E ALC : onCreate 10-23 13:50:50.369 19846 19874 I ReactNativeJS: Running "DragonFly"

Vanilla app

Created with react-native-init <project_name> command

Methodology: Time difference between ReactNativeJS: "HelloWorld" and MainActivity.onCreate

  • Average: 87ms

  • Times: [90ms, 78ms, 99ms, 87ms, 81ms]

10-23 13:59:53.202 20154 20154 E ALC : onCreate 10-23 13:59:53.292 20154 20176 I ReactNativeJS: Running "HelloAlberto

10-23 14:00:05.189 20210 20210 E ALC : onCreate 10-23 14:00:05.267 20210 20232 I ReactNativeJS: Running "HelloAlberto

10-23 14:00:16.976 20259 20259 E ALC : onCreate `10-23 14:00:17.075 20259 20281 I ReactNativeJS: Running “HelloAlberto

10-23 14:00:28.206 20306 20306 E ALC : onCreate 10-23 14:00:28.293 20306 20328 I ReactNativeJS: Running “HelloAlberto`

10-23 14:00:53.051 20403 20403 E ALC : onCreate 10-23 14:00:53.132 20403 20425 I ReactNativeJS: Running "HelloAlberto

Appendix B: FLP page load times with Hermes bytecode bundle vs plain text bundle

Plain Text bundle

  • Average: 5.3s

    • start leg: 4266ms

    • rendering leg: 553.4s

10-25 11:14:05.573 22356 22444 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 5278ms | [pieceDurations: START: 4190ms, INITIALIZING: 2ms, REQUEST: 1ms, RESPONSE: 312ms, PROCESSING: 229ms, RENDERING: 542ms]

10-25 11:14:17.162 23003 23085 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 5434ms | [pieceDurations: START: 4323ms, INITIALIZING: 2ms, REQUEST: 0ms, RESPONSE: 319ms, PROCESSING: 238ms, RENDERING: 549ms]

10-25 11:14:29.317 23659 23744 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 5396ms | [pieceDurations: START: 4283ms, INITIALIZING: 2ms, REQUEST: 1ms, RESPONSE: 321ms, PROCESSING: 235ms, RENDERING: 553ms]

10-25 11:14:40.513 24304 24389 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 5423ms | [pieceDurations: START: 4287ms, INITIALIZING: 2ms, REQUEST: 1ms, RESPONSE: 322ms, PROCESSING: 252ms, RENDERING: 557ms]

10-25 11:14:53.985 24961 25059 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 5376ms | [pieceDurations: START: 4247ms, INITIALIZING: 2ms, REQUEST: 1ms, RESPONSE: 312ms, PROCESSING: 247ms, RENDERING: 566ms]

Hermes enabled bytecode bundle

  • Average: 1.215s

    • start leg: 366.4ms

    • rendering leg: 458ms

10-25 11:06:45.532 18249 18338 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 1268ms | [pieceDurations: START: 393ms, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 209ms, PROCESSING: 208ms, RENDERING: 455ms]

10-25 11:06:54.906 18913 19002 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 1150ms | [pieceDurations: START: 366ms, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 155ms, PROCESSING: 198ms, RENDERING: 428ms]

10-25 11:07:03.542 19557 19642 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 1247ms | [pieceDurations: START: 374ms, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 180ms, PROCESSING: 221ms, RENDERING: 469ms]

10-25 11:07:10.013 20175 20257 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 1237ms | [pieceDurations: START: 349ms, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 157ms, PROCESSING: 215ms, RENDERING: 514ms]

10-25 11:07:16.950 20834 20918 E AmznMusic_LatencyTrackerLogger: latencyCode: [pageLoadFindV3] operation: [pageLoad] subType: [findV3] duration = 1175ms | [pieceDurations: START: 377ms, INITIALIZING: 0ms, REQUEST: 0ms, RESPONSE: 157ms, PROCESSING: 212ms, RENDERING: 428ms]