1355009 - Intermittent test_fallback_update.py TestFallbackUpdate.test_update | TimeoutException: Timed out after 5.1 seconds, caused by <class 'marionette_driver.errors.NoSuchWindowException'>: File "marionette_driver/wait.py", line 125, in until

Status: RESOLVED FIXED

(Testing :: Firefox UI Tests, defect)

Description

[Treeherder Bug Filer]

Filed by: hskupin [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=89958248&repo=mozilla-central

https://firefox-ui-tests.s3.amazonaws.com/0a8b3947-2437-416b-95e4-e1bb1b351a4f/log_info.log

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Most likely regressed by the changes on bug 893505. Robert, which preference do we have to set to force the update behavior through the about dialog? Thanks

Comment 2

[Robert Strong (they/them - no direct email)]

app.update.doorhanger

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Thanks Rob!

Here the test failure for reference:

14:16:49     INFO - TEST-UNEXPECTED-ERROR | test_fallback_update.py TestFallbackUpdate.test_update | TimeoutException: Timed out after 5.0 seconds, caused by <class 'marionette_driver.errors.NoSuchWindowException'>:   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/marionette_driver/wait.py", line 125, in until
14:16:49     INFO -     rv = condition(self.marionette)
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/firefox_ui_harness/testcases.py", line 293, in <lambda>
14:16:49     INFO -     lambda _: self.puppeteer.windows.switch_to(lambda win: type(win) is UpdateWizardDialog)
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/firefox_puppeteer/ui/windows.py", line 189, in switch_to
14:16:49     INFO -     .format(target))
14:16:49     INFO - Traceback (most recent call last):
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 166, in run
14:16:49     INFO -     testMethod()
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/tests/firefox-ui/tests/update/fallback/test_fallback_update.py", line 21, in test_update
14:16:49     INFO -     self.download_and_apply_forced_update()
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/firefox_ui_harness/testcases.py", line 293, in download_and_apply_forced_update
14:16:49     INFO -     lambda _: self.puppeteer.windows.switch_to(lambda win: type(win) is UpdateWizardDialog)
14:16:49     INFO -   File "/Users/mozauto/jenkins/workspace/mozilla-central_update/build/venv/lib/python2.7/site-packages/marionette_driver/wait.py", line 150, in until
14:16:49     INFO -     cause=last_exc)

That's interesting because there shouldn't be a change for the fallback case, right?

Checking the AUS logs I can see:

14:16:50     INFO -  *** AUS:SVC Downloader:onProgress - progress: 40800000/68709955
14:16:50     INFO -  *** AUS:SVC Downloader:onStopRequest - original URI spec: https://mozilla-nightly-updates.s3.amazonaws.com/mozilla-central/20170409123541/Firefox-mozilla-central-55.0a1-macosx64-en-US.complete.mar?versionId=MWg8x3FG7kldA24FXtkbUMya_IJMiDnI, final URI spec: https://mozilla-nightly-updates.s3.amazonaws.com/mozilla-central/20170409123541/Firefox-mozilla-central-55.0a1-macosx64-en-US.complete.mar?versionId=MWg8x3FG7kldA24FXtkbUMya_IJMiDnI, status: 2152857618
14:16:50     INFO -  *** AUS:SVC Downloader:onStopRequest - status: 2152857618, current fail: 0, max fail: 10, retryTimeout: 2000
14:16:50     INFO -  *** AUS:SVC Downloader:onStopRequest - non-verification failure
14:16:50     INFO -  *** AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849
14:16:50     INFO -  *** AUS:SVC Downloader:onStopRequest - setting state to: download-failed
14:16:50     INFO -  *** AUS:SVC Downloader:onStopRequest - notifying observers of error. topic: update-error, status: download-attempt-failed

Maybe this failure while downloading the update had an influence here, and is the reason why I cannot reproduce it locally. 

I think that I will wait for the next set of Nighly builds from today, before continuing.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Rob, can we expect that the old software update dialog is no longer used in case of fallback updates? This is what's causing this problem.

Comment 5

[Robert Strong (they/them - no direct email)]

Not sure and I don't have the time to check right now but you can try it out.

Comment 6

[Intermittent Failures Robot]

20 failures in 150 pushes (0.133 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* mozilla-central: 20

Platform breakdown:
* windows8-64: 4
* windows7-64: 4
* windows8-32: 2
* windows7-32: 2
* osx-10-9: 2
* osx-10-11: 2
* osx-10-10: 2
* linux64: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1355009&startday=2017-04-10&endday=2017-04-10&tree=all

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I re-downloaded the Nightly from April 9th, and now I no longer see the old software update window. As it looks like I may had a typo when downloading it the day before via mozdownload.

Given that this window does no longer pop-up we have to ensure that Firefox has not been updated at this time. So I propose to also add some additional checks to ensure that we are still at the correct state. This is also good because of bug 1316564, which has shown that we miss in some cases that Firefox has not been updated.

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Bug 1355009 - Force update tests to only allow a single update.

There was never a need to run a multiple-update step in the past, and as
we agreed a while ago it is not something we want to do in the future.
It means that watershed releases will have to be tested by issuing
multiple update tests.

Review commit: https://reviewboard.mozilla.org/r/128866/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/128866/

Comment 9

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Bug 1355009 - Harden update tests with better error messages.

To ensure better failure messages a refactoring of checks has to be done. It
includes the following changes:

* No further checks for a follow-up (watershed) update. It's not supported
and as such doesn't need assertions (bug 1353717)

* Checks for fallback updates have to be made to ensure that an invalidated
partial/complete update does not cause an upgrade of Firefox during the restart.

Review commit: https://reviewboard.mozilla.org/r/128868/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/128868/

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Attachment: Bug 1355009 - Temporarily disable usage of simplified update ui.

As long as update tests do not support the new simplified update ui
it has to be kept disabled.

Review commit: https://reviewboard.mozilla.org/r/128870/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/128870/

Comment 11

[Andreas Tolfsen ❲:ato❳]

Comment on attachment 8856944 [details]
Bug 1355009 - Temporarily disable usage of simplified update ui.

https://reviewboard.mozilla.org/r/128870/#review131378

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Matt, could you please have a look at those patches and check if the asserts we do now are correct? For this perspective no-one else is around who could review the changes. Andreas just reviewed the technical part. Thanks.

Comment 13

[Andreas Tolfsen ❲:ato❳]

Comment on attachment 8856942 [details]
Bug 1355009 - Force update tests to only allow a single update.

https://reviewboard.mozilla.org/r/128866/#review131380

::: commit-message-b1364:1
(Diff revision 1)
> +Bug 1355009 - Forcing update tests to only allow a single update.

Make imperative, e.g. s/Forcing/Force/

::: commit-message-b1364:3
(Diff revision 1)
> +There was never a need to run a multiple-update step in the past, and as
> +we agreed a while ago it is not something we want to do in the future.
> +It means that watershed releases will have to be tested by issuing
> +multiple update tests.

For the record, I have no clue what this means.  I’ve given a technical review of this patch and that side looks fine, but I’m unable to give any feedback on whether this is a correct change.

::: testing/firefox-ui/harness/firefox_ui_harness/testcases.py:149
(Diff revision 1)
>              check = self.marionette.execute_script("""
>                Components.utils.import("resource://gre/modules/Services.jsm");
>  
>                return  Services.vc.compare(arguments[0], arguments[1]);
> -            """, script_args=[update['build_post']['version'], update['build_pre']['version']])
> +            """, script_args=[self.update_status['build_post']['version'],
> +                              self.update_status['build_pre']['version']])

Make script_args a tuple.

Comment 14

[Andreas Tolfsen ❲:ato❳]

Comment on attachment 8856943 [details]
Bug 1355009 - Harden update tests with better error messages.

https://reviewboard.mozilla.org/r/128868/#review131384

::: commit-message-d4b18:1
(Diff revision 1)
> +Bug 1355009 - Hardening update tests with better checks when build got updated.

Make imperative, e.g.:

> Harden update tests with better checks when build gets updated

Although maybe a better commit message is:

> Harden update tests with better errors

::: testing/firefox-ui/harness/firefox_ui_harness/testcases.py:159
(Diff revision 1)
> -            # The post buildid should be identical with the buildid contained in the patch
> +        # The post buildid should be identical with the buildid contained in the patch
> -            self.assertEqual(self.update_status['build_post']['buildid'],
> +        self.assertEqual(self.update_status['build_post']['buildid'],
> -                             self.update_status['patch']['buildid'])
> +                         self.update_status['patch']['buildid'])
>  
> -            # If a target buildid has been specified, check if it matches the updated build
> -            if self.target_buildid:
> -                self.assertEqual(self.update_status['build_post']['buildid'], self.target_buildid)
> -
> -            # An upgrade should not change the builds locale
> +        # An upgrade should not change the builds locale
> -            self.assertEqual(self.update_status['build_post']['locale'],
> +        self.assertEqual(self.update_status['build_post']['locale'],
> -                             self.update_status['build_pre']['locale'])
> +                         self.update_status['build_pre']['locale'])
>  
> -            # Check that no application-wide add-ons have been disabled
> +        # Check that no application-wide add-ons have been disabled
> -            self.assertEqual(self.update_status['build_post']['disabled_addons'],
> +        self.assertEqual(self.update_status['build_post']['disabled_addons'],
> -                             self.update_status['build_pre']['disabled_addons'])
> +                         self.update_status['build_pre']['disabled_addons'])

Feels natural to add a better message to these as well, but don’t consider it a blocker.

::: testing/firefox-ui/harness/firefox_ui_harness/testcases.py:171
(Diff revision 1)
> +        # If a target version has been specified, check if it matches the updated build
> +        if self.target_version:
> +            self.assertEqual(self.update_status['build_post']['version'], self.target_version)
> +
> +        # If a target buildid has been specified, check if it matches the updated build
> +        if self.target_buildid:
> +            self.assertEqual(self.update_status['build_post']['buildid'], self.target_buildid)

Perhaps these also deserve better messages?

::: testing/firefox-ui/harness/firefox_ui_harness/testcases.py:189
(Diff revision 1)
> +
> +        # Ensure that the version has not been changed
> +        version_check = self.marionette.execute_script("""
> +          Components.utils.import("resource://gre/modules/Services.jsm");
> +
> +          return  Services.vc.compare(arguments[0], arguments[1]);

Two spaces after "return".

::: testing/firefox-ui/harness/firefox_ui_harness/testcases.py:190
(Diff revision 1)
> +        """, script_args=[build_info['version'],
> +                          self.update_status['build_pre']['version']])

Use tuple for script_args.

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8856943 [details]
Bug 1355009 - Harden update tests with better error messages.

https://reviewboard.mozilla.org/r/128868/#review131384

> Perhaps these also deserve better messages?

Makes sense. I will push some updates soon.

Comment 16

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8856942 [details]
Bug 1355009 - Force update tests to only allow a single update.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/128866/diff/1-2/

Comment 17

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8856943 [details]
Bug 1355009 - Harden update tests with better error messages.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/128868/diff/1-2/

Comment 18

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8856944 [details]
Bug 1355009 - Temporarily disable usage of simplified update ui.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/128870/diff/1-2/

Comment 19

[Molly Howell (she/her) (mostly inactive)]

(In reply to Henrik Skupin (:whimboo) from comment #12)
> Matt, could you please have a look at those patches and check if the asserts
> we do now are correct? For this perspective no-one else is around who could
> review the changes. Andreas just reviewed the technical part. Thanks.

Yeah, this all makes sense. Thanks for doing this work.

Comment 20

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Thanks. I'm going to land this now.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d2380e05da13
Force update tests to only allow a single update. r=ato
https://hg.mozilla.org/integration/autoland/rev/796ca9307804
Harden update tests with better error messages. r=ato
https://hg.mozilla.org/integration/autoland/rev/78ac68316644
Temporarily disable usage of simplified update ui. r=ato

Comment 22

[Intermittent Failures Robot]

31 failures in 153 pushes (0.203 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* mozilla-central: 31

Platform breakdown:
* windows8-64: 6
* windows7-64: 6
* windows8-32: 3
* windows7-32: 3
* osx-10-9: 3
* osx-10-11: 3
* osx-10-10: 3
* linux64: 2
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1355009&startday=2017-04-11&endday=2017-04-11&tree=all

Comment 23

[Iris Hsiao [:ihsiao]]

https://hg.mozilla.org/mozilla-central/rev/d2380e05da13
https://hg.mozilla.org/mozilla-central/rev/796ca9307804
https://hg.mozilla.org/mozilla-central/rev/78ac68316644

Comment 24

[Henrik Skupin [:whimboo][⌚️UTC+2]]

With the patch we fix a couple of issues which are all not directly related to the new updater ui. So disabling the pref for older builds is not a problem at all.

Given that the assertion check improvements already pay off on central, please uplift this test-only patch to aurora too. Thanks.

Comment 25

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/e0f7bd5b5857
https://hg.mozilla.org/releases/mozilla-aurora/rev/431b2f377dc0
https://hg.mozilla.org/releases/mozilla-aurora/rev/a5069d5ac732

Comment 26

[Intermittent Failures Robot]

51 failures in 894 pushes (0.057 failures/push) were associated with this bug in the last 7 days. 

This is the #28 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* mozilla-central: 51

Platform breakdown:
* windows8-64: 10
* windows7-64: 10
* windows8-32: 5
* windows7-32: 5
* osx-10-9: 5
* osx-10-11: 5
* osx-10-10: 5
* linux64: 3
* linux32: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1355009&startday=2017-04-10&endday=2017-04-16&tree=all

Comment 27

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Firefox-52esr is affected and we would need this test-only patch to unhide the real underlying issue for bug 1316564. So if it applies cleanly please uplift. Thanks.

Comment 28

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr52/rev/562f2490aba8
https://hg.mozilla.org/releases/mozilla-esr52/rev/efa5bc8349b3
https://hg.mozilla.org/releases/mozilla-esr52/rev/c01007911fb7

Comment 29

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Ryan, can you please also uplift this patch to the esr52.1.x relbranch? Thanks.

Comment 30

[Ryan VanderMeulen [:RyanVM]]

Pushed to FIREFOX_ESR_52_1_X_RELBRANCH. Any future ESR 52.1.x releases (should they happen) will contain the fix.

https://hg.mozilla.org/releases/mozilla-esr52/rev/435587252b44
https://hg.mozilla.org/releases/mozilla-esr52/rev/2c4ff51c0f7a
https://hg.mozilla.org/releases/mozilla-esr52/rev/6fa5a7b42bc5