No-Jun Park [:njpark] Reporter
	Description • 9 years ago

With the below build flashed to the device, python marionette on-device test fails the setup.  It appears that the b2g is not completely ready within the given timeout value.

See: https://github.com/mozilla-b2g/gaia/blob/master/tests/python/gaia-ui-tests/gaiatest/gaia_test.py#L675

Example of error msg:
Traceback (most recent call last):
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/.env/lib/python2.7/site-packages/marionette_client-0.13-py2.7.egg/marionette/marionette_test.py", line 277, in run
    self.setUp()
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/tests/python/gaia-ui-tests/gaiatest/tests/functional/browser/test_browser_lan.py", line 14, in setUp
    GaiaTestCase.setUp(self)
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 858, in setUp
    self.device.start_b2g()
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 665, in start_b2g
    self.wait_for_b2g_ready(timeout)
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 675, in wait_for_b2g_ready
    lambda m: m.find_element(By.TAG_NAME, 'body').get_attribute('ready-state') == 'fullyLoaded')
  File "/var/lib/jenkins/jobs/flame-kk-319.mozilla-central.nightly.ui.functional.sanity.bitbar/workspace/.env/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/wait.py", line 143, in until
    cause=last_exc)

Version flashed on device:
Build ID               20150601010203
Gaia Revision          e6dc0f4c583407a4a52a66ce7cb11f058302a762
Gaia Date              2015-05-29 17:20:26
Gecko Revision         https://hg.mozilla.org/mozilla-central/rev/f8d21278244b
Gecko Version          41.0a1
Device Name            flame
Firmware(Release)      4.4.2
Firmware(Incremental)  eng.cltbld.20150601.042741
Firmware Date          Mon Jun  1 04:27:52 EDT 2015
Bootloader             L1TC000118D0

	Dave Hunt [:davehunt] [he/him] ⌚BST
	Comment 1 • 9 years ago

I suggest trying higher timeout values (the default is 120 seconds). If that resolves it then we should determine if this is a performance regression of some concern.

	No-Jun Park [:njpark] Reporter
	Comment 2 • 9 years ago

https://bugzilla.mozilla.org/show_bug.cgi?id=1094759 might be related, and now the bug is no longer reproducible.  Reruns of past failed runs are passing right now.  Will look at it closer for next little while.

	No-Jun Park [:njpark] Reporter
	Comment 3 • 9 years ago

Peter, when you rerun the UI automation runs, and if it passes, could you closed this bug please?  thanks!

	Peter Bylenga [:PBylenga]
	Comment 4 • 9 years ago

Newest one is passing.

http://jenkins1.qa.scl3.mozilla.com/view/UI/job/flame-kk-319.mozilla-central.nightly.ui.functional.smoke.bitbar/199/HTML_Report/

	No-Jun Park [:njpark] Reporter
	Comment 5 • 9 years ago

It came back, and at the same time Bug 1094759 is relanded.

http://jenkins1.qa.scl3.mozilla.com/view/Graphics/job/flame-kk-319.mozilla-central.nightly.ui.graphics.reference.bitbar/53/console

	No-Jun Park [:njpark] Reporter
	Comment 7 • 9 years ago

Actually, I can now consistently reproduce the bug locally, after syncing my gaia folder (of the gaia-ui-test) on my pc.  (the build on the phone isn't changed)  And it looks like the passing builds in jenkins are using older builds... so... yeah the problem is still there.

It's odd that when I had 2 day old gaia folder, I could not repro the bug, but with the latest that I can.

	No-Jun Park [:njpark] Reporter
	Comment 8 • 9 years ago

On the screen, the homescreen is showing normally without any issues, but for some reasion self.wait_for_b2g_ready() is timed out on the script.

	Martijn Wargers (dead)
	Comment 9 • 9 years ago

(In reply to No-Jun Park [:njpark] from comment #8)
> On the screen, the homescreen is showing normally without any issues, but
> for some reasion self.wait_for_b2g_ready() is timed out on the script.

Because the ready-state=fullyLoaded attribute isn't added to the body element of the system app. I checked this with self.marionette.execute_script('return document.body.outerHTML') and a time.sleep(60) before, to make sure that everything should have been loaded.

I tried to check with webIDE too, but that doesn't seem to work with this build, because "allow USB debugging connection" dialog tapping "Allow" doesn't seem to work.

	Martijn Wargers (dead)
	Comment 10 • 9 years ago

Instead of checking for this ready-state=fullyLoaded attribute and adding a time.sleep(120) call in gaia_test.py, I get this error:
TEST-UNEXPECTED-ERROR | test_cost_control_reset_wifi.py TestCostControlReset.test_cost_control_reset_wifi | JavascriptException: JavascriptException: TypeError: window.wrappedJSObject.Service.query(...) is undefined
stacktrace:
	execute_script @gaia_test.py, line 113
	inline javascript, line 367
	src: "    let app = window.wrappedJSObject.Service"



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 277, in run
    self.setUp()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/tests/functional/cost_control/test_cost_control_reset_wifi.py", line 15, in setUp
    GaiaTestCase.setUp(self)
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 903, in setUp
    self.cleanup_gaia(full_reset=False)
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 947, in cleanup_gaia
    self.device.turn_screen_off()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 725, in turn_screen_off
    apps.switch_to_displayed_app()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 121, in switch_to_displayed_app
    self.marionette.switch_to_frame(self.displayed_app.frame)
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 113, in displayed_app
    result = self.marionette.execute_script('return GaiaApps.getDisplayedApp();')
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/marionette.py", line 1452, in execute_script
    filename=os.path.basename(frame[0]))
  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 147172ms

SUMMARY
-------
passed: 0
failed: 1
todo: 0

	Martijn Wargers (dead)
	Comment 11 • 9 years ago

(In reply to No-Jun Park [:njpark] from comment #6)
> Created attachment 8615352 [details]
> logcat of timeout

I see all kinds of js errors in there, I guess those could be the cause of this issue.

	Martijn Wargers (dead)
	Comment 12 • 9 years ago

I guess the settings js errors are not related, because that was already filed in bug 1119727.

	(inactive after 6/18) Alive Kuo [:alive]
	Comment 13 • 9 years ago

(In reply to Martijn Wargers [:mwargers] (QA) from comment #10)
> Instead of checking for this ready-state=fullyLoaded attribute and adding a
> time.sleep(120) call in gaia_test.py, I get this error:
> TEST-UNEXPECTED-ERROR | test_cost_control_reset_wifi.py
> TestCostControlReset.test_cost_control_reset_wifi | JavascriptException:
> JavascriptException: TypeError: window.wrappedJSObject.Service.query(...) is
> undefined
> stacktrace:
> 	execute_script @gaia_test.py, line 113
> 	inline javascript, line 367
> 	src: "    let app = window.wrappedJSObject.Service"
> 
> 
> 
> 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 277,
> in run
>     self.setUp()
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/tests/
> functional/cost_control/test_cost_control_reset_wifi.py", line 15, in setUp
>     GaiaTestCase.setUp(self)
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/
> gaia_test.py", line 903, in setUp
>     self.cleanup_gaia(full_reset=False)
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/
> gaia_test.py", line 947, in cleanup_gaia
>     self.device.turn_screen_off()
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/
> gaia_test.py", line 725, in turn_screen_off
>     apps.switch_to_displayed_app()
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/
> gaia_test.py", line 121, in switch_to_displayed_app
>     self.marionette.switch_to_frame(self.displayed_app.frame)
>   File
> "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/
> gaia_test.py", line 113, in displayed_app
>     result = self.marionette.execute_script('return
> GaiaApps.getDisplayedApp();')
>   File
> "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/
> marionette_driver-0.7-py2.7.egg/marionette_driver/marionette.py", line 1452,
> in execute_script
>     filename=os.path.basename(frame[0]))
>   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 147172ms
> 
> SUMMARY
> -------
> passed: 0
> failed: 1
> todo: 0

I am seeing this pass on my flame:


(mip) (mip) ~/Projects/gaia/tests/python/gaia-ui-tests ⮀ ⭠ bugzilla/1094759-mip-failure  ⮀ mip/bin/gaiatest --address=localhost:2828 --testvars=/Users/alive/Projects/testvars.json --restart gaiatest/tests/functional/cost_control/test_cost_control_reset_wifi.py
Results will not be posted to Treeherder. Please set the following environment variables to enable Treeherder reports: TREEHERDER_KEY, TREEHERDER_SECRET
starting httpd
running httpd on http://10.247.26.4:51258/
mozversion application_buildid: 20150527160204
mozversion application_changeset: 2c815cc65cc9
mozversion application_display_name: B2G
mozversion application_id: {3c2e2abc-06d4-11e1-ac3b-374f68613e61}
mozversion application_name: B2G
mozversion application_remotingname: b2g
mozversion application_repository: https://hg.mozilla.org/mozilla-central
mozversion application_vendor: Mozilla
mozversion application_version: 41.0a1
mozversion device_firmware_date: 1428967910
mozversion device_firmware_version_base: L1TC000118D0
mozversion device_firmware_version_incremental: eng.cltbld.20150413.193139
mozversion device_firmware_version_release: 4.4.2
mozversion device_id: flame
mozversion gaia_changeset: 5f72017b3c3ece3797c115f1f11f5df94826de12
mozversion gaia_date: 1433471487
mozversion platform_buildid: 20150527160204
mozversion platform_changeset: 2c815cc65cc9
mozversion platform_repository: https://hg.mozilla.org/mozilla-central
mozversion platform_version: 41.0a1
SUITE-START | Running 1 tests
TEST-START | test_cost_control_reset_wifi.py TestCostControlReset.test_cost_control_reset_wifi
TEST-PASS | test_cost_control_reset_wifi.py TestCostControlReset.test_cost_control_reset_wifi | took 53922ms

SUMMARY
-------
passed: 1
failed: 0
todo: 0
SUITE-END | took 54s

	(inactive after 6/18) Alive Kuo [:alive]
	Comment 14 • 9 years ago

(In reply to Martijn Wargers [:mwargers] (QA) from comment #11)
> (In reply to No-Jun Park [:njpark] from comment #6)
> > Created attachment 8615352 [details]
> > logcat of timeout
> 
> I see all kinds of js errors in there, I guess those could be the cause of
> this issue.

Javascript Error in statusbar is already fixed by other bugs.

I just couldn't reproduce here; I am seeking Taipei QA help...

	Paul Yang [:pyang] (away)
	Comment 15 • 9 years ago

No-jun, can you provide complete version list of marionette/gaiatest dependencies?

	Paul Yang [:pyang] (away)
	Comment 16 • 9 years ago

Just try on lab with latest central
The test passed.

Results will not be posted to Treeherder. Please set the following environment variables to enable Treeherder reports: TREEHERDER_KEY, TREEHERDER_SECRET
starting httpd
running httpd on http://10.247.24.133:54917/
mozversion application_buildid: 20150605010203
mozversion application_changeset: 0496b5b3e9ef
mozversion application_display_name: B2G
mozversion application_id: {3c2e2abc-06d4-11e1-ac3b-374f68613e61}
mozversion application_name: B2G
mozversion application_remotingname: b2g
mozversion application_repository: https://hg.mozilla.org/mozilla-central
mozversion application_vendor: Mozilla
mozversion application_version: 41.0a1
mozversion device_firmware_date: 1433493459
mozversion device_firmware_version_base: L1TC100118D0
mozversion device_firmware_version_incremental: eng.cltbld.20150605.043730
mozversion device_firmware_version_release: 4.4.2
mozversion device_id: flame
mozversion gaia_changeset: 65369b217faac7d70c1a29100c4208c6d1db16e3
mozversion gaia_date: 1433449696
mozversion platform_buildid: 20150605010203
mozversion platform_changeset: 0496b5b3e9ef
mozversion platform_repository: https://hg.mozilla.org/mozilla-central
mozversion platform_version: 41.0a1
SUITE-START | Running 1 tests
TEST-START | test_cost_control_reset_wifi.py TestCostControlReset.test_cost_control_reset_wifi
TEST-PASS | test_cost_control_reset_wifi.py TestCostControlReset.test_cost_control_reset_wifi | took 111680ms

SUMMARY
-------
passed: 1
failed: 0
todo: 0
SUITE-END | took 112s

	Martijn Wargers (dead)
	Comment 17 • 9 years ago

(In reply to Paul Yang [: pyang] from comment #16)
> Just try on lab with latest central
> The test passed.

I can confirm!
I flashed to the latest build, using flash_pvt.py and updated my gaia tree. After that, I can run Gaia UI tests again.

	No-Jun Park [:njpark] Reporter
	Comment 18 • 9 years ago

I can confirm that after syncing to the latest gaia then running python setup.py develop, I can run the test again.

	Martijn Wargers (dead)
	Comment 19 • 9 years ago

Note that I just now got this error again:
TEST-START | test_gallery_handle_valid_image_file.py TestGalleryHandleValidPhoto.test_gallery_open_valid_image_file_animated_gif
TEST-UNEXPECTED-ERROR | test_gallery_handle_valid_image_file.py TestGalleryHandleValidPhoto.test_gallery_open_valid_image_file_animated_gif | TimeoutException: TimeoutException: Timed out after 120.0 seconds


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 277, in run
    self.setUp()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 862, in setUp
    self.device.start_b2g()
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 669, in start_b2g
    self.wait_for_b2g_ready(timeout)
  File "/Users/mwargers/B2G/gaia_clean/tests/python/gaia-ui-tests/gaiatest/gaia_test.py", line 679, in wait_for_b2g_ready
    lambda m: m.find_element(By.TAG_NAME, 'body').get_attribute('ready-state') == 'fullyLoaded')
  File "/Users/mwargers/.virtualenvs/gaia-py-latest/lib/python2.7/site-packages/marionette_driver-0.7-py2.7.egg/marionette_driver/wait.py", line 143, in until
    cause=last_exc)
TEST-INFO took 147987ms

It was a one time thing, it seems to work again fine now.

Anyway, I think this bug can be marked resolved?

	Martijn Wargers (dead)
	Comment 20 • 9 years ago

I'll just mark it wfm then.
This bug happened because the local Gaia tree was out of sync (newer) with the Gaia build on device.