Closed Bug 987994 Opened 10 years ago Closed 10 years ago

multiple apps regressed cold_load_launch time by 300ms on Mar 24

Categories

(Firefox OS Graveyard :: Gaia::System::Window Mgmt, defect, P1)

ARM
Gonk (Firefox OS)
defect

Tracking

(blocking-b2g:2.0+, b2g-v2.0 fixed)

RESOLVED FIXED
2.0 S2 (23may)
blocking-b2g 2.0+
Tracking Status
b2g-v2.0 --- fixed

People

(Reporter: bkelly, Assigned: alive)

References

Details

(Keywords: perf, regression, Whiteboard: [c=progress p= s= u=2.0] [b2gperf_regression])

Severity: normal → blocker
blocking-b2g: 1.5? → 1.5+
Priority: -- → P1
Whiteboard: [b2gperf_regression] → [c=progress p= s= u=1.5] [b2gperf_regression]
Bug 961800 caused an issue in b2gperf, which meant we needed to update dependencies and push a new release. I don't think the b2gperf changes are likely to have caused this regression, but it is possible, and also possible that updating the version of gaiatest that b2gperf uses caused a regression.

I also noticed bug 987946, which relates to app launching performance but does not involve b2gperf.

Here are the recent b2gperf changes:
https://github.com/mozilla/b2gperf/commit/38f8f9643054d6dfc03ca7749f446cc369bc577d
https://github.com/mozilla/b2gperf/commit/ac9b104566de1341142db899d4b01dec0a5b8f3c
https://github.com/mozilla/b2gperf/commit/1dba265dfff7ccf9c83f4fe60bca5454c49cc311
https://github.com/mozilla/b2gperf/commit/1c092edee5fb60d7cd15c2d4ac18fe9c053d832f
This isn't conclusive, but I ran b2ghaystack [1] for the good/bad gecko revisions and couldn't replicate on mozilla-central or mozilla-inbound builds. I did find however that the first build selected in b2g-inbound showed higher launch times similar to the regression.

Revision: 79e0f5671f99d2ccf70013f464f6a64e789ed5cf
Timestamp: 23 March 2014 23:12:15
Location: https://pvtbuilds.mozilla.org/pvt/mozilla.org/b2gotoro/tinderbox-builds/b2g-inbound-hamachi-eng/20140323231215/

Results:
Settings, cold_load_time: median:1596, mean:1610, std: 73, max:1976, min:1513, all:1645,1513,1568,1583,1551,1588,1594,1613,1595,1571,1605,1596,1976,1575,1597,1622,1638,1619,1602,1593,1619,1610,1590,1595,1588,1617,1643,1569,1618,1621


Here's the pushlog, which includes bug 961800: http://hg.mozilla.org/integration/b2g-inbound/pushloghtml?fromchange=fa098f9fe89c&tochange=79e0f5671f99

[1] https://github.com/davehunt/b2ghaystack
Hmm, interesting behavior in the graphs now.  It appears settings has stayed at its regressed level, but the other apps have dropped back down to one degree or another.  Some are still at regressed launch times, some are back to normal, and some are faster.  This looks... confusing.
Oh, and now browser as regressed another full second?
The variance may be related to the device firmware. It appears the recent low values have earlier firmware. I'm going to deduce which devices these are and file a bug to update them all to be on the same version.
I raised bug 988465 for the firmware version issue, and taken the device with older firmware temporarily offline.
This regression is also noticeable in the Eideticker results, for example: http://eideticker.mozilla.org/b2g/#/inari/b2g-settings-startup/timetostableframe
Looking at the detail view, it appears we're on the loading screen (with the app icon centered) for longer. The fact we can replicate on Eideticker means we can rule out b2gperf as a cause.

Good:
http://eideticker.mozilla.org/b2g/detail.html?id=41881878b42a11e3919bf0def1767b24#/framediffsums

Bad:
http://eideticker.mozilla.org/b2g/detail.html?id=6caa723cb4eb11e3b13ff0def1767b24#/framediffsums
Since removing the firmware variability the results appear to be stable (yet still regressed).
(In reply to Dave Hunt (:davehunt) from comment #9)
> Since removing the firmware variability the results appear to be stable (yet
> still regressed).

Thank you Dave!  This should help make analysis easier all around.

I wonder if we should consider adding an "expected firmware version" to our test infrastructure and flag any results not on that version.
Assignee: nobody → dhuseby
Whiteboard: [c=progress p= s= u=1.5] [b2gperf_regression] → [c=progress p=2 s= u=1.5] [b2gperf_regression]
FYI, still seeing multiple regressions as of March 31st.  I'll get on the bisect.
gecko a9f77f8
gaia d4655e7
Results for Settings, cold_load_time: median:1416, mean:1439, std: 54, max:1582, min:1376
gecko a9f77f8
gaia 9da1b9c
Results for Settings, cold_load_time: median:1752, mean:1760, std: 34, max:1907, min:1727
gecko b31f92b
gaia d4655e7
Results for Settings, cold_load_time: median:1441, mean:1466, std: 81, max:1821, min:1413
gecko b31f92b
gaia 9da1b9c
Results for Settings, cold_load_time: median:1725, mean:1739, std: 49, max:1929, min:1704


the regression is in gaia.
git bisect start 9da1b9c11bf5 d4655e7fed7403

gaia 9e90675
Results for Settings, cold_load_time: median:1737, mean:1750, std: 59, max:1936, min:1613
git bisect bad

gaia f7700e6
Results for Settings, cold_load_time: median:1735, mean:1764, std: 136, max:2475, min:1669
git bisect bad

gaia 80af23f
Results for Settings, cold_load_time: median:1735, mean:1740, std: 34, max:1851, min:1669
git bisect bad

gaia befb78c
Results for Settings, cold_load_time: median:1400, mean:1423, std: 57, max:1603, min:1345
git bisect good

gaia 5c0b527
Results for Settings, cold_load_time: median:1736, mean:1747, std: 48, max:1952, min:1685
git bisect bad

gaia 439e40e
Results for Settings, cold_load_time: median:1727, mean:1731, std: 46, max:1935, min:1627
git bisect bad

439e40ef0e79393f94ca102b9fbd0785355e4b34 is the first bad commit
commit 439e40ef0e79393f94ca102b9fbd0785355e4b34
Author: Alive Kuo <alegnadise@gmail.com>
Date:   Mon Feb 3 11:49:44 2014 +0100

    Bug 961800 - Implement Child Window Factory.
    
    Conflicts:
        apps/system/js/app_transition_controller.js
        apps/system/js/app_window.js
        apps/system/js/app_window_manager.js
        apps/system/js/cards_view.js
        apps/system/style/window.css

:100644 100644 635b6e3f784982c7c3944ba50a05a3259b8a8fab 11c79904ce42b229c18a28d24c9bd20ed718dda8 M      Makefile
:040000 040000 e3b5cbb0db28d2a6e75962207f44dc2a630d7e10 d3cc2b91fe4a8ae471ab9e2f3ee3eb7c0f246305 M      apps
:040000 040000 c787ffbabb879c3fc111407aefdefa257f68b019 b27d5e19622014e8f61747a18627aa521d5a890b M      build
:040000 040000 4ca18cee8ccb928feb6bd18f06d287330d8bf5ee eef9f32e75e5581c3561fcb17cd2dc21085761e6 M      test_apps
:040000 040000 ae9d9dfa93d8af9eb44623fd2b4466036a5f4cbb 154ad42f68f34472427c9bf1b6a07ff7f199882d M      tests
Here's another perf regression for you.  Can you help break this up or pinpoint what the cause is.  This patch is huge and touches lots of things.
Flags: needinfo?(alive)
This bug too.  I suspect this one may also be caused by moving when the System app fires the event.
Flags: needinfo?(hub)
Same thing with this bug.  The child window launcher rewrite might have changed the relative timing but not actually slow down the app launch times.  Can you help me determine if the regression is a false positive?
Flags: needinfo?(wlachance)
I'd like to help but after re-read my patch I cannot figure out why.
The apploadtime is exactly [loadend event time -  launch time(after mozbrowser element rendering)].
But the code should not touch them.
The main difference is there's a mozbrowseropenwindow event handler injected, but since app won't open a new window when it's launching, this handler shall not matter.

I will do some more manual tests this afternoon.
Flags: needinfo?(alive)
I try to enable DEBUG flag in appWindow and observe settings app launch time,
but it doesn't seem much gain from w/ or w/o bug 961800 to me...
It's usually 2.x sec on my unagi.

############ Without bug 961800 #############
[Dump: AppWindow][Music][154.955] publishing external event: willrender
[Dump: AppWindow][Music][155.013] publishing internal event: rendered
[Dump: AppWindow][Music][155.015] publishing external event: rendered
[Dump: AppWindow][Music][155.019]installing sub components...
[Dump: AppWindow][Music][155.025] publishing internal event: created
[Dump: AppWindow][Music][155.026] publishing external event: created
[Dump: AppWindow][Music][155.038]requesting to open
[Dump: AppWindow][Music][155.039]loaded yet
[Dump: HomescreenWindow][Homescreen][155.095]portrait-primary
[Dump: AppWindow][Music][155.097]open with undefined
[Dump: AppWindow][Music][155.099]closed,opening,::,open
[Dump: AppWindow][Music][155.105] publishing internal event: opening
[Dump: AppWindow][Music][155.108] fade in <<<<<
[Dump: AppWindow][Music][155.110]Dump: set visibility -> ,true
[Dump: AppWindow][Music][155.111]before showing frame
[Dump: AppWindow][Music][155.112]setVisible on browser element:true
[Dump: AppWindow][Music][155.114]screenshot state -> ,frame
[Dump: AppWindow][Music][155.116] publishing external event: opening
[Dump: AppWindow][Music][155.119] publishing internal event: willopen
[Dump: AppWindow][Music][155.120] publishing external event: willopen
[Dump: HomescreenWindow][Homescreen][155.123]close with undefined
[Dump: HomescreenWindow][Homescreen][155.125]opened,closing,::,close
[Dump: HomescreenWindow][Homescreen][155.127] publishing internal event: closing
[Dump: HomescreenWindow][Homescreen][155.130] publishing external event: closing
[Dump: HomescreenWindow][Homescreen][155.131] publishing internal event: willclose
[Dump: HomescreenWindow][Homescreen][155.132] publishing external event: willclose
[Dump: AppWindow][Music][155.327] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][155.330] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][155.336] publishing internal event: loading
[Dump: AppWindow][Music][155.337] publishing external event: loading
[Dump: HomescreenWindow][Homescreen][155.486]zoom-in has been ENDED!
[Dump: HomescreenWindow][Homescreen][155.487]closing,closed,::,complete
[Dump: HomescreenWindow][Homescreen][155.493] publishing internal event: closed
[Dump: HomescreenWindow][Homescreen][155.504]Dump: set visibility -> ,false
[Dump: HomescreenWindow][Homescreen][155.508]setVisible on browser element:false
[Dump: HomescreenWindow][Homescreen][155.524]screenshot state -> ,none
[Dump: HomescreenWindow][Homescreen][155.529] publishing external event: closed
[Dump: HomescreenWindow][Homescreen][155.536] publishing internal event: close
[Dump: HomescreenWindow][Homescreen][155.541] publishing external event: close
[Dump: AppWindow][Music][155.543]openApp has been ENDED!
[Dump: AppWindow][Music][155.551]opening,opened,::,complete
[Dump: AppWindow][Music][155.560] publishing internal event: opened
[Dump: AppWindow][Music][155.563]Dump: set visibility -> ,true
[Dump: AppWindow][Music][155.564]before showing frame
[Dump: AppWindow][Music][155.575]setVisible on browser element:true
[Dump: AppWindow][Music][155.578]screenshot state -> ,frame
[Dump: AppWindow][Music][155.581] locking screen orientation to default
[Dump: AppWindow][Music][155.594] publishing external event: opened
[Dump: AppWindow][Music][155.601] publishing internal event: open
[Dump: AppWindow][Music][155.612] publishing external event: open
[Dump: HomescreenWindow][Homescreen][156.011] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][156.012] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][156.016] publishing internal event: background
[Dump: HomescreenWindow][Homescreen][156.017] publishing external event: background
[Dump: AppWindow][Music][156.123] nextpaint is timeouted.
[Dump: AppWindow][Music][157.021] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][157.023] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][157.024] publishing internal event: locationchange
[Dump: AppWindow][Music][157.034] publishing external event: locationchange
[Dump: AppWindow][Music][157.421] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][157.422] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][157.424] publishing internal event: titlechange
[Dump: AppWindow][Music][157.436] publishing external event: titlechange
[Dump: AppWindow][Music][157.716] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][157.718] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][157.720] publishing internal event: loadtime
[Dump: AppWindow][Music][157.722] publishing external event: loadtime
[Dump: AppWindow][Music][157.734] publishing internal event: loaded
[Dump: AppWindow][Music][157.736] publishing external event: loaded
[Dump: AppWindow][Music][157.737]bgcolor= ,rgb(0, 0, 0)
[Dump: AppWindow][Music][157.738]setting background color..


[Dump: AppWindow][Music][115.008] publishing external event: willrender
[Dump: AppWindow][Music][115.048] publishing internal event: rendered
[Dump: AppWindow][Music][115.050] publishing external event: rendered
[Dump: AppWindow][Music][115.051]installing sub components...
[Dump: AppWindow][Music][115.055] publishing internal event: created
[Dump: AppWindow][Music][115.056] publishing external event: created
[Dump: AppWindow][Music][115.060]requesting to open
[Dump: AppWindow][Music][115.061]loaded yet
[Dump: HomescreenWindow][Homescreen][115.114]portrait-primary
[Dump: AppWindow][Music][115.115]open with undefined
[Dump: AppWindow][Music][115.117]closed,opening,::,open
[Dump: AppWindow][Music][115.129] publishing internal event: opening
[Dump: AppWindow][Music][115.131] fade in <<<<<
[Dump: AppWindow][Music][115.132]Dump: set visibility -> ,true
[Dump: AppWindow][Music][115.133]before showing frame
[Dump: AppWindow][Music][115.135]setVisible on browser element:true
[Dump: AppWindow][Music][115.140]screenshot state -> ,frame
[Dump: AppWindow][Music][115.141] publishing external event: opening
[Dump: AppWindow][Music][115.143] publishing internal event: willopen
[Dump: AppWindow][Music][115.144] publishing external event: willopen
[Dump: HomescreenWindow][Homescreen][115.147]close with undefined
[Dump: HomescreenWindow][Homescreen][115.148]opened,closing,::,close
[Dump: HomescreenWindow][Homescreen][115.150] publishing internal event: closing
[Dump: HomescreenWindow][Homescreen][115.152] publishing external event: closing
[Dump: HomescreenWindow][Homescreen][115.154] publishing internal event: willclose
[Dump: HomescreenWindow][Homescreen][115.155] publishing external event: willclose
[Dump: AppWindow][Music][115.232] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][115.233] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][115.238] publishing internal event: loading
[Dump: AppWindow][Music][115.240] publishing external event: loading
[Dump: HomescreenWindow][Homescreen][115.530]zoom-in has been ENDED!
[Dump: HomescreenWindow][Homescreen][115.539]closing,closed,::,complete
[Dump: HomescreenWindow][Homescreen][115.544] publishing internal event: closed
[Dump: HomescreenWindow][Homescreen][115.545]Dump: set visibility -> ,false
[Dump: HomescreenWindow][Homescreen][115.554]setVisible on browser element:false
[Dump: HomescreenWindow][Homescreen][115.566]screenshot state -> ,none
[Dump: HomescreenWindow][Homescreen][115.579] publishing external event: closed
[Dump: HomescreenWindow][Homescreen][115.581] publishing internal event: close
[Dump: HomescreenWindow][Homescreen][115.582] publishing external event: close
[Dump: AppWindow][Music][115.587]openApp has been ENDED!
[Dump: AppWindow][Music][115.588]opening,opened,::,complete
[Dump: AppWindow][Music][115.606] publishing internal event: opened
[Dump: AppWindow][Music][115.609]Dump: set visibility -> ,true
[Dump: AppWindow][Music][115.619]before showing frame
[Dump: AppWindow][Music][115.620]setVisible on browser element:true
[Dump: AppWindow][Music][115.631]screenshot state -> ,frame
[Dump: AppWindow][Music][115.634] locking screen orientation to default
[Dump: AppWindow][Music][115.640] publishing external event: opened
[Dump: AppWindow][Music][115.661] publishing internal event: open
[Dump: AppWindow][Music][115.677] publishing external event: open
[Dump: HomescreenWindow][Homescreen][116.047] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][116.056] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][116.058] publishing internal event: background
[Dump: HomescreenWindow][Homescreen][116.059] publishing external event: background
[Dump: AppWindow][Music][116.165] nextpaint is timeouted.
[Dump: AppWindow][Music][117.055] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][117.057] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][117.058] publishing internal event: locationchange
[Dump: AppWindow][Music][117.060] publishing external event: locationchange
[Dump: AppWindow][Music][117.502] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][117.517] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][117.518] publishing internal event: titlechange
[Dump: AppWindow][Music][117.520] publishing external event: titlechange
[Dump: AppWindow][Music][117.782] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][117.784] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][117.786] publishing internal event: loadtime
[Dump: AppWindow][Music][117.791] publishing external event: loadtime
[Dump: AppWindow][Music][117.794] publishing internal event: loaded
[Dump: AppWindow][Music][117.796] publishing external event: loaded
[Dump: AppWindow][Music][117.811]bgcolor= ,rgb(0, 0, 0)
[Dump: AppWindow][Music][117.813]setting background color..


############ With bug 961800 ################
====== Music app cold launch ======
[Dump: AppWindow][Music][AppWindow-0][160.570] publishing external event: willrender
[Dump: AppWindow][Music][AppWindow-0][160.626] publishing internal event: rendered
[Dump: AppWindow][Music][AppWindow-0][160.627] publishing external event: rendered
[Dump: AppWindow][Music][AppWindow-0][160.631]installing sub components...
[Dump: AppWindow][Music][AppWindow-0][160.638] publishing internal event: created
[Dump: AppWindow][Music][AppWindow-0][160.639] publishing external event: created
[Dump: AppWindow][Music][AppWindow-0][160.652]requesting to open
[Dump: AppWindow][Music][AppWindow-0][160.654]loaded yet
[Dump: HomescreenWindow][Homescreen][homescreen][160.709]portrait-primary
[Dump: AppWindow][Music][AppWindow-0][160.711]open with undefined
[Dump: AppWindow][Music][AppWindow-0][160.713]closed,opening,::,open
[Dump: AppWindow][Music][AppWindow-0][160.727] publishing internal event: opening
[Dump: AppWindow][Music][AppWindow-0][160.730] fade in <<<<<
[Dump: AppWindow][Music][AppWindow-0][160.731]Dump: set visibility -> ,true
[Dump: AppWindow][Music][AppWindow-0][160.732]before showing frame
[Dump: AppWindow][Music][AppWindow-0][160.734]setVisible on browser element:true
[Dump: AppWindow][Music][AppWindow-0][160.741]screenshot state -> ,frame
[Dump: AppWindow][Music][AppWindow-0][160.743] publishing external event: opening
[Dump: AppWindow][Music][AppWindow-0][160.746] publishing internal event: willopen
[Dump: AppWindow][Music][AppWindow-0][160.748] publishing external event: willopen
[Dump: HomescreenWindow][Homescreen][homescreen][160.751]close with undefined
[Dump: HomescreenWindow][Homescreen][homescreen][160.753]opened,closing,::,close
[Dump: HomescreenWindow][Homescreen][homescreen][160.755] publishing internal event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][160.758] publishing external event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][160.759] publishing internal event: willclose
[Dump: HomescreenWindow][Homescreen][homescreen][160.760] publishing external event: willclose
[Dump: AppWindow][Music][AppWindow-0][160.840] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][AppWindow-0][160.841] Handling mozbrowserloadstart event...
[Dump: AppWindow][Music][AppWindow-0][160.843] publishing internal event: loading
[Dump: AppWindow][Music][AppWindow-0][160.844] publishing external event: loading
[Dump: HomescreenWindow][Homescreen][homescreen][161.094]zoom-in has been ENDED!
[Dump: HomescreenWindow][Homescreen][homescreen][161.096]closing,closed,::,complete
[Dump: HomescreenWindow][Homescreen][homescreen][161.112] publishing internal event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][161.114]Dump: set visibility -> ,false
[Dump: HomescreenWindow][Homescreen][homescreen][161.116]setVisible on browser element:false
[Dump: HomescreenWindow][Homescreen][homescreen][161.135]screenshot state -> ,none
[Dump: HomescreenWindow][Homescreen][homescreen][161.140] publishing external event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][161.146] publishing internal event: close
[Dump: HomescreenWindow][Homescreen][homescreen][161.148] publishing external event: close
[Dump: AppWindow][Music][AppWindow-0][161.149]openApp has been ENDED!
[Dump: AppWindow][Music][AppWindow-0][161.150]opening,opened,::,complete
[Dump: AppWindow][Music][AppWindow-0][161.153] publishing internal event: opened
[Dump: AppWindow][Music][AppWindow-0][161.169]Dump: set visibility -> ,true
[Dump: AppWindow][Music][AppWindow-0][161.177]before showing frame
[Dump: AppWindow][Music][AppWindow-0][161.181]setVisible on browser element:true
[Dump: AppWindow][Music][AppWindow-0][161.187]screenshot state -> ,frame
[Dump: AppWindow][Music][AppWindow-0][161.192] locking screen orientation to default
[Dump: AppWindow][Music][AppWindow-0][161.207] publishing external event: opened
[Dump: HomescreenWindow][Homescreen][homescreen][161.218] fade out >>>>
[Dump: AppWindow][Music][AppWindow-0][161.221] publishing internal event: open
[Dump: AppWindow][Music][AppWindow-0][161.223] publishing external event: open
[Dump: HomescreenWindow][Homescreen][homescreen][161.619] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][161.620] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][161.622] publishing internal event: background
[Dump: HomescreenWindow][Homescreen][homescreen][161.623] publishing external event: background
[Dump: AppWindow][Music][AppWindow-0][161.723] nextpaint is timeouted.
[Dump: AppWindow][Music][AppWindow-0][162.637] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][AppWindow-0][162.639] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Music][AppWindow-0][162.641] publishing internal event: locationchange
[Dump: AppWindow][Music][AppWindow-0][162.642] publishing external event: locationchange
[Dump: AppWindow][Music][AppWindow-0][163.001] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][AppWindow-0][163.002] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Music][AppWindow-0][163.004] publishing internal event: titlechange
[Dump: AppWindow][Music][AppWindow-0][163.018] publishing external event: titlechange
[Dump: AppWindow][Music][AppWindow-0][163.409] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][AppWindow-0][163.413] Handling mozbrowserloadend event...
[Dump: AppWindow][Music][AppWindow-0][163.426] publishing internal event: loadtime
[Dump: AppWindow][Music][AppWindow-0][163.433] publishing external event: loadtime
[Dump: AppWindow][Music][AppWindow-0][163.448] publishing internal event: loaded
[Dump: AppWindow][Music][AppWindow-0][163.450] publishing external event: loaded
[Dump: AppWindow][Music][AppWindow-0][163.459]bgcolor= ,rgb(0, 0, 0)
[Dump: AppWindow][Music][AppWindow-0][163.465]setting background color..


======= Settings app cold launch =======
[Dump: AppWindow][Settings][AppWindow-1][789.675] publishing external event: willrender
[Dump: AppWindow][Settings][AppWindow-1][789.720] publishing internal event: rendered
[Dump: AppWindow][Settings][AppWindow-1][789.722] publishing external event: rendered
[Dump: AppWindow][Settings][AppWindow-1][789.725]installing sub components...
[Dump: AppWindow][Settings][AppWindow-1][789.730] publishing internal event: created
[Dump: AppWindow][Settings][AppWindow-1][789.731] publishing external event: created
[Dump: AppWindow][Settings][AppWindow-1][789.737]requesting to open
[Dump: AppWindow][Settings][AppWindow-1][789.738]loaded yet
[Dump: HomescreenWindow][Homescreen][homescreen][789.804]portrait-primary
[Dump: AppWindow][Settings][AppWindow-1][789.806]open with undefined
[Dump: AppWindow][Settings][AppWindow-1][789.808]closed,opening,::,open
[Dump: AppWindow][Settings][AppWindow-1][789.810] publishing internal event: opening
[Dump: AppWindow][Settings][AppWindow-1][789.818] fade in <<<<<
[Dump: AppWindow][Settings][AppWindow-1][789.819]Dump: set visibility -> ,true
[Dump: AppWindow][Settings][AppWindow-1][789.820]before showing frame
[Dump: AppWindow][Settings][AppWindow-1][789.822]setVisible on browser element:true
[Dump: AppWindow][Settings][AppWindow-1][789.828]screenshot state -> ,frame
[Dump: AppWindow][Settings][AppWindow-1][789.829] publishing external event: opening
[Dump: AppWindow][Settings][AppWindow-1][789.835] publishing internal event: willopen
[Dump: AppWindow][Settings][AppWindow-1][789.837] publishing external event: willopen
[Dump: HomescreenWindow][Homescreen][homescreen][789.843]close with undefined
[Dump: HomescreenWindow][Homescreen][homescreen][789.844]opened,closing,::,close
[Dump: HomescreenWindow][Homescreen][homescreen][789.847] publishing internal event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][789.849] publishing external event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][789.851] publishing internal event: willclose
[Dump: HomescreenWindow][Homescreen][homescreen][789.852] publishing external event: willclose
[Dump: AppWindow][Settings][AppWindow-1][789.977] Handling mozbrowserloadstart event...
[Dump: AppWindow][Settings][AppWindow-1][789.978] Handling mozbrowserloadstart event...
[Dump: AppWindow][Settings][AppWindow-1][789.989] publishing internal event: loading
[Dump: AppWindow][Settings][AppWindow-1][789.991] publishing external event: loading
[Dump: HomescreenWindow][Homescreen][homescreen][790.299]zoom-in has been ENDED!
[Dump: HomescreenWindow][Homescreen][homescreen][790.300]closing,closed,::,complete
[Dump: HomescreenWindow][Homescreen][homescreen][790.313] publishing internal event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][790.314]Dump: set visibility -> ,false
[Dump: HomescreenWindow][Homescreen][homescreen][790.321]setVisible on browser element:false
[Dump: HomescreenWindow][Homescreen][homescreen][790.344]screenshot state -> ,none
[Dump: HomescreenWindow][Homescreen][homescreen][790.349] publishing external event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][790.351] publishing internal event: close
[Dump: HomescreenWindow][Homescreen][homescreen][790.358] publishing external event: close
[Dump: AppWindow][Settings][AppWindow-1][790.368]openApp has been ENDED!
[Dump: AppWindow][Settings][AppWindow-1][790.369]opening,opened,::,complete
[Dump: AppWindow][Settings][AppWindow-1][790.380] publishing internal event: opened
[Dump: AppWindow][Settings][AppWindow-1][790.389]Dump: set visibility -> ,true
[Dump: AppWindow][Settings][AppWindow-1][790.390]before showing frame
[Dump: AppWindow][Settings][AppWindow-1][790.397]setVisible on browser element:true
[Dump: AppWindow][Settings][AppWindow-1][790.407]screenshot state -> ,frame
[Dump: AppWindow][Settings][AppWindow-1][790.411] locking screen orientation to default
[Dump: AppWindow][Settings][AppWindow-1][790.427] publishing external event: opened
[Dump: HomescreenWindow][Homescreen][homescreen][790.436] fade out >>>>
[Dump: AppWindow][Settings][AppWindow-1][790.440] publishing internal event: open
[Dump: AppWindow][Settings][AppWindow-1][790.441] publishing external event: open
[Dump: HomescreenWindow][Homescreen][homescreen][790.732] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][790.734] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][790.737] publishing internal event: background
[Dump: HomescreenWindow][Homescreen][homescreen][790.738] publishing external event: background
[Dump: AppWindow][Settings][AppWindow-1][791.095] nextpaint is timeouted.
[Dump: AppWindow][Settings][AppWindow-1][791.919] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Settings][AppWindow-1][791.921] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Settings][AppWindow-1][791.922] publishing internal event: locationchange
[Dump: AppWindow][Settings][AppWindow-1][791.924] publishing external event: locationchange
[Dump: AppWindow][Settings][AppWindow-1][792.184] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Settings][AppWindow-1][792.185] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Settings][AppWindow-1][792.197] publishing internal event: titlechange
[Dump: AppWindow][Settings][AppWindow-1][792.199] publishing external event: titlechange
[Dump: AppWindow][Settings][AppWindow-1][793.460] Handling mozbrowserloadend event...
[Dump: AppWindow][Settings][AppWindow-1][793.465] Handling mozbrowserloadend event... 
[Dump: AppWindow][Settings][AppWindow-1][793.475] publishing internal event: loadtime
[Dump: AppWindow][Settings][AppWindow-1][793.477] publishing external event: loadtime
[Dump: AppWindow][Settings][AppWindow-1][793.489] publishing internal event: loaded
[Dump: AppWindow][Settings][AppWindow-1][793.493] publishing external event: loaded
[Dump: AppWindow][Settings][AppWindow-1][793.494]bgcolor= ,rgb(244, 244, 244)
[Dump: AppWindow][Settings][AppWindow-1][793.495]setting background color..

############# next paint improve #############
 [Dump: AppWindow][Settings][AppWindow-1][181.068] publishing external event: willrender
 [Dump: AppWindow][Settings][AppWindow-1][181.100] publishing internal event: rendered
 [Dump: AppWindow][Settings][AppWindow-1][181.102] publishing external event: rendered
 [Dump: AppWindow][Settings][AppWindow-1][181.105]installing sub components...
 [Dump: AppWindow][Settings][AppWindow-1][181.109] publishing internal event: created
 [Dump: AppWindow][Settings][AppWindow-1][181.111] publishing external event: created
 [Dump: AppWindow][Settings][AppWindow-1][181.117]requesting to open
 [Dump: AppWindow][Settings][AppWindow-1][181.118]loaded yet
 [Dump: AppWindow][Settings][AppWindow-1][181.139]open with undefined
 [Dump: AppWindow][Settings][AppWindow-1][181.141]closed,opening,::,open
 [Dump: AppWindow][Settings][AppWindow-1][181.143] publishing internal event: opening
 [Dump: AppWindow][Settings][AppWindow-1][181.145] fade in <<<<<
 [Dump: AppWindow][Settings][AppWindow-1][181.151]Dump: set visibility -> ,true
 [Dump: AppWindow][Settings][AppWindow-1][181.152]before showing frame
 [Dump: AppWindow][Settings][AppWindow-1][181.153]setVisible on browser element:true
 [Dump: AppWindow][Settings][AppWindow-1][181.158]screenshot state -> ,frame
 [Dump: AppWindow][Settings][AppWindow-1][181.159] publishing external event: opening
 [Dump: AppWindow][Settings][AppWindow-1][181.168] publishing internal event: willopen
 [Dump: AppWindow][Settings][AppWindow-1][181.169] publishing external event: willopen
 [Dump: HomescreenWindow][Homescreen][homescreen][181.172]close with undefined
 [Dump: HomescreenWindow][Homescreen][homescreen][181.174]opened,closing,::,close
 [Dump: HomescreenWindow][Homescreen][homescreen][181.176] publishing internal event: closing
 [Dump: HomescreenWindow][Homescreen][homescreen][181.179] publishing external event: closing
 [Dump: HomescreenWindow][Homescreen][homescreen][181.181] publishing internal event: willclose
 [Dump: HomescreenWindow][Homescreen][homescreen][181.182] publishing external event: willclose
 [Dump: AppWindow][Settings][AppWindow-1][181.266] Handling mozbrowserloadstart event...
 [Dump: AppWindow][Settings][AppWindow-1][181.269] Handling mozbrowserloadstart event...
 [Dump: AppWindow][Settings][AppWindow-1][181.277] publishing internal event: loading
 [Dump: AppWindow][Settings][AppWindow-1][181.278] publishing external event: loading
 [Dump: AppWindow][Settings][AppWindow-1][181.369] Handling mozbrowserlocationchange event...
 [Dump: AppWindow][Settings][AppWindow-1][181.376] Handling mozbrowserlocationchange event...
 [Dump: AppWindow][Settings][AppWindow-1][181.385] publishing internal event: locationchange
 [Dump: AppWindow][Settings][AppWindow-1][181.387] publishing external event: locationchange
 [Dump: HomescreenWindow][Homescreen][homescreen][181.493]zoom-in has been ENDED!
 [Dump: HomescreenWindow][Homescreen][homescreen][181.495]closing,closed,::,complete
 [Dump: HomescreenWindow][Homescreen][homescreen][181.502] publishing internal event: closed
 [Dump: HomescreenWindow][Homescreen][homescreen][181.508]Dump: set visibility -> ,false
 [Dump: HomescreenWindow][Homescreen][homescreen][181.512]setVisible on browser element:false
 [Dump: HomescreenWindow][Homescreen][homescreen][181.533]screenshot state -> ,none
 [Dump: HomescreenWindow][Homescreen][homescreen][181.541] publishing external event: closed
 [Dump: HomescreenWindow][Homescreen][homescreen][181.544] publishing internal event: close
 [Dump: HomescreenWindow][Homescreen][homescreen][181.551] publishing external event: close
 [Dump: AppWindow][Settings][AppWindow-1][181.553]openApp has been ENDED!
 [Dump: AppWindow][Settings][AppWindow-1][181.558]opening,opened,::,complete
 [Dump: AppWindow][Settings][AppWindow-1][181.565] publishing internal event: opened
 [Dump: AppWindow][Settings][AppWindow-1][181.572]Dump: set visibility -> ,true
 [Dump: AppWindow][Settings][AppWindow-1][181.573]before showing frame
 [Dump: AppWindow][Settings][AppWindow-1][181.574]setVisible on browser element:true
 [Dump: AppWindow][Settings][AppWindow-1][181.583]screenshot state -> ,frame
 [Dump: AppWindow][Settings][AppWindow-1][181.585] locking screen orientation to default
 [Dump: AppWindow][Settings][AppWindow-1][181.591]aw__dump@app://system.gaiamobile.org/js/app_window.js:175
E/GeckoConsole(  519): AppWindow.prototype.publish@app://system.gaiamobile.org/js/app_window.js:949
 [Dump: AppWindow][Settings][AppWindow-1][181.593] publishing external event: opened
 [Dump: HomescreenWindow][Homescreen][homescreen][181.605] fade out >>>>
 [Dump: AppWindow][Settings][AppWindow-1][181.607] publishing internal event: open
 [Dump: AppWindow][Settings][AppWindow-1][181.609] publishing external event: open
 [Dump: HomescreenWindow][Homescreen][homescreen][181.809] Handling mozbrowservisibilitychange event...
 [Dump: HomescreenWindow][Homescreen][homescreen][181.811] Handling mozbrowservisibilitychange event...
 [Dump: HomescreenWindow][Homescreen][homescreen][181.813] publishing internal event: background
 [Dump: HomescreenWindow][Homescreen][homescreen][181.815] publishing external event: background
 [Dump: AppWindow][Settings][AppWindow-1][181.827] Handling mozbrowsertitlechange event...
 [Dump: AppWindow][Settings][AppWindow-1][181.829] Handling mozbrowsertitlechange event...
 [Dump: AppWindow][Settings][AppWindow-1][181.839] publishing internal event: titlechange
 [Dump: AppWindow][Settings][AppWindow-1][181.851] publishing external event: titlechange
 [Dump: AppWindow][Settings][AppWindow-1][182.943] Handling mozbrowserloadend event...
 [Dump: AppWindow][Settings][AppWindow-1][182.946] Handling mozbrowserloadend event...
 [Dump: AppWindow][Settings][AppWindow-1][182.948] publishing internal event: loadtime
 [Dump: AppWindow][Settings][AppWindow-1][182.959] publishing external event: loadtime
 [Dump: AppWindow][Settings][AppWindow-1][182.962] publishing internal event: loaded
 [Dump: AppWindow][Settings][AppWindow-1][182.963] publishing external event: loaded
 [Dump: AppWindow][Settings][AppWindow-1][182.965]bgcolor= ,rgb(244, 244, 244)
 [Dump: AppWindow][Settings][AppWindow-1][182.966]setting background color..


 [Dump: AppWindow][Settings][AppWindow-4][770.627] publishing external event: willrender
[Dump: AppWindow][Settings][AppWindow-4][770.666] publishing internal event: rendered
[Dump: AppWindow][Settings][AppWindow-4][770.668] publishing external event: rendered
[Dump: AppWindow][Settings][AppWindow-4][770.672]installing sub components...
[Dump: AppWindow][Settings][AppWindow-4][770.678] publishing internal event: created
[Dump: AppWindow][Settings][AppWindow-4][770.679] publishing external event: created
[Dump: AppWindow][Settings][AppWindow-4][770.692]requesting to open
[Dump: AppWindow][Settings][AppWindow-4][770.694]loaded yet
[Dump: AppWindow][Settings][AppWindow-4][770.762]open with undefined
[Dump: AppWindow][Settings][AppWindow-4][770.764]closed,opening,::,open
[Dump: AppWindow][Settings][AppWindow-4][770.772] publishing internal event: opening
[Dump: AppWindow][Settings][AppWindow-4][770.777] fade in <<<<<
[Dump: AppWindow][Settings][AppWindow-4][770.778]Dump: set visibility -> ,true
[Dump: AppWindow][Settings][AppWindow-4][770.788]before showing frame
[Dump: AppWindow][Settings][AppWindow-4][770.789]setVisible on browser element:true
[Dump: AppWindow][Settings][AppWindow-4][770.792]screenshot state -> ,frame
[Dump: AppWindow][Settings][AppWindow-4][770.793] publishing external event: opening
[Dump: AppWindow][Settings][AppWindow-4][770.798] publishing internal event: willopen
[Dump: AppWindow][Settings][AppWindow-4][770.800] publishing external event: willopen
[Dump: HomescreenWindow][Homescreen][homescreen][770.803]close with undefined
[Dump: HomescreenWindow][Homescreen][homescreen][770.804]opened,closing,::,close
[Dump: HomescreenWindow][Homescreen][homescreen][770.807] publishing internal event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][770.809] publishing external event: closing
[Dump: HomescreenWindow][Homescreen][homescreen][770.810] publishing internal event: willclose
[Dump: HomescreenWindow][Homescreen][homescreen][770.812] publishing external event: willclose
[Dump: AppWindow][Settings][AppWindow-4][771.100] Handling mozbrowserloadstart event...
[Dump: AppWindow][Settings][AppWindow-4][771.102] Handling mozbrowserloadstart event...
[Dump: AppWindow][Settings][AppWindow-4][771.104] publishing internal event: loading
[Dump: AppWindow][Settings][AppWindow-4][771.107] publishing external event: loading
[Dump: HomescreenWindow][Homescreen][homescreen][771.161]zoom-in has been ENDED!
[Dump: HomescreenWindow][Homescreen][homescreen][771.163]closing,closed,::,complete
[Dump: HomescreenWindow][Homescreen][homescreen][771.180] publishing internal event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][771.182]Dump: set visibility -> ,false
[Dump: HomescreenWindow][Homescreen][homescreen][771.183]setVisible on browser element:false
[Dump: HomescreenWindow][Homescreen][homescreen][771.202]screenshot state -> ,none
[Dump: HomescreenWindow][Homescreen][homescreen][771.216] publishing external event: closed
[Dump: HomescreenWindow][Homescreen][homescreen][771.225] publishing internal event: close
[Dump: HomescreenWindow][Homescreen][homescreen][771.233] publishing external event: close
[Dump: AppWindow][Settings][AppWindow-4][771.235]openApp has been ENDED!
[Dump: AppWindow][Settings][AppWindow-4][771.241]opening,opened,::,complete
[Dump: AppWindow][Settings][AppWindow-4][771.245] publishing internal event: opened
[Dump: AppWindow][Settings][AppWindow-4][771.256]Dump: set visibility -> ,true
[Dump: AppWindow][Settings][AppWindow-4][771.261]before showing frame
[Dump: AppWindow][Settings][AppWindow-4][771.263]setVisible on browser element:true
[Dump: AppWindow][Settings][AppWindow-4][771.272]screenshot state -> ,frame
[Dump: AppWindow][Settings][AppWindow-4][771.280] locking screen orientation to default
[Dump: AppWindow][Settings][AppWindow-4][771.293]aw__dump@app://system.gaiamobile.org/js/app_window.js:175
E/GeckoConsole(  519): AppWindow.prototype.publish@app://system.gaiamobile.org/js/app_window.js:949
[Dump: AppWindow][Settings][AppWindow-4][771.304] publishing external event: opened
[Dump: HomescreenWindow][Homescreen][homescreen][771.324] fade out >>>>
[Dump: AppWindow][Settings][AppWindow-4][771.332] publishing internal event: open
[Dump: AppWindow][Settings][AppWindow-4][771.342] publishing external event: open
[Dump: HomescreenWindow][Homescreen][homescreen][771.786] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][771.791] Handling mozbrowservisibilitychange event...
[Dump: HomescreenWindow][Homescreen][homescreen][771.793] publishing internal event: background
[Dump: HomescreenWindow][Homescreen][homescreen][771.794] publishing external event: background
[Dump: AppWindow][Settings][AppWindow-4][771.903] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Settings][AppWindow-4][771.904] Handling mozbrowserlocationchange event...
[Dump: AppWindow][Settings][AppWindow-4][771.906] publishing internal event: locationchange
[Dump: AppWindow][Settings][AppWindow-4][771.907] publishing external event: locationchange
[Dump: AppWindow][Settings][AppWindow-4][771.920] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Settings][AppWindow-4][771.922] Handling mozbrowsertitlechange event...
[Dump: AppWindow][Settings][AppWindow-4][771.923] publishing internal event: titlechange
[Dump: AppWindow][Settings][AppWindow-4][771.925] publishing external event: titlechange
[Dump: AppWindow][Settings][AppWindow-4][773.106] Handling mozbrowserloadend event...
[Dump: AppWindow][Settings][AppWindow-4][773.108] Handling mozbrowserloadend event...
[Dump: AppWindow][Settings][AppWindow-4][773.115] publishing internal event: loadtime
[Dump: AppWindow][Settings][AppWindow-4][773.117] publishing external event: loadtime
[Dump: AppWindow][Settings][AppWindow-4][773.132] publishing internal event: loaded
[Dump: AppWindow][Settings][AppWindow-4][773.135] publishing external event: loaded
[Dump: AppWindow][Settings][AppWindow-4][773.141]bgcolor= ,rgb(244, 244, 244)
[Dump: AppWindow][Settings][AppWindow-4][773.145]setting background color..
Blocking on bug 950673 as we need to solve that one first. The solution to that bug may also solve this.
Depends on: 950673
Flags: needinfo?(hub)
Assignee: dhuseby → alive
Flags: needinfo?(wlachance)
Status: NEW → ASSIGNED
Whiteboard: [c=progress p=2 s= u=1.5] [b2gperf_regression] → [c=progress p=2 s= u=2.0] [b2gperf_regression]
Whiteboard: [c=progress p=2 s= u=2.0] [b2gperf_regression] → [c=progress p= s= u=2.0] [b2gperf_regression]
See Also: → 992263
FYI, Bug 1002847 is resolved, invalid.
And Bug 992263 is resolved, duplicate.
Depends on: 1003788
Blocks: 961800
Component: Performance → Gaia::System::Window Mgmt
Is this still an issue? If not please closed as FIXED. Bug 950673 mentioned in comment 19 has been fixed and most apps seemed to have recovered from the initially reported regression: http://mzl.la/T8hg7d
Flags: needinfo?(alive)
Yes, we could close this unless bug 950673 is reopened.
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Flags: needinfo?(alive)
Resolution: --- → FIXED
Target Milestone: --- → 2.0 S2 (23may)
You need to log in before you can comment on or make changes to this bug.