Nativescript: [Tracking] Performance improvements

[sis0k0]

• [x] Profile hello-ng app in iOS with webinspector.
• [x] Profile Angular renderer.
• [x] Profile Android runtime performance.
• [x] Profile app.css (with theme) performance.
• [ ] Experiment with rollup
• [x] Implement suspend native updates - use them in angular
• [ ] Android GC hits ~500ms. on Angular apps
• [ ] Android runtime. Don't attach all methods/properties for proxy objects on init. Instead generate them when they are first accesses. #4597
• [ ] Android runtime. Use hash-maps instead of arrays to store methods.
• [ ] iOS runtime. Debug build on device wait 500ms for JS debugger.
• [ ] iOS runtime. Debug build on device spends 300ms on startup doing live sync initialization.

Benchmarks for start-up time with an old Android phone (API lvl 19):

| | theme | NO theme | DIFF (theme vs NO theme)
| --- | --- | --- | ---
| debug | 8.1096 sec | 8.028 sec | +0.0816 sec
| webpack + AoT + uglify | 3.2703 sec | 3.1973 sec | +0.073 sec

Possible improvements:

• Set app.css as styleUrl to the root component with ViewEncapsulation.None.
  We'll call addCss in the renderer anyway. The benchmarks showed that the results for app start-up are the same.

---

Want to back this issue? Post a bounty on it! We accept bounties via Bountysource.

[PanayotCankov]

About measuring, there is some time fore the first line of JavaScript is executed and it would be nice to track this too.

For iOS there is a nice video here about measuring pre-main times.
Basically it points to adding DYLD_PRINT_STATISTICS = 1 environment variable in Xcode and outputs dyld times. Here is a baseline of blank app:

Total pre-main time:  25.32 milliseconds (100.0%)
         dylib loading time:  15.12 milliseconds (59.7%)
        rebase/binding time:   1.87 milliseconds (7.3%)
            ObjC setup time:   2.19 milliseconds (8.6%)
           initializer time:   6.06 milliseconds (23.9%)
           slowest intializers :
             libSystem.B.dylib :   1.91 milliseconds (7.5%)
   libBacktraceRecording.dylib :   3.20 milliseconds (12.6%)

error in __connection_block_invoke_2: Connection interrupted

And here is a hello world {N} app:

Total pre-main time: 144.99 milliseconds (100.0%)
         dylib loading time: 115.66 milliseconds (79.7%)
        rebase/binding time:  14.12 milliseconds (9.7%)
            ObjC setup time:   3.04 milliseconds (2.1%)
           initializer time:  12.10 milliseconds (8.3%)
           slowest intializers :
             libSystem.B.dylib :   4.27 milliseconds (2.9%)
   libBacktraceRecording.dylib :   3.26 milliseconds (2.2%)
                  NativeScript :   3.98 milliseconds (2.7%)

The next interesting thing is the runtime also loads some frameworks using dlopen here it would be good if we can track these times too if DYLD_PRINT_STATISTICS or a similar flag is set.

[PanayotCankov]

The app we want to optimise is

tns create someapp --ng
cd someapp
npm i --save-dev nativescript-dev-webpack
npm i
npm run start-android-bundle --uglify

[PanayotCankov]

On LG about:

• 1900ms go for runtime initialization before the first line of JS in the main.aot.js is executed
  
  
  
  • 1500ms of which are in require("vendor.js")
  
  
  • 100ms of which are in require("bundle.js")
  
  
• 1644ms go from the first line of main.aot.js to ngAfterViewInit
  
  
  
  • 100ms exposing android/content/Intent
  
  
  • 500ms GC (see below)
  
  
  • 196ms exposing org/nativescript/widgets/ContentLayout
  
  
  • 28ms exposing android/app/Fragment
  
  
  • 20ms exposing android/os/Bundle
  
  
• 424ms are spent after ngAfterViewInit creating native ui
  
  
  
  • 66ms exposing android/widget/ListView
  
  
  • 22ms exposing android/support/v7/widget/Toolbar
  
  
  • 16ms exposing android/graphics/drawable/Drawable
  
  
  • 62ms exposing android/widget/Button
  
  

• At some point 500ms go for OnGcFinished in the runtime
  Startup time is about 4.800ms.
  We have to track the GC pauses when profiling the JS code.

MarkReachableObjects in the Android time seem to visit 163302 objects starting from the Application_ActivityLifecycleCallbacks taking about 500ms.

[jlooper]

If it could help, the startup time of my non webpacked app is pretty slow, standard with Angular I think: github.com/jlooper/practicebuddy. Recently updated to 3

[PanayotCankov]

@jlooper Rx.js takes 450ms as the whole module is required. When using Rx.js it will be better to require separate operators. There is also about one second delay between the initial appearance of the gradient background and the login form, I am not sure what is the reason but it may be waiting some async operation to complete, such as firebase initialization. Also on tns run ios we've found there are about 300ms. going for live sync initialization and another 500ms. the runtime is waiting for a JavaScript debugger to be attached. These are not present in release, but if they are addressed they will release the debug startup time and will affect positively the {N} image:

• https://github.com/NativeScript/ios-runtime/blob/28c9b2a5ccf799a84f88f4cc0081d82d4cc24505/build/project-template/internal/main.m#L17
• https://github.com/NativeScript/ios-runtime/blob/28c9b2a5ccf799a84f88f4cc0081d82d4cc24505/build/project-template/internal/main.m#L39

Further the app takes about 1500ms. to parse and execute the JavaScript modules for angular, tns-core-modules and nativescript-modules, this about of time is dramatically reduced to about 350ms when webpack with --uglify is used.

It looks possible to drop iOS startup time on iPhone6+ to under a 1sec.

[PanayotCankov]

There is manual instrumentation applied in the tns-core-modules@next, nativescript-angular@next, tns-android@next, and currently on PR for tns-ios@next. When these versions are used, setting "profiling": "timeline" in the app/package.json will enable manual instrumentation within the packages and will print times for key components in the terminal. The app output can then be piped to the npm tool timeline-view to generate HTML timeline view of the times.

To add functions to profile see the "tns-core-module/profiling".profile decorator.

The utility currently just collects log output so you can add whatever traces by manually logging:

var start = profiling.start();
var end = profiling.end();
console.log("Timeline: " + message + "  (" + start + "ms. - " + end + "ms.)");

How to use in apps:

1. Enable profiling in: app/package.json:

{
  "main": "main.js",
  "name": "tns-template-hello-world-ng",
  "version": "3.0.0",
  "profiling": "timeline"
}

1. Install the converter:

npm i -g timeline-view

1. Run the app and pipe the output:

npm run start-ios-bundle --uglify | timeline-view

1. Interact with the app and when done - stop the execution by hitting Ctrl + C in the terminal.
2. The timeline-view will then generate an html file and print path to the generated file. Open it in browser:

Timeline: t.setAttribute  (1244 - 1244) [0]
Timeline: e.onItemLoading  (1240 - 1245) [4]
Timeline: "properties".initNativeView  (1246 - 1247) [0]
^CExiting... Print charts...

Timeline report at: file:///Users/cankov/proj/ngperfapp/times.html

[EddyVerbruggen]

I did some webpack experiments with the Groceries sample app 2 days ago. Didn't change anything in master, only tweaked the scripts in package.json so I was able to run a few measurements.

All times below were timed by hand: from tapping the icon on the homescreen until the UI was visible (splashscreen shows, then a nasty white screen, then the UI shows). So there's roughly a 2 tenths error margin.

[PanayotCankov]

There was a follow up blog-post:
https://www.nativescript.org/blog/deep-dive-into-nativescript-3.1-performance-improvements