1068094 - Experiment with moz-app-loaded in launch atom

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: Gaia::UI Tests, defect)

Description

[Zac C (:zac)]

There is an event called moz-app-loaded.

We should experiment with that in the launch atom and see if it improves reliability in some way.

Comment 1

[Dave Hunt [:davehunt] [he/him] ⌚BST]

moz-app-visually-complete may be even better, but Eli can probably let us know which is best to use when waiting for apps to load. We're currently using 'appopen' as seen here: https://github.com/mozilla-b2g/gaia/blob/506da17d0f8dce5d1731b5fc48d5b64c52f55135/tests/atoms/gaia_apps.js#L281

Comment 2

[:Eli Perelman]

`moz-app-visually-complete` is the event we use to indicate when it appears an app is ready to be used by a user, but in no way correlates to the app being completed with background processing or other tasks. This would be indicated by `moz-app-loaded`, which is used when the app is in a state of stability and nothing else should happen barring other interactions.

Comment 3

[:Eli Perelman]

As an aside, `moz-app-loaded` is the event we use in `make test-perf` to determine the app is in stability and and capture performance numbers [1].

[1] https://github.com/mozilla-b2g/gaia/blob/master/tests/performance/startup_events_test.js#L25

Comment 4

[Martijn Wargers (dead)]

Attachment: mozapploaded

I tried this in tests/atoms/gaia_apps.js, but this causes all kinds of timeouts in my local Flame device.
For instance in tests/python/gaia-ui-tests/gaiatest/tests/functional/browser/test_browser_navigation.py

With appopen, I see this in the console log with that test:
I/GeckoConsole(10525): Content JS LOG: app with origin 'app://search.gaiamobile.org' has launched

With moz-app-loaded, that doesn't happen.

As a sidenote, I wonder where the appopen event is fired in the code, I can't seem to find it:
http://mxr.mozilla.org/mozilla-central/search?string=appopen
http://mxr.mozilla.org/gaia/search?string=appopen

Btw, I tried the appopened event (which also seems to exist). That seems to work fine.

Comment 5

[Dave Hunt [:davehunt] [he/him] ⌚BST]

This would suggest the moz-app-loaded event is not being fired. Eli: Is there anything we need to do to enable these perf events or should they always fire?

Comment 6

[Zac C (:zac)]

Martijn, that code looks right - let's wait and see what Eli says.

Comment 7

[:Eli Perelman]

There is nothing that needs to be done to fire the events other than just injecting the dispatching of them in code, no preferences, etc. The issue you are most likely dealing with is trying to consume an event for which it has not yet been implemented. This would be anything related to the System-level apps, i.e. verticalhome, search, system, browser, etc. The system apps do not yet have this event, and I see that you are using it in the browser navigation/search test. The list of apps on Datazilla [1] paint a good picture of which apps you can use the moz-* events.

[1] https://datazilla.mozilla.org/b2g/

Comment 8

[Zac C (:zac)]

Thanks Eli.. 

I think this experiment is over if we can't use this event for all the apps. What we have now has been quite reliable lately so there is no pressing need to make changes.

Comment 9

[Dave Hunt [:davehunt] [he/him] ⌚BST]

(In reply to Zac C (:zac) from comment #8)
> I think this experiment is over if we can't use this event for all the apps.
> What we have now has been quite reliable lately so there is no pressing need
> to make changes.

I still think it's worth investigating if this allows us to remove some of the potentially brittle waits when loading certain apps (such as launching the video app and then waiting for n thumbnails to be displayed). If it only applies to certain apps then we could indicate in those app objects perhaps a boolean flag that defaults to using the current event?

Comment 10

[Martijn Wargers (dead)]

(In reply to Martijn Wargers [:mwargers] (QA) from comment #4)
> Created attachment 8509870 [details] [diff] [review]
> mozapploaded
> 
> I tried this in tests/atoms/gaia_apps.js, but this causes all kinds of
> timeouts in my local Flame device.
> For instance in
> tests/python/gaia-ui-tests/gaiatest/tests/functional/browser/
> test_browser_navigation.py
> 
> With appopen, I see this in the console log with that test:
> I/GeckoConsole(10525): Content JS LOG: app with origin
> 'app://search.gaiamobile.org' has launched
> 
> With moz-app-loaded, that doesn't happen.
> 
> As a sidenote, I wonder where the appopen event is fired in the code, I
> can't seem to find it:
> http://mxr.mozilla.org/mozilla-central/search?string=appopen
> http://mxr.mozilla.org/gaia/search?string=appopen
> 
> Btw, I tried the appopened event (which also seems to exist). That seems to
> work fine.

I posted this question some time ago on dev-gaia, I got this reply from Fred Lin:
Appopen event is fired in https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/app_transition_controller.js#L133

Those events are defined in app_transition_controller, xxx_window... by `publish`, the dispatchEvent wrapper defined in https://github.com/mozilla-b2g/gaia/blob/master/apps/system/js/app_window.js#L1209

Comment 11

[Martijn Wargers (dead)]

Attachment: https://github.com/mozilla-b2g/gaia/pull/30502

This seems to work, using the 'launchapp' event.
I tested with test_a11y_cards_view.py from bug 1156234.
Normally, that test would fail for me within 50 repeats, but with the 'launchapp' event, that didn't happen.
I also tried out the 'appopened' event, but that one also gave me at least once a failure as in bug 1156234.

Comment 12

[Martijn Wargers (dead)]

Comment on attachment 8617330 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30502

Dave Hunt, can we use the 'launchapp' event here? It seems to be much more reliable, afaict.
I retested this locally with test_a11y_cards_view.py and repeated it 200 times and I get 2 failures in total, and those are not the ones from bug 1156234.

It's this one, in case you're interested:
TEST-UNEXPECTED-ERROR | test_a11y_cards_view.py TestCardsViewAccessibility.test_a11y_cards_view | ScriptTimeoutException: ScriptTimeoutException: timed out


Traceback (most recent call last):
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_client-0.13-py2.7.egg/marionette/marionette_test.py", line 296, in run
    testMethod()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/tests/accessibility/system/test_a11y_cards_view.py", line 112, in test_a11y_cards_view
    cards[0].a11y_click_screenshot_view()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/apps/system/regions/cards_view.py", line 110, in a11y_click_screenshot_view
    self.accessibility.click(self.root_element.find_element(*self._screenshot_view_locator))
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 538, in click
    self._run_async_script('click', [element])
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 589, in _run_async_script
    args)
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 575, in execute_async_script
    '%s\n%s' % (content, script), args, **kwargs)
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/marionette.py", line 1510, in execute_async_script
    debug_script=debug_script)
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/decorators.py", line 36, in _
    return func(*args, **kwargs)
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/marionette.py", line 711, in _send_message
    self._handle_error(response)
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/marionette.py", line 747, in _handle_error
    raise errors.lookup(status)(message, stacktrace=stacktrace)
TEST-INFO took 18362ms

Comment 13

[Dave Hunt [:davehunt] [he/him] ⌚BST]

It's great that this appears to resolve our launch timeouts, but where did you find 'launchapp' event from? Is this guaranteed to work for all apps? I wonder if Eli can provide an update here, in case anything has changed since comment 7.

Comment 14

[Martijn Wargers (dead)]

(In reply to Dave Hunt (:davehunt) from comment #13)
> It's great that this appears to resolve our launch timeouts, but where did
> you find 'launchapp' event from? Is this guaranteed to work for all apps?

Sorry, can't really answer those questions. I don't even remember where I found it (I just browser through mxr, I think). 
I would love to know what events there are in b2g, datazilla doesn't seem to work anymore?

Comment 15

[:Eli Perelman]

Datazilla was deprecated as of April 1st 2015 [1]. The system does provide some events that denote some sort of loading progress for apps, but they are not valuable visual indicators for all apps, since some may defer loading. This is why we moved away from implicit performance indicators to the explicit ones, e.g. marking loading progress within apps using performance.mark().

The Datazilla UI has been replaced by the Raptor dashboards [2], and the current default section measuring the launch times of applications is at [3]. All our apps mark their completion of launch when they mark fullyLoaded using performance.mark('fullyLoaded'). Unfortunately there is no event to receive when this happens. For Raptor, we parse logcat to know when this has occurred.

[1] https://groups.google.com/d/msg/mozilla.dev.gaia/geibu6Kduxg/HjbPxMbc7IYJ
[2] http://raptor.mozilla.org
[3] http://raptor.mozilla.org/#/dashboard/script/mark.js?device=flame-kk&branch=master&memory=319&suite=coldlaunch

Comment 16

[Martijn Wargers (dead)]

Could someone know if we could use 'launchapp' here in the pull request?
I also found 'appopened', perhaps that would be a better choice?
http://mxr.mozilla.org/gaia/source/apps/system/js/app_window_manager.js#31

Comment 17

[EJ Chen [:eragonj][:小龍哥][Contributor mode on](inactive)]

I think Alive would be the best person to answer this because he is the owner of System app :)

Comment 18

[Martijn Wargers (dead)]

Anyone else perhaps knows about the 'launchapp' or 'appopened'. Is it documented somewhere?
I'm hoping (and from my limited testing, it seems so) that it could solve a whole bunch of intermittent failures on Treeherder we see a lot.

Comment 19

[Gabriele Svelto [:gsvelto]]

Nothing specific that I know of but grep'ing through the code yielded these two comments:

- launchapp

https://github.com/mozilla-b2g/gaia/blob/7cfe9eb9ade41043dea02d350680735b815d9c5a/apps/system/js/app_window_factory.js#L11

- appopened

https://github.com/mozilla-b2g/gaia/blob/7cfe9eb9ade41043dea02d350680735b815d9c5a/apps/system/js/app_usage_metrics.js#L431

As others mentioned :alive can certainly tell you more.

Comment 20

[(inactive after 6/18) Alive Kuo [:alive]]

launchapp means system app is dealing with the app launch request from gecko (which may come from mozApp launch call or a window disposition activity call.)

appopened means an app is already opened but may not being loaded if the device is very slow.

apploaded may be something you need, but it's better if you could describe your need more...

Comment 21

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Comment on attachment 8617330 [details] [review]
https://github.com/mozilla-b2g/gaia/pull/30502

If this doesn't cause regressions and improves our app loading issues then I don't have an issue with it - I'd like us to understand exactly why it's better though.

Comment 22

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Please update the commit message though as your change does not use moz-app-loaded.

Comment 23

[Martijn Wargers (dead)]

(In reply to (inactive after 6/18) Alive Kuo [:alive] from comment #20)
> apploaded may be something you need, but it's better if you could describe
> your need more...

It is to get rid of intermittent failures like bug 1156234. There are a lot more of those (I should make them all depending on this bug).
We just need an event here that consistently fires when an app is launched. 'windowopened' doesn't seem to cut it.

So you think I should use the 'apploaded' event here?

Comment 24

[(inactive after 6/18) Alive Kuo [:alive]]

(In reply to Martijn Wargers [:mwargers] (QA) from comment #23)
> (In reply to (inactive after 6/18) Alive Kuo [:alive] from comment #20)
> > apploaded may be something you need, but it's better if you could describe
> > your need more...
> 
> It is to get rid of intermittent failures like bug 1156234. There are a lot
> more of those (I should make them all depending on this bug).
> We just need an event here that consistently fires when an app is launched.
> 'windowopened' doesn't seem to cut it.
> 
> So you think I should use the 'apploaded' event here?

I will say opened + loaded. opened should be consistently fired; if not, it's a bug.
The problem of opened is when an app is opened, it may be still in the loading process; the resources loading and the transition is totally independent.

Comment 25

[Martijn Wargers (dead)]

(In reply to (inactive after 6/18) Alive Kuo [:alive] from comment #24)
> I will say opened + loaded. opened should be consistently fired; if not,
> it's a bug.
> The problem of opened is when an app is opened, it may be still in the
> loading process; the resources loading and the transition is totally
> independent.

I'm not sure how to use 2 event listeners here (appopened and apploaded, right?). Af far as I understand, apploaded is fired after appopened, then why having an event listener for appopened here?

Comment 26

[Martijn Wargers (dead)]

(In reply to (inactive after 6/18) Alive Kuo [:alive] from comment #24)
> I will say opened + loaded. opened should be consistently fired; if not,
> it's a bug.

Then there is a bug here, I guess, see comment 11:
"
I also tried out the 'appopened' event, but that one also gave me at least once a failure as in bug 1156234.
"

I guess the usage of 'launchapp' is not acceptable here?
From your comment 20:
"
launchapp means system app is dealing with the app launch request from gecko (which may come from mozApp launch call or a window disposition activity call.)
"

Otherwise, I guess someone needs to be found who can make 'appopened' fire consistently.

Comment 27

[Martijn Wargers (dead)]

Apparently, Alive is not active in bugzilla anymore. Tim, do you perhaps know if the usage of 'launchapp' would be acceptable here?

Comment 28

[(inactive after 6/18) Alive Kuo [:alive]]

I guess you are using appopened without AppWindow. To fit all kind of window including activity, you could try 'windowopened'.

Comment 29

[Martijn Wargers (dead)]

Alive, please see the pull request. Currently 'windowopened' is already used, but that's not fired consistently either.

Comment 30

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Apparently Alive is still <del>alive</del> active :)

Anyhow, read through the comment I suspect intermittent shouldn't be fixed by moving the event listener at all -- launchapp or appopened events simply either fires *before* or *after* the app transition in System app -- it does not imply the app is loaded and ready to interact at all. To assert that I think the best solution is to go into the frame of these apps and prove the element within.

That said, apploaded or windowloaded from AppWindow#_handle_mozbrowserloadend dispatches when, as the name of the function implied, the hosting frame dispatches mozbrowserloadend event. I would avoid working with mozbrowserloadend as while it is kind of deterministic (if you only consider Gecko and not other browsers) the timing is not really controllable explicitly by apps.

Comment 31

[Martijn Wargers (dead)]

Thanks Tim, that is useful info. I guess that sometimes mozbrowserloadend event doesn't get dispatched then.
Could this code be responsible in some way? http://mxr.mozilla.org/gaia/source/apps/system/js/app_window.js#1203
1203     // WebAPI testing is using mozbrowserloadend event to know
1204     // the first app is loaded so we cannot stop the propagation here.
1205     // but we don't want subsequent mozbrowser events to bubble to the
1206     // used-to-be-rear-window
1207     if (this.rearWindow && evt.type.startsWith('mozbrowser')) {
1208       evt.stopPropagation();
1209     }
This bug especially seems to happen often in bug 1156234 where multiple apps are launch quickly after each other.

Regarding Gaia UI tests, I don't necessarily think that it is important to have a state where the app is fully loaded (although it would be better), because Gaia UI tests has tons of code that waits for elements to be visible and ready to use.
Or perhaps you disagree, Dave?

Comment 32

[Martijn Wargers (dead)]

Now, Gip(u) are hidden on Treeherder, because of the high failure rate, see bug 1180511. Specifically the "test_kill.py, test_kill_multiple.py, test_killall.py tests (and perhaps some test_launch*)" tests were mentioned there, which are failing because 'windowopened' not firing consistently.

Perhaps the code in comment 31 needs to be updated? 

Like I said in comment 31 too, I think most of the time (all of the time?), with Gaia UI tests, we already do what you said in comment 30: "To assert that I think the best solution is to go into the frame of these apps and prove the element within."

Comment 33

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Martjin, I am a bit confused here. Even though the native event is stopped, the apploaded and windowloaded custom event is always published by _handle_mozbrowserloadend function. Are we really sure that we are not getting these custom events?

http://mxr.mozilla.org/gaia/source/apps/system/js/app_window.js#1227

Comment 34

[Martijn Wargers (dead)]

(In reply to Tim Guan-tin Chien [:timdream] (slow response; please ni? to queue) from comment #33)
> Martjin, I am a bit confused here. Even though the native event is stopped,
> the apploaded and windowloaded custom event is always published by
> _handle_mozbrowserloadend function. Are we really sure that we are not
> getting these custom events?
> 
> http://mxr.mozilla.org/gaia/source/apps/system/js/app_window.js#1227

Ok, I guess I could look for those in logcat and make sure they are always firing and when the failure happens in one of the mentioned Gaia UI tests I could then see if it would still have been fired.

Comment 35

[BMO Automation]

Firefox OS is not being worked on