Closed Bug 1104624 Opened 10 years ago Closed 10 years ago

Tests are failing when trying to switch frame with MarionetteException: Frame not responding, switching to root frame

Categories

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

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: viorela, Assigned: rwood)

References

Details

There are some tests failing intermittently on b2g-inbound while executing self.marionette.switch_to_frame(): http://jenkins1.qa.scl3.mozilla.com/job/flame-kk-319.b2g-inbound.ui.functional.smoke/1356/HTML_Report/ I was able to reproduce the failure locally, by running one of those automated tests (test_add_photo_to_contact.py). Reproduction rate: 2/10 The issue is not reproducible manually. TEST-UNEXPECTED-ERROR | test_add_photo_to_contact.py TestContacts.test_add_photo_from_gallery_to_contact | MarionetteException: MarionetteException: Frame not responding (app://gallery.gaiamobile.org/manifest.webapp), switching to root frame Traceback (most recent call last): File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/marionette_test.py", line 264, in run testMethod() File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/tests/python/gaia-ui-tests/gaiatest/tests/functional/contacts/test_add_photo_to_contact.py", line 51, in test_add_photo_from_gallery_to_contact image.tap_crop_done() File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/tests/python/gaia-ui-tests/gaiatest/apps/gallery/regions/crop_view.py", line 23, in tap_crop_done self.wait_for_condition(lambda m: self.apps.displayed_app.src != self._src) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/tests/python/gaia-ui-tests/gaiatest/apps/base.py", line 56, in wait_for_condition Wait(self.marionette, timeout).until(method, message=message) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/wait.py", line 122, in until rv = condition(self.marionette) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/tests/python/gaia-ui-tests/gaiatest/apps/gallery/regions/crop_view.py", line 23, in <lambda> self.wait_for_condition(lambda m: self.apps.displayed_app.src != self._src) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 79, in displayed_app self.marionette.switch_to_frame() File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/marionette.py", line 987, in switch_to_frame response = self._send_message('switchToFrame', 'ok', id=frame, focus=focus) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/decorators.py", line 35, in _ return func(*args, **kwargs) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/marionette.py", line 638, in _send_message self._handle_error(response) File "/var/jenkins/1/workspace/flame-kk-319.b2g-inbound.ui.functional.smoke/.env/local/lib/python2.7/site-packages/marionette_client-0.8.4-py2.7.egg/marionette/marionette.py", line 712, in _handle_error raise errors.MarionetteException(message=message, status=status, stacktrace=stacktrace) MarionetteException: MarionetteException: Frame not responding (app://gallery.gaiamobile.org/manifest.webapp), switching to root frame Regression range, based on mozilla-inbound: Last working: Gaia-Rev 3b4c64b5a05d106568dae3f88d38bdbb3d5bc29e Gecko-Rev https://hg.mozilla.org/integration/mozilla-inbound/rev/252b954764ee Build-ID 20141124060745 Version 36.0a1 Device-Name flame FW-Release 4.4.2 FW-Incremental eng.cltbld.20141124.092916 FW-Date Mon Nov 24 09:29:27 EST 2014 Bootloader L1TC10011880 First failing: Gaia-Rev 3b4c64b5a05d106568dae3f88d38bdbb3d5bc29e Gecko-Rev https://hg.mozilla.org/integration/mozilla-inbound/rev/5671737e4f24 Build-ID 20141124061445 Version 36.0a1 Device-Name flame FW-Release 4.4.2 FW-Incremental eng.cltbld.20141124.093133 FW-Date Mon Nov 24 09:31:44 EST 2014 Bootloader L1TC10011880 Gaia changes: None Gecko changes: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=252b954764ee&tochange=5671737e4f24
It looks like commit https://hg.mozilla.org/integration/mozilla-inbound/rev/5671737e4f24 caused this failure. Rwood, can you please take a look? Thanks!
Flags: needinfo?(rwood)
Flags: needinfo?(mdas)
I'll take a look.
Flags: needinfo?(mdas)
Assignee: nobody → rwood
Flags: needinfo?(rwood)
Looks like the OOP frame heartbeart is timing out sometimes when grabbing the currently displayed app (self.apps.displayed_app), which switches to the system app then back to the current app. Investigating...
Got to the bottom of this one. Contacts app launched, OOP frame heartbeat starts (pinging contacts app) Inside edit contacts, edit picture is clicked, "select from" system dialog appears Switches to system frame, OOP frame heartbeat stops Gallery is selected in "Select from" dialog, gallery app starts and becomes the displayed app Switch to frame into gallery app, OOP frame heartbeat starts (pinging gallery app) Image thumbnail is tapped, 'crop' screen appears, 'Done' button becomes enabled 'Done' button tapped; gallery app closed; returns to contacts app (edit contacts) Switch to system frame, so we can grab the apps.displayed_app, to verify we have returned to contacts -- Most times -- The most recent OOP frame heartbeat gallery ping is received before the gallery app is closed. Then when we switch to system frame, the OOP frame heartbeat monitor is turned off (stops pinging gallery). Test continues as usual and passes -- Intermittently -- The OOP frame heartbeat gallery ping is sent just slightly right at the moment or just after the gallery app is closed (but before the switch to system frame); resulting in an error sending the ping, and ultimately the OOP frame heartbeat marionette exception. Solution in the works...
Blocks: 984508
QA Whiteboard: [fxosqa-auto-backlog-]
Definitely a timing issue. When trying to reproduce this locally (with the latest central builds): on device (flame-kk 319MB) out of 500 test runs (test_add_photo_to_contact.py), the intermittent failure occurred only once. On the b2g-destkop, I couldn't get it to reproduce at all (0/500). On the b2g-emulator, the failure happened the very first run, and every time after that (15/15). Adding debug code and running on the emulator, to be certain what the problem is.
I/Gecko ( 2369): 1418161815986 Marionette: emitting Touch event of type touchstart to element with id: crop-done-button and tag name: BUTTON at coordinates (294, 25) relative to the viewport I/Gecko ( 2369): 1418161815997 Marionette: emitting Touch event of type touchend to element with id: crop-done-button and tag name: BUTTON at coordinates (294, 25) relative to the viewport I/Gecko ( 2369): 1418161816010 Marionette: emitting Mouse event of type mousemove at coordinates (294, 25) relative to the viewport I/Gecko ( 2369): 1418161816025 Marionette: emitting Mouse event of type mousedown at coordinates (294, 25) relative to the viewport I/Gecko ( 2369): 1418161816071 Marionette: emitting Mouse event of type mouseup at coordinates (294, 25) relative to the viewport I/Gecko ( 1908): 1418161816523 Marionette INFO RJ: Now is 1418161816523 I/Gecko ( 1908): 1418161816525 Marionette INFO RJ: Last pong was at 1418161814999 I/Gecko ( 1908): 1418161816544 Marionette INFO RJ: Elapsed is 1524 I/Gecko ( 1908): 1418161816555 Marionette INFO RJ: Sending ping 35 I/Gecko ( 1908): 1418161816561 Marionette INFO sendToClient: {"from":"0","ok":true}, {6c3472d6-f05e-4b0b-b005-0dc7e3c0dbdb}, {6c3472d6-f05e-4b0b-b005-0dc7e3c0dbdb} I/Gecko ( 1908): 1418161816681 Marionette INFO RJ: Received pong number 33 I/Gecko ( 1908): 1418161816684 Marionette INFO RJ: last pong is 1418161816683 I/Gecko ( 1908): 1418161816701 Marionette INFO RJ: Received pong number 34 I/Gecko ( 1908): 1418161816702 Marionette INFO RJ: last pong is 1418161816702 D/skia ( 2022): START /proc/cpuinfo: D/skia ( 2022): Processor : ARMv7 Processor rev 0 (v7l) D/skia ( 2022): BogoMIPS : 419.43 D/skia ( 2022): Features : swp half thumb fastmult vfp edsp neon vfpv3 D/skia ( 2022): CPU implementer : 0x41 D/skia ( 2022): CPU architecture: 7 D/skia ( 2022): CPU variant : 0x0 D/skia ( 2022): CPU part : 0xc08 D/skia ( 2022): CPU revision : 0 D/skia ( 2022): D/skia ( 2022): Hardware : Goldfish D/skia ( 2022): Revision : 0000 D/skia ( 2022): Serial : 0000000000000000 D/skia ( 2022): D/skia ( 2022): END /proc/cpuinfo D/skia ( 2022): Device supports ARM NEON instructions! I/Gecko ( 1908): 1418161817440 Marionette INFO RJ: Now is 1418161817440 I/Gecko ( 1908): 1418161817441 Marionette INFO RJ: Last pong was at 1418161816702 I/Gecko ( 1908): 1418161817442 Marionette INFO RJ: Elapsed is 738 I/Gecko ( 1908): 1418161817443 Marionette INFO RJ: Sending ping 36 I/Gecko ( 1908): 1418161817451 Marionette INFO RJ: Pulse - error catch I/Gecko ( 1908): 1418161817452 Marionette INFO RJ: Error msg: sendAsync failed: false I/Gecko ( 1908): 1418161817457 Marionette INFO RJ: Error code: undefined I/Gecko ( 1908): 1418161817458 Marionette INFO RJ: Error stack: null I/Gecko ( 1908): 1418161817459 Marionette INFO RJ: Stopping heartbeat I/Gecko ( 1908): 1418161817461 Marionette INFO Deleting frame from remote frames list: 3 I/Gecko ( 1908): 1418161817523 Marionette DEBUG Got request: switchToFrame, data:
sendAsync is returning NS_ERROR_NOT_INITIALIZED; frame has closed. Trying to send PING to the gallery app, but the gallery app has closed already and we have returned to the contacts app; however the OOP heartbeat monitor has not been turned off yet / race condition (my theory in comment 4 is correct)
I've tried setting up event listeners for window 'close' as well as 'mozbrowserclose' but they don't seem to be fired when the gallery app is closed, maybe because it is via web activities? :mounir, are there any gaia events that I can listen for, that are fired when the gallery is closed via a web activity (i.e. Add new contact, in edit contact tap 'add picture', select gallery, select a photo, click 'Done', gallery closes and we are returned to edit contact).
Flags: needinfo?(mounir)
Blocks: 1161088
This seems to have become a regular failure now in test_add_photo_to_contact.py, see bug 1161088. Robert, is there a workaround for this, perhaps?
Flags: needinfo?(rwood)
Hi Martijn, this bug was caused by a patch in Bug 984508, that was backed out afterwords. Since that patch was backed out, this bug is not valid anymore (I am closing it). The failure in Bug 1161088 is not the same issue. FYI, I don't work on Marionette anymore, but if you ask someone in #ateam they can point you in the right direction. Thanks!
Status: NEW → RESOLVED
Closed: 10 years ago
Flags: needinfo?(rwood)
Flags: needinfo?(mounir)
Resolution: --- → WONTFIX
Ok, thanks for the info. I would call this bug fixed, actually, because the patch from bug 984508, but whatever you prefer.
No longer blocks: 1161088
Resolution: WONTFIX → FIXED
You need to log in before you can comment on or make changes to this bug.