Closed Bug 1441376 Opened 6 years ago Closed 6 years ago

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

Categories

(Firefox :: Sync, defect, P1)

Product:
Firefox
Component:
Sync
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 61
Tracking Flags:
Tracking Status
firefox60 --- fixed
firefox61 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(2 files)

Bug 1441376 - Proof of concept.
59 bytes, text/x-review-board-request
Details
Bug 1441376 - Stop the Syncing animation manually in browser_remote_tabs_button.js test.
59 bytes, text/x-review-board-request
Paolo
: review+
Details 
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. -
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
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)
(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)
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)
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: nobody → eoger
Status: NEW → ASSIGNED
Flags: needinfo?(eoger)
Priority: -- → P1
Sounds like Ed has this covered!
Flags: needinfo?(kit)
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+
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
https://hg.mozilla.org/mozilla-central/rev/39b4ff73882c
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox61: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 61
Blocks: 1447877
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: