Open Bug 1570812 Opened 6 years ago Updated 2 years ago

Intermittent browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Test timed out -

Categories

(Core :: Security, defect, P3)

Product:
Core
Component:
Security
Type:
defect

Tracking

()

Status:
REOPENED

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [test isolation][stockwell disabled])

Attachments

(7 files, 2 obsolete files)

Bug 1570812 - Disable browser_dynamical_window_rounding.js on mac for frequent failures. r=#intermittent-reviewers
47 bytes, text/x-phabricator-request
Details | Review
Bug 1570812 - disable browser_dynamical_window_rounding.js on Linux_64_opt for frequent failures. r=#intermittent-reviewers
48 bytes, text/x-phabricator-request
Details | Review
more-rfp-logging.patch
15.50 KB, patch
Details | Diff | Splinter Review
Prevent additional resize events.
6.45 KB, patch
Details | Diff | Splinter Review
Simplifying resize workaround for Linux.
48 bytes, text/x-phabricator-request
Details | Review
Bug 1570812 - Prevent additional resize events on Linux. r=stransky
48 bytes, text/x-phabricator-request
Details | Review
Bug 1570812 - Enable browser_dynamical_window_rounding.js on Linux. r=#anti-tracking-reviewers
48 bytes, text/x-phabricator-request
Details | Review

Filed by: aciure [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=259429294&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/KiveCgUoTv-0zN08-8gMRw/runs/0/artifacts/public/logs/live_backing.log

[task 2019-08-01T21:48:07.098Z] 21:48:07 INFO - GECKO(2912) | --DOMWINDOW == 0 (0x7f489c0bf000) [pid = 3215] [serial = 3] [outer = (nil)] [url = http://example.net/browser/browser/components/resistFingerprinting/test/browser/file_dummy.html]
[task 2019-08-01T21:49:21.596Z] 21:49:21 INFO - TEST-INFO | started process screentopng
[task 2019-08-01T21:49:22.199Z] 21:49:22 INFO - TEST-INFO | screentopng: exit 0
[task 2019-08-01T21:49:22.199Z] 21:49:22 INFO - Buffered messages logged at 21:47:51
[task 2019-08-01T21:49:22.199Z] 21:49:22 INFO - Entering test bound setup
[task 2019-08-01T21:49:22.199Z] 21:49:22 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
[task 2019-08-01T21:49:22.199Z] 21:49:22 INFO - Leaving test bound setup
[task 2019-08-01T21:49:22.200Z] 21:49:22 INFO - Entering test bound do_tests
[task 2019-08-01T21:49:22.200Z] 21:49:22 INFO - Run test for the default window rounding.
[task 2019-08-01T21:49:22.200Z] 21:49:22 INFO - Open a content tab for testing.
[task 2019-08-01T21:49:22.200Z] 21:49:22 INFO - Buffered messages logged at 21:47:52
[task 2019-08-01T21:49:22.203Z] 21:49:22 INFO - Wait until the margins are applied for the opened tab.
[task 2019-08-01T21:49:22.206Z] 21:49:22 INFO - Case 1250x1000: Resize the window and wait until resize event happened (currently 1280x966)
[task 2019-08-01T21:49:22.209Z] 21:49:22 INFO - Case 1250x1000: Resizing (currently 1280x966)
[task 2019-08-01T21:49:22.211Z] 21:49:22 INFO - Case 1250x1000: Resized (currently 1250x926)
[task 2019-08-01T21:49:22.213Z] 21:49:22 INFO - Case 1250x1000: Waiting until margin has been updated on browser element. (currently 1250x926)
[task 2019-08-01T21:49:22.215Z] 21:49:22 INFO - Buffered messages finished
[task 2019-08-01T21:49:22.217Z] 21:49:22 INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Test timed out -
[task 2019-08-01T21:49:22.220Z] 21:49:22 INFO - GECKO(2912) | MEMORY STAT | vsize 2961MB | residentFast 334MB | heapAllocated 84MB
[task 2019-08-01T21:49:22.222Z] 21:49:22 INFO - TEST-OK | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | took 90062ms
[task 2019-08-01T21:49:22.228Z] 21:49:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-08-01T21:49:22.230Z] 21:49:22 INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Found a tab after previous test timed out: http://example.net/browser/browser/components/resistfingerprinting/test/browser/file_dummy.html -
[task 2019-08-01T21:49:22.232Z] 21:49:22 INFO - GECKO(2912) | [Parent 2912, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
[task 2019-08-01T21:49:22.241Z] 21:49:22 INFO - GECKO(2912) | [Parent 2912, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
[task 2019-08-01T21:49:22.244Z] 21:49:22 INFO - GECKO(2912) | [Child 2983, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-08-01T21:49:22.246Z] 21:49:22 INFO - GECKO(2912) | ++DOCSHELL 0x7f4f2d5a2800 == 1 [pid = 3086] [id = {15648733-4dab-4d73-b0cf-ebf1c8e3487a}]
[task 2019-08-01T21:49:22.248Z] 21:49:22 INFO - GECKO(2912) | ++DOMWINDOW == 1 (0x7f4f2d920d40) [pid = 3086] [serial = 4] [outer = (nil)]
[task 2019-08-01T21:49:22.250Z] 21:49:22 INFO - GECKO(2912) | [Child 3086, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-08-01T21:49:22.261Z] 21:49:22 INFO - GECKO(2912) | ++DOMWINDOW == 2 (0x7f4f2da02400) [pid = 3086] [serial = 5] [outer = 0x7f4f2d920d40]
[task 2019-08-01T21:49:22.263Z] 21:49:22 INFO - checking window state
[task 2019-08-01T21:49:22.265Z] 21:49:22 INFO - GECKO(2912) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object

Whiteboard: [test isolation]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE

There are 23 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-01-16&endday=2020-01-23&tree=trunk&bug=1570812

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=286154213&repo=autoland&lineNumber=6734

Wennie, could you assign this to someone?

Flags: needinfo?(wleung)
Whiteboard: [test isolation] → [test isolation][stockwell needswork:owner]

There are 28 failures associated to this bug in the last 7 days. These are occurring on macosx1014-64 (debug) and macosx1014-64-shippable (opt).

recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=291377063&repo=autoland

This bug failed 47 times in the last 7 days. Occurs on linux1804-64, linux1804-64-shippable, macosx1014-64 and macosx1014-64-shippable on opt and debug build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=292568873&repo=autoland&lineNumber=3727

 INFO - TEST-PASS | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Margin updated when findbar closed - 
[task 2020-03-10T23:23:59.803Z] 23:23:59     INFO - Console message: [JavaScript Error: "TypeError: can't access property "ownerGlobal", browser is null" {file: "resource:///actors/RFPHelperParent.jsm" line: 28}]
[task 2020-03-10T23:23:59.803Z] 23:23:59     INFO - Buffered messages logged at 23:22:36
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Console message: OpenGL compositor Initialized Succesfully.
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Version: 2.1 INTEL-12.9.22
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Vendor: Intel Inc.
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Renderer: Intel Iris OpenGL Engine
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - FBO Texture Target: TEXTURE_2D
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Run test for the default window rounding in new window.
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Open a content tab for testing.
[task 2020-03-10T23:23:59.804Z] 23:23:59     INFO - Buffered messages logged at 23:22:37
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - Wait until the margins are applied for the opened tab.
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - Buffered messages finished
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Test timed out - 
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - GECKO(1817) | MEMORY STAT | vsize 7661MB | residentFast 352MB | heapAllocated 120MB
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - TEST-OK | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | took 90043ms
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - GECKO(1817) | [Child 1823: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x118743000 == 1 [pid = 1823] [id = {1b06f7ed-a5e5-9244-8027-77220eb26a35}]
[task 2020-03-10T23:23:59.805Z] 23:23:59     INFO - GECKO(1817) | [Child 1823: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x11870b8c0) [pid = 1823] [serial = 4] [outer = 0x0]
[task 2020-03-10T23:23:59.806Z] 23:23:59     INFO - GECKO(1817) | [Child 1823, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/checkouts/gecko/layout/base/nsPresContext.cpp, line 839
[task 2020-03-10T23:23:59.808Z] 23:23:59     INFO - GECKO(1817) | [Child 1823: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x1213eb800) [pid = 1823] [serial = 5] [outer = 0x11870b8c0]
[task 2020-03-10T23:23:59.808Z] 23:23:59     INFO - GECKO(1817) | [Child 1823: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x1271b4c00) [pid = 1823] [serial = 6] [outer = 0x11870b8c0]
[task 2020-03-10T23:23:59.809Z] 23:23:59     INFO - checking window state
[task 2020-03-10T23:23:59.809Z] 23:23:59     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-03-10T23:23:59.809Z] 23:23:59     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Found a browser window after previous test timed out - 
[task 2020-03-10T23:23:59.809Z] 23:23:59     INFO - GECKO(1817) | must wait for focus
[task 2020-03-10T23:23:59.926Z] 23:23:59     INFO - TEST-START | browser/components/resistfingerprinting/test/browser/browser_navigator.js

Daniel: Can you have someone take a look at his bug?

Flags: needinfo?(dveditz)
Whiteboard: [test isolation][stockwell unknown] → [test isolation][stockwell unknown][stockwell needworks:owner]

Bouncing the request to Ethan

Flags: needinfo?(wleung)
Flags: needinfo?(ettseng)
Flags: needinfo?(dveditz)

Tim, the frequency of the failures caught people's attention. Could you investigate to see if we can find out the root cause?

Flags: needinfo?(ettseng) → needinfo?(tihuang)
Priority: P5 → P3
Assignee: nobody → tihuang

Sure, I can take a look. Leave the ni still, so I can check it regularly.

There are 24 failures associated to this bug in the last 7 days. These are occurring on macosx1014-64 opt and macosx1014-64-shippable debug.

recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=295869357&repo=autoland

:timhuang any updates for this?

:timhuang did you have the chance to look at this?
Thank you.

Pushed by csabou@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b23dab8b4aaf Disable browser_dynamical_window_rounding.js on mac for frequent failures. r=jmaher
Keywords: leave-open
Whiteboard: [test isolation][stockwell disable-recommended] → [test isolation][stockwell disabled]

Sorry, I haven't had time to check this. Will check this in the near future.

Flags: needinfo?(tihuang)

Update:

There have been 30 failures within the last 7 days:

  • 11 failures on Linux 18.04 x64 Shippable opt
  • 1 failure on Linux 18.04 x64 CCov opt
  • 18 failures on Linux 18.04 x64 opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=344813015&repo=autoland&lineNumber=6676

[task 2021-07-09T18:17:28.281Z] 18:17:28     INFO - TEST-START | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js
[task 2021-07-09T18:17:28.321Z] 18:17:28     INFO - GECKO(7065) | JavaScript error: resource://gre/modules/RFPHelper.jsm, line 323: NotSupportedError: ChromeUtils.registerWindowActor: 'RFPHelper' actor is already registered.
[task 2021-07-09T18:18:13.298Z] 18:18:13     INFO - TEST-INFO | started process screentopng
[task 2021-07-09T18:18:13.606Z] 18:18:13     INFO - TEST-INFO | screentopng: exit 0
[task 2021-07-09T18:18:13.607Z] 18:18:13     INFO - Buffered messages logged at 18:17:28
[task 2021-07-09T18:18:13.608Z] 18:18:13     INFO - Entering test bound setup
[task 2021-07-09T18:18:13.609Z] 18:18:13     INFO - Console message: [JavaScript Warning: "Layout was forced before the page was fully loaded. If stylesheets are not yet loaded this may cause a flash of unstyled content." {file: "about:newtab" line: 0}]
[task 2021-07-09T18:18:13.609Z] 18:18:13     INFO - Console message: [JavaScript Error: "NotSupportedError: ChromeUtils.registerWindowActor: 'RFPHelper' actor is already registered." {file: "resource://gre/modules/RFPHelper.jsm" line: 323}]
[task 2021-07-09T18:18:13.610Z] 18:18:13     INFO - _registerActor@resource://gre/modules/RFPHelper.jsm:323:17
[task 2021-07-09T18:18:13.611Z] 18:18:13     INFO - _handleLetterboxingPrefChanged@resource://gre/modules/RFPHelper.jsm:313:12
[task 2021-07-09T18:18:13.612Z] 18:18:13     INFO - _handlePrefChanged@resource://gre/modules/RFPHelper.jsm:127:14
[task 2021-07-09T18:18:13.613Z] 18:18:13     INFO - observe@resource://gre/modules/RFPHelper.jsm:90:14
[task 2021-07-09T18:18:13.614Z] 18:18:13     INFO - _setPref@resource://specialpowers/SpecialPowersParent.jsm:519:31
[task 2021-07-09T18:18:13.614Z] 18:18:13     INFO - _applyPrefs@resource://specialpowers/SpecialPowersParent.jsm:409:14
[task 2021-07-09T18:18:13.615Z] 18:18:13     INFO - pushPrefEnv/<@resource://specialpowers/SpecialPowersParent.jsm:495:12
[task 2021-07-09T18:18:13.616Z] 18:18:13     INFO - doPrefEnvOp@resource://specialpowers/SpecialPowersParent.jsm:57:12
[task 2021-07-09T18:18:13.617Z] 18:18:13     INFO - pushPrefEnv@resource://specialpowers/SpecialPowersParent.jsm:440:12
[task 2021-07-09T18:18:13.618Z] 18:18:13     INFO - receiveMessage@resource://specialpowers/SpecialPowersParent.jsm:806:23
[task 2021-07-09T18:18:13.619Z] 18:18:13     INFO - 
[task 2021-07-09T18:18:13.620Z] 18:18:13     INFO - Leaving test bound setup
[task 2021-07-09T18:18:13.621Z] 18:18:13     INFO - Entering test bound do_tests
[task 2021-07-09T18:18:13.622Z] 18:18:13     INFO - Run test for the default window rounding.
[task 2021-07-09T18:18:13.623Z] 18:18:13     INFO - Open a content tab for testing.
[task 2021-07-09T18:18:13.624Z] 18:18:13     INFO - Wait until the margins are applied for the opened tab.
[task 2021-07-09T18:18:13.625Z] 18:18:13     INFO - Buffered messages finished
[task 2021-07-09T18:18:13.626Z] 18:18:13     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Test timed out - 
[task 2021-07-09T18:18:13.626Z] 18:18:13     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-09T18:18:13.629Z] 18:18:13     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Uncaught exception received from previously timed out test - test:letterboxing:update-margin-finish observer not removed before the end of test
[task 2021-07-09T18:18:13.630Z] 18:18:13     INFO - GECKO(7065) | MEMORY STAT | vsize 3292MB | residentFast 310MB | heapAllocated 94MB
[task 2021-07-09T18:18:13.631Z] 18:18:13     INFO - TEST-OK | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | took 45051ms

Daniel, as the owner of the component, could you help us assign this to someone?
Thank you.

Flags: needinfo?(dveditz)

bouncing to Ethan again

Flags: needinfo?(dveditz) → needinfo?(ettseng)

Tim, please provide your thoughts here.

Flags: needinfo?(ettseng) → needinfo?(tihuang)

It seems that the observer 'test:letterboxing:update-margin-finish' does file after letterboxing was enabled.

Tom, would you be able to take a look? Thanks.

Flags: needinfo?(tihuang) → needinfo?(tom)

Update:
There have been 46 failures within the last 7 days:
• 33 failures on Linux 18.04 x64 opt
• 1 failures on Linux 18.04 x64 asan opt
• 3 failures on Linux 18.04 x64 CCov opt
• 9 failures on Linux 18.04 x64 Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=346203755&repo=mozilla-central&lineNumber=6691

[task 2021-07-23T23:24:22.920Z] 23:24:22     INFO - TEST-START | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js
[task 2021-07-23T23:24:22.947Z] 23:24:22     INFO - GECKO(7151) | JavaScript error: resource://gre/modules/RFPHelper.jsm, line 323: NotSupportedError: ChromeUtils.registerWindowActor: 'RFPHelper' actor is already registered.
[task 2021-07-23T23:25:07.925Z] 23:25:07     INFO - TEST-INFO | started process screentopng
[task 2021-07-23T23:25:08.238Z] 23:25:08     INFO - TEST-INFO | screentopng: exit 0
[task 2021-07-23T23:25:08.240Z] 23:25:08     INFO - Buffered messages logged at 23:24:22
[task 2021-07-23T23:25:08.241Z] 23:25:08     INFO - Entering test bound setup
[task 2021-07-23T23:25:08.243Z] 23:25:08     INFO - Console message: [JavaScript Error: "NotSupportedError: ChromeUtils.registerWindowActor: 'RFPHelper' actor is already registered." {file: "resource://gre/modules/RFPHelper.jsm" line: 323}]
[task 2021-07-23T23:25:08.244Z] 23:25:08     INFO - _registerActor@resource://gre/modules/RFPHelper.jsm:323:17
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - _handleLetterboxingPrefChanged@resource://gre/modules/RFPHelper.jsm:313:12
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - _handlePrefChanged@resource://gre/modules/RFPHelper.jsm:127:14
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - observe@resource://gre/modules/RFPHelper.jsm:90:14
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - _setPref@resource://specialpowers/SpecialPowersParent.jsm:533:31
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - _applyPrefs@resource://specialpowers/SpecialPowersParent.jsm:419:14
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - pushPrefEnv/<@resource://specialpowers/SpecialPowersParent.jsm:506:34
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - doPrefEnvOp@resource://specialpowers/SpecialPowersParent.jsm:57:12
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - pushPrefEnv@resource://specialpowers/SpecialPowersParent.jsm:451:12
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - receiveMessage@resource://specialpowers/SpecialPowersParent.jsm:820:23
[task 2021-07-23T23:25:08.246Z] 23:25:08     INFO - 
[task 2021-07-23T23:25:08.247Z] 23:25:08     INFO - Leaving test bound setup
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Entering test bound do_tests
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Run test for the default window rounding.
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Open a content tab for testing.
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Buffered messages logged at 23:24:23
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Wait until the margins are applied for the opened tab.
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - Buffered messages finished
[task 2021-07-23T23:25:08.254Z] 23:25:08     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Test timed out - 
[task 2021-07-23T23:25:08.255Z] 23:25:08     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-23T23:25:08.256Z] 23:25:08     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Uncaught exception received from previously timed out test - test:letterboxing:update-margin-finish observer not removed before the end of test
[task 2021-07-23T23:25:08.256Z] 23:25:08     INFO - GECKO(7151) | MEMORY STAT | vsize 3303MB | residentFast 299MB | heapAllocated 95MB
[task 2021-07-23T23:25:08.257Z] 23:25:08     INFO - TEST-OK | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | took 45035ms
[task 2021-07-23T23:25:08.258Z] 23:25:08     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-23T23:25:08.259Z] 23:25:08     INFO - TEST-UNEXPECTED-FAIL | browser/components/resistfingerprinting/test/browser/browser_dynamical_window_rounding.js | Found a tab after previous test timed out: http://example.net/browser/browser/components/resistfingerprinting/test/browser/file_dummy.html - 
[task 2021-07-23T23:25:08.260Z] 23:25:08     INFO - checking window state
[task 2021-07-23T23:25:08.260Z] 23:25:08     INFO - TEST-START | browser/components/resistfingerprinting/test/browser/browser_navigator.js

I tried reproducing this locally; but could not, so I've sent in a try run with more verbose logging to try and repro it there.

I'm seeing two types of failures.

  1. We fail immediately because the resize event is not fired for the first time we set margins: setting margins to 40 x 27.5"
  2. We don't fail immediately but we seem to fail towards the end of one test and then we keep going but we still fail at the end because the test passed but we added a test:letterboxing:update-margin-finish observer but it wasn't received. This failure is also after setting margins to 40 x 27.5"....

The two types of failures I'm seeing are ones where I am not seeing a resize event right at browser launch; and one where I have (seemingly) two threads trying to resize and set the margins simultaneously...

Attached patch more-rfp-logging.patch — — Splinter Review

Archiving this patch I wrote to add a bunch more logging to the RFP JavaScript for debugging purposes.

After spending a bunch of time and a bunch of try runs on this I'm no closer to understanding the issue; and the next step is a significant increase in difficulty that will require help from other people, so I'm going to disable the test.

Flags: needinfo?(tom)
Pushed by tritter@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/50b37c9ac524 disable browser_dynamical_window_rounding.js on Linux_64_opt for frequent failures. r=intermittent-reviewers,bhearsum

The size is set before a resize is started. Once the gtk window is resized we check whether the window size matches. When another resize starts before the other ends, the size will not match the window size and causes another resize. This patch will perform that check only for the last resize.

(In reply to matc from comment #101)

Created attachment 9241394 [details] [diff] [review]
Prevent additional resize events.

The size is set before a resize is started. Once the gtk window is resized we check whether the window size matches. When another resize starts before the other ends, the size will not match the window size and causes another resize. This patch will perform that check only for the last resize.

Wow; thanks for this!! Would you like to submit it to phabricator, or would you like me to try to land it in your name?

Flags: needinfo?(matc.pub)
Attached file Prevent additional resize events on Linux. (obsolete) —

This patch prevents updating mBounds when a resize completes after another resize has already started.

With the changes from D125736 the test no longer fails on Linux.

There was also a bug in calcMaximumAvailSize, which would recalculate the chrome size whenever the chrome width was 0. Which is always the case on Linux.

(In reply to Tom Ritter [:tjr] (ni? for response to CVE/sec-approval/advisories/etc) from comment #102)

(In reply to matc from comment #101)

Created attachment 9241394 [details] [diff] [review]
Prevent additional resize events.

The size is set before a resize is started. Once the gtk window is resized we check whether the window size matches. When another resize starts before the other ends, the size will not match the window size and causes another resize. This patch will perform that check only for the last resize.

Wow; thanks for this!! Would you like to submit it to phabricator, or would you like me to try to land it in your name?

I submitted the changes to phabricator. On Fedora Gnome the test no longer fails for me, even with --setenv=MOZ_CHAOSMODE=FF .

Flags: needinfo?(matc.pub)

The resize problem on Linux will always produce at least one resize event for every resize, but each resize might also produce a second resize event. The window will always end up with the size of the final resize.

The primary problem with the resize problem is that we might continue a test case after receiving a resize event originating from a previous test case. There is no need for a second resize, as we eventually get into the state expected by the current test case. We can just keep trying. An oversight of the previous workaround was to not update the container size before each call to the check function.

We also have to check that the resulting window size actually matches the test case.

There was also a bug in calcMaximumAvailSize, which would recalculate the chrome size whenever the chrome width was 0. Which is always the case on Linux.

Created attachment 9242085 [details]
Simplifying resize workaround for Linux.

This patch does not depend on any fixes to the gtk window code. My approach to prevent additional resize events will most likely not result in a fix to this problem.

Matc, please let me know when you feel is ready for review.
Thanks.

Flags: needinfo?(matc.pub)
Attachment #9241418 - Attachment description: Prevent additional resize events. → Prevent additional resize events on Linux.

I recall a bug in core gecko event handling that fails to distinguish between resize notifications and resize requests. Perhaps this might be the source of problems here. When a resize notification is received, something responds with a resize request. This of course causes problems if there are pending resize notifications.

To prevent dispatching a "resize" event twice for the same resize, this patch
dispatches "resize" events only once a resize is complete. This change also
happens to fix Bug 1489463, because Gecko is no longer aware of the resize that
caused the problem.

This also changes the behaviour if Gecko initiates a resize in a restrictive
window manager (e.g. i3) that rejects all resizes, then the rendered size of
Gecko will keep matching the native window size. Gecko will no longer end up
occupying only parts of a native window, or be larger than the native window.
Because a resize initiated by Gecko still changes mBounds immediately, we have
to somehow recover the actual size. We can achieve this by checking whether the
GdkFrameClock emits two "update" signals without the window receiving a new
size allocation. From the second signal we can query the native window size and
adjust mBounds. This is implemented as RequestFallbackSizeAllocation(). In the
worst case (e.g. when a size allocation for some resaon, for example changing
size mode at the same time, occurs after the second "update" signal) it will
appear during OnSizeAllocate() as if there never was a resize.

This change with some adjustments in RFPHelper also allows us to remove the
resize workaround for Linux in browser_dynamical_window_rounding.js. We have to
treat DOMContentLoaded in the window child actor as if the content was resized.
We also can't notify about update-margin-finish based on the style margin
value, but instead have to check browser element size and only notify once per
size.

Attachment #9241418 - Attachment is obsolete: true

Removing the resize workaround surfaces some minor problems. We can miss resize
events in RFPHelperChild.jsm while the content is not yet loaded. Treating
DOMContentLoaded the same as resize events catches these cases. Although this
would cause multiple "update-margin-finish" notifications in other cases.

Therefore this patch changes the "update-margin-finish" notification to be
issued when the browser element size already matches our current target size.
Notifications are only issued if the size is different to one at the time of
the last notification for a given browser element. This also allows us to catch
cases where the final margin update changes the margin, but the content size no
longer has to change. This occasionally happens during the FindBar open/close
animation.

Unrelated changes:

  • Allow for chrome width of 0 in calcMaximumAvailSize().
  • Prevent error messages when RFPHelperParent.jsm no longer has an
    embedderElement.
  • Prevent error messages when enabling letterboxing twice, during module
    initialization and on preference changed notification.

Depends on D133585

Attachment #9241649 - Attachment is obsolete: true
Attachment #9254963 - Attachment description: Bug 1570812 - Enable browser_dynamical_window_rounding.js on Linux. r=timhuang → Bug 1570812 - Enable browser_dynamical_window_rounding.js on Linux. r=#anti-tracking-reviewers
Severity: normal → S3

Clear a needinfo that is pending on an inactive user.

Inactive users most likely will not respond; if the missing information is essential and cannot be collected another way, the bug maybe should be closed as INCOMPLETE.

For more information, please visit BugBot documentation.

Flags: needinfo?(matc.pub)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: