rstrong's blog

in search of ponies

  • Home

Navigation Menu

  • « Previous
  • Next »

Categories

  • Mozilla

Firefox JavaScript component startup costs

December 23rd, 2009 by rstrong

I’ve spent some time profiling the startup costs for JavaScript components from the first app-startup notification through the last final-ui-startup notification. I’ve limited the data to just these notifications for the time being in order to keep the focus specifically on this subset of startup cost to make the analysis easier. All times are in milliseconds and the profiling was done on WinCE Firefox trunk using a Tegra device. The patches in Bug 507012 were used and as can be seen the noise is pretty darn small. Where possible I have calculated the difference between the start and end time for each component (this isn’t immediately obvious from the log files) so the data would include at least some of the native code cost for the component during startup. This additional cost is readily apparent in the tables at the end of this post where fuelApplication.js is removed entirely from startup.

Note: get_PB_Enabled is short for PBS_get_privateBrowsingEnabled in nsPrivateBrowsingService.js.

Samples: 50

stage file function avg stdev min max
start to final     3946.148 62.610 (1.59%) 3832.055 4087.264
app-startup     927.774 8.117 (0.87%) 911.413 946.115
app-startup fuelApplication.js JS_Execute 632.945 7.690 (1.21%) 617.986 655.014
app-startup fuelApplication.js init|observe 22.706 0.301 (1.33%) 22.368 23.980
app-startup nsSessionStartup.js JS_Execute 27.703 0.304 (1.10%) 27.271 28.404
app-startup nsSessionStartup.js init|observe 12.801 0.137 (1.07%) 12.645 13.180
app-startup nsBrowserGlue.js JS_Execute 48.739 0.527 (1.08%) 45.564 49.544
app-startup nsBrowserGlue.js init|observe 22.068 0.129 (0.58%) 21.931 22.386
app-startup nsPrivateBrowsingService.js JS_Execute 30.141 0.306 (1.01%) 29.725 31.694
app-startup nsPrivateBrowsingService.js init|observe 21.593 0.177 (0.82%) 21.341 22.277
app-startup WebContentConverter.js JS_Execute 33.150 0.225 (0.68%) 32.904 34.148
app-startup WebContentConverter.js init|observe 9.549 0.073 (0.76%) 9.444 9.741
app-startup nsTryToClose.js JS_Execute 12.994 0.386 (2.97%) 12.587 14.098
app-startup nsTryToClose.js init|observe 10.511 0.247 (2.35%) 10.164 11.232
profile-after-change     343.994 3.557 (1.03%) 337.407 352.034
profile-after-change nsPrivateBrowsingService.js observe 8.906 0.278 (3.12%) 8.232 9.834
profile-after-change nsExtensionManager.js JS_Execute 192.271 3.356 (1.75%) 186.200 199.659
profile-after-change nsExtensionManager.js init|observe 86.652 0.493 (0.57%) 84.153 84.153
profile-after-change nsUpdateTimerManager.js JS_Execute 19.618 0.099 (0.50%) 19.376 19.832
profile-after-change nsUpdateTimerManager.js init|observe 11.913 0.100 (0.84%) 11.779 12.122
profile-after-change nsUpdateServiceStub.js JS_Execute 9.062 0.083 (0.92%) 8.877 9.265
profile-after-change nsUpdateServiceStub.js init 9.599 0.198 (2.06%) 9.396 10.240
command-line-startup     3.953 0.079 (2.00%) 3.866 4.108
command-line-startup nsPrivateBrowsingService.js observe 3.953 0.079 (2.00%) 3.866 4.108
called-from-native nsPrivateBrowsingService.js get_PB_Enabled 2.130 0.085 (4.01%) 2.059 2.450
called-from-native nsExtensionManager.js EM_start 201.015 2.805 (1.40%) 196.609 208.310
final-ui-startup     183.553 0.932 (0.51%) 181.029 186.338
final-ui-startup nsBrowserGlue.js observe 167.908 0.907 (0.54%) 165.127 170.474
final-ui-startup nsSessionStartup.js observe 13.533 0.179 (1.32%) 13.235 13.995
final-ui-startup fuelApplication.js observe 1.637 0.110 (6.73%) 1.564 1.873

 
 
Totals for each component using their averages from the previous table.

Samples: 50

Component JS_Execute CallHooks Total
fuelApplication.js 632.945 24.343 657.288
nsExtensionManager.js 192.271 287.667 479.937
nsBrowserGlue.js 48.739 189.976 238.715
nsPrivateBrowsingService.js 30.141 36.582 66.723
nsSessionStartup.js 27.703 26.334 54.037
WebContentConverter.js 33.150 9.549 42.698
nsUpdateTimerManager.js 19.618 11.913 31.531
nsTryToClose.js 12.994 10.511 23.505
nsUpdateServiceStub.js 9.062 9.599 18.660

 
 
One thing that stands out is that fuelApplication.js appears to be paying a penalty for being the first JavaScript component to load. To verify this I made nsSessionStartup.js load first, fuelApplication.js load second, and analyzed the new data. The results showed that the load first penalty is ≈ 558ms for JS_Execute and ≈ 10ms for the first CallHook.

Totals for each component using their averages with nsSessionStartup.js loading first and fuelApplication.js loading second (complete table not shown).

Samples: 50

Component JS_Execute CallHooks Total
nsSessionStartup.js 584.927 37.141 622.067
nsExtensionManager.js 192.704 288.571 481.275
nsBrowserGlue.js 48.255 189.883 238.138
fuelApplication.js 74.777 15.408 90.185
nsPrivateBrowsingService.js 30.115 36.482 66.597
WebContentConverter.js 33.068 9.534 42.601
nsUpdateTimerManager.js 19.615 11.916 31.530
nsTryToClose.js 12.987 10.508 23.495
nsUpdateServiceStub.js 8.949 9.653 18.602

 
 
There are a couple of things that can be done to the nsExtensionManager.js component that I’ll write about later. Besides optimizing a couple of these components I think that the fuelApplication.js component should either be re-written as a JavaScript module or be removed entirely. With its removal from the startup path startup time is reduced by ≈ 140ms on WinCE Firefox trunk with a Tegra device as can be seen below. I suspect that this would also reduce startup on a few of the Firefox desktop platforms by ≈ 1%.

Filed: Bug 536504 [Firefox] – Remove fuelApplications.js from the startup path [All]

Samples: 30

stage file function avg stdev min max
start to final     3806.027 54.004 (1.42%) 3673.833 3919.366
app-startup     824.938 9.636 (1.17%) 807.022 844.464
app-startup nsSessionStartup.js JS_Execute 569.328 6.921 (1.22%) 554.889 580.804
app-startup nsSessionStartup.js init|observe 23.529 1.419 (6.03%) 21.495 26.296
app-startup nsBrowserGlue.js JS_Execute 52.306 3.796 (7.26%) 36.339 59.105
app-startup nsBrowserGlue.js init|observe 22.714 0.112 (0.50%) 22.513 22.945
app-startup nsPrivateBrowsingService.js JS_Execute 28.945 0.163 (0.56%) 28.527 29.397
app-startup nsPrivateBrowsingService.js init|observe 20.176 0.110 (0.55%) 19.980 20.384
app-startup WebContentConverter.js JS_Execute 35.192 0.173 (0.49%) 34.916 35.591
app-startup WebContentConverter.js init|observe 9.532 0.128 (1.34%) 9.305 9.968
app-startup nsTryToClose.js JS_Execute 13.500 0.560 (4.14%) 13.083 14.826
app-startup nsTryToClose.js init|observe 9.889 0.317 (3.20%) 9.559 10.702
profile-after-change     343.520 5.753 (1.67%) 330.411 360.803
profile-after-change nsPrivateBrowsingService.js observe 5.880 0.442 (7.51%) 4.748 6.569
profile-after-change nsExtensionManager.js JS_Execute 196.433 5.820 (2.96%) 184.414 215.039
profile-after-change nsExtensionManager.js init|observe 86.338 0.264 (0.31%) 85.751 86.854
profile-after-change nsUpdateTimerManager.js JS_Execute 19.623 0.094 (0.48%) 19.428 19.792
profile-after-change nsUpdateTimerManager.js init|observe 11.814 0.111 (0.94%) 11.701 11.701
profile-after-change nsUpdateServiceStub.js JS_Execute 7.826 0.083 (1.06%) 7.608 8.059
profile-after-change nsUpdateServiceStub.js init 9.714 0.080 (0.82%) 9.588 9.882
command-line-startup     4.940 0.073 (1.48%) 4.837 5.111
command-line-startup nsPrivateBrowsingService.js observe 4.940 0.073 (1.48%) 4.837 5.111
called-from-native nsPrivateBrowsingService.js get_PB_Enabled 2.137 0.103 (4.81%) 2.054 2.390
called-from-native nsExtensionManager.js EM_start 197.268 2.809 (1.42%) 193.497 204.272
final-ui-startup     177.882 0.716 (0.40%) 177.263 180.097
final-ui-startup nsBrowserGlue.js observe 164.155 0.631 (0.38%) 163.518 166.598
final-ui-startup nsSessionStartup.js observe 13.495 0.399 (2.96%) 13.215 15.489

 
 
Totals for each component using their averages without fuelApplication.js from the previous table.

Samples: 30

Component JS_Execute CallHooks Total
nsSessionStartup.js 569.328 37.024 606.352
nsExtensionManager.js 196.433 283.605 480.038
nsBrowserGlue.js 52.306 186.869 239.174
nsPrivateBrowsingService.js 28.945 33.134 62.080
WebContentConverter.js 35.192 9.532 44.724
nsUpdateTimerManager.js 19.623 11.814 31.437
nsTryToClose.js 13.500 9.889 23.389
nsUpdateServiceStub.js 7.826 9.714 17.539

 
 
The profile logs used for this analysis include additional details including call stacks and are available for download…
profile logs

Posted in Mozilla    5 Comments

5 Responses to “Firefox JavaScript component startup costs”

  1. on 23 Dec 2009 at 3:13 pm   Taras

    Rob,
    Can you post your patch to produce the log output for above?

  2. on 23 Dec 2009 at 3:17 pm   rstrong

    I plan on it but at present it uses hardcoded line numbers to profile the individual components and I want to have it instead scan the file and figure it out. Also, much of the compilation of the data is currently performed by an OpenOffice Calc spreadsheet.

  3. on 02 Jan 2010 at 12:51 pm   Justin

    I think you may want to use the “approximately equal” symbol (≈) instead of the “congruent to” symbol (≅) in this article.

  4. on 03 Jan 2010 at 3:25 pm   rstrong

    thanks and fixed

  5. on 15 Jan 2010 at 4:08 pm   Firefox Startup Performance – January 15 « dietrich

    [...] I was gone, Rob Strong put up a great post about what JS components are in the startup path and how much time they take [...]

Copyright © rstrong's blog