Permafailing TV (test-verify) browser/components/customizableui/test/browser_remote_tabs_button.js | Uncaught exception - Condition timed out: () => syncWasCalled

RESOLVED FIXED in Firefox 60

Status

()

defect
P1
normal
RESOLVED FIXED
Last year
Last year

People

(Reporter: intermittent-bug-filer, Assigned: eoger)

Tracking

(Blocks 1 bug, {intermittent-failure})

unspecified
Firefox 61
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox60 fixed, firefox61 fixed)

Details

(Whiteboard: [stockwell unknown])

Attachments

(2 attachments)

Reporter

Description

Last year
treeherder
Filed by: ncsoregi [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/ZZCZc817SkiceC8i6lXTMQ/runs/0/artifacts/public/logs/live_backing.log

[task 2018-02-26T23:46:22.081Z] 23:46:22     INFO - TEST-START | browser/components/customizableui/test/browser_remote_tabs_button.js
[task 2018-02-26T23:46:22.167Z] 23:46:22     INFO - GECKO(7941) | ++DOMWINDOW == 6 (0x7f748b90e400) [pid = 7992] [serial = 6] [outer = 0x7f74893df000]
[task 2018-02-26T23:46:22.305Z] 23:46:22     INFO - GECKO(7941) | ++DOMWINDOW == 2 (0x7fa4086ac400) [pid = 8021] [serial = 2] [outer = 0x7fa406138000]
[task 2018-02-26T23:46:22.448Z] 23:46:22     INFO - GECKO(7941) | ++DOMWINDOW == 7 (0x7f748b87a000) [pid = 7992] [serial = 7] [outer = 0x7f74893df000]
[task 2018-02-26T23:46:22.513Z] 23:46:22     INFO - GECKO(7941) | [Child 7992, Main Thread] WARNING: attempt to modify an immutable nsStandardURL: file /builds/worker/workspace/build/src/netwerk/base/nsStandardURL.cpp, line 1698
[task 2018-02-26T23:46:24.500Z] 23:46:24     INFO - GECKO(7941) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpRkL9kC.mozrunner/runtests_leaks_tab_pid8057.log
[task 2018-02-26T23:46:24.850Z] 23:46:24     INFO - GECKO(7941) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2018-02-26T23:46:25.925Z] 23:46:25     INFO - GECKO(7941) | --DOCSHELL 0x7f7488881800 == 1 [pid = 7992] [id = {3dd26784-0f64-499c-be34-534c914cacd4}]
[task 2018-02-26T23:46:26.527Z] 23:46:26     INFO - GECKO(7941) | --DOCSHELL 0x7fb54e5d9800 == 4 [pid = 7941] [id = {4637ea15-d892-46a6-8b79-d86e2b3620ca}]
[task 2018-02-26T23:46:29.754Z] 23:46:29     INFO - TEST-INFO | started process screentopng
[task 2018-02-26T23:46:30.222Z] 23:46:30     INFO - TEST-INFO | screentopng: exit 0
[task 2018-02-26T23:46:30.222Z] 23:46:30     INFO - Buffered messages logged at 23:46:22
[task 2018-02-26T23:46:30.222Z] 23:46:30     INFO - Entering test bound testSyncRemoteTabsButtonFunctionality
[task 2018-02-26T23:46:30.222Z] 23:46:30     INFO - Test the Sync Remote Tabs button in the panel
[task 2018-02-26T23:46:30.223Z] 23:46:30     INFO - Buffered messages logged at 23:46:23
[task 2018-02-26T23:46:30.223Z] 23:46:30     INFO - Waiting for overflow button to have non-0 size
[task 2018-02-26T23:46:30.224Z] 23:46:30     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 170}]
[task 2018-02-26T23:46:30.225Z] 23:46:30     INFO - The panel menu was opened
[task 2018-02-26T23:46:30.227Z] 23:46:30     INFO - TEST-PASS | browser/components/customizableui/test/browser_remote_tabs_button.js | The sync remote tabs button was added to the Panel Menu - 
[task 2018-02-26T23:46:30.242Z] 23:46:30     INFO - TEST-PASS | browser/components/customizableui/test/browser_remote_tabs_button.js | Sync Panel is in view - 
[task 2018-02-26T23:46:30.244Z] 23:46:30     INFO - The sync now button was clicked
[task 2018-02-26T23:46:30.245Z] 23:46:30     INFO - Buffered messages logged at 23:46:25
[task 2018-02-26T23:46:30.247Z] 23:46:30     INFO - Global property added while loading chrome://browser/content/browser-thumbnails.js: getTopSiteURLs
[task 2018-02-26T23:46:30.249Z] 23:46:30     INFO - Buffered messages finished
[task 2018-02-26T23:46:30.253Z] 23:46:30     INFO - TEST-UNEXPECTED-FAIL | browser/components/customizableui/test/browser_remote_tabs_button.js | Uncaught exception - Condition timed out: () => syncWasCalled
[task 2018-02-26T23:46:30.258Z] 23:46:30     INFO - Leaving test bound testSyncRemoteTabsButtonFunctionality
[task 2018-02-26T23:46:30.263Z] 23:46:30     INFO - Entering test bound asyncCleanup
[task 2018-02-26T23:46:30.265Z] 23:46:30     INFO - GECKO(7941) | 1519688789760	addons.xpi	WARN	Attempting to activate an already active default theme
[task 2018-02-26T23:46:30.270Z] 23:46:30     INFO - TEST-PASS | browser/components/customizableui/test/browser_remote_tabs_button.js | The panel UI is in default state again. -
Comment hidden (Intermittent Failures Robot)

Comment 2

Last year
Looks like this was tripped when landing bug 1440333. Paolo, can you take a look at why this is perma-failing and if it's symptomatic of another issue with panelmultiview?
Component: Toolbars and Customization → Sync
Flags: needinfo?(paolo.mozmail)
Summary: Permafailing browser/components/customizableui/test/browser_remote_tabs_button.js | Uncaught exception - Condition timed out: () => syncWasCalled → Permafailing TV (test-verify) browser/components/customizableui/test/browser_remote_tabs_button.js | Uncaught exception - Condition timed out: () => syncWasCalled

Comment 3

Last year
I took a look at browser_remote_tabs_button.js and the implementation looks correct to me in the way it waits for PanelMultiView events. I'm wondering if there is maybe a race condition in sync code.

Anyways, is this still an issue? The browser_remote_tabs_button.js test itself doesn't fail when I run it locally.
Flags: needinfo?(paolo.mozmail)

Comment 4

Last year
(In reply to :Paolo Amadini from comment #3)
> Anyways, is this still an issue? The browser_remote_tabs_button.js test
> itself doesn't fail when I run it locally.

Did you run it with --verify?
Flags: needinfo?(paolo.mozmail)

Comment 5

Last year
Ah, I didn't, thanks. The test fails with --repeat=2 because syncing is in progress the second time.

I'll attach a patch just to show what I mean, but there's probably a proper way to fix this by waiting for some event during the cleanup phase. This is not related to the PanelMultiView work.
Flags: needinfo?(paolo.mozmail)
Comment hidden (mozreview-request)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Kit or Thom, could you perhaps use Paolo's proof of concept to write a "proper" (per comment 5) fix for this intermittent? It looks like it's frequent enough that it'll be in the top intermittent oranges soon at the current rate.
Flags: needinfo?(tchiovoloni)
Flags: needinfo?(kit)
I don't think there is a good event to listen to since sync is mocked out here. Having it call the actual function causes failures early in login, though.

One thing I notice in that test is that there are a few references to service.syncAndReportErrors, which should be service.errorHandler.syncAndReportErrors (it gets it right where it actually matters, but resets it improperly). This doesn't effect the actual test, however.

Anyway, Eduoard is more familiar with the UI code (and it's tests) than I am, and might know better what event that button is listening to in the first place. Personally I'd be fine with a fix like Paolo's, though (although I think we should also fix the incorrect references to service.syncAndReportErrors while we're here)
Flags: needinfo?(tchiovoloni) → needinfo?(eoger)
Assignee

Updated

Last year
Assignee: nobody → eoger
Status: NEW → ASSIGNED
Flags: needinfo?(eoger)
Priority: -- → P1
Comment hidden (mozreview-request)
Sounds like Ed has this covered!
Flags: needinfo?(kit)
Comment hidden (Intermittent Failures Robot)

Comment 15

Last year
mozreview-review
Comment on attachment 8957689 [details]
Bug 1441376 - Stop the Syncing animation manually in browser_remote_tabs_button.js test.

https://reviewboard.mozilla.org/r/226606/#review232704

Thanks for coming up with a proper fix for this! I have just a few suggestions to make the issue clearer to people using this code as reference later.

::: commit-message-f1965:11
(Diff revision 1)
> +We fix this by stopping the animation ourselves manually at the end of the test,
> +so the subsequent runs of this same test will start with a correct UI state.

Not only runs of the same test, but any newly added test that relies on this button and by chance runs roughly 1.5 seconds after this one would be intermittent.

::: browser/components/customizableui/test/browser_remote_tabs_button.js:50
(Diff revision 1)
>    syncNowButton.click();
>    info("The sync now button was clicked");
>  
>    await waitForCondition(() => syncWasCalled);
> +
> +  // Stop the Syncing animation manually because it is behind a setTimeout.

Move the relevant parts of the commit message to this code comment, in particular how this is required to avoid the button being disabled at the beginning of a future test.
Attachment #8957689 - Flags: review?(paolo.mozmail) → review+
Comment hidden (mozreview-request)

Comment 17

Last year
Pushed by eoger@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/39b4ff73882c
Stop the Syncing animation manually in browser_remote_tabs_button.js test. r=Paolo

Comment 18

Last year
bugherder
https://hg.mozilla.org/mozilla-central/rev/39b4ff73882c
Status: ASSIGNED → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
Comment hidden (Intermittent Failures Robot)
Blocks: 1447877
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.