Closed Bug 1659193 Opened 4 years ago Closed 2 years ago

Reader mode scrolling to hash/reference/ids is unreliable (was: Intermittent toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (0) should be within 1 CSS pixel of offsetTop (2894) - 2894 <= 1 - got 2894, expected 1 (operator <=)

Categories

(Toolkit :: Reader Mode, defect, P3)

Product:
Toolkit
Component:
Reader Mode
Platform:
Desktop
All
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
99 Branch
Tracking Flags:
Tracking Status
firefox98 --- fixed
firefox99 --- fixed

People

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

References

Details

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

Attachments

(3 files)

Bug 1659193 - disable browser_readerMode_with_anchor.js on Mac_qr for frequent failures. r=#intermittent-reviewers
48 bytes, text/x-phabricator-request
Details | Review
Bug 1659193 - fix scroll-to-ref support in reader mode to not be racy, r?emilio
48 bytes, text/x-phabricator-request
pascalc
: approval-mozilla-beta+
Details | Review
Bug 1659193 - re-enable browser_readerMode_with_anchor.js on macOS now that the underlying problem is fixed, r?aryx
48 bytes, text/x-phabricator-request
pascalc
: approval-mozilla-beta+
Details | Review

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=313053336&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/eTIAyAoFTEWZYL8UxNsZSg/runs/0/artifacts/public/logs/live_backing.log

[task 2020-08-14T19:42:58.730Z] 19:42:58     INFO - TEST-START | toolkit/components/reader/test/browser_readerMode_with_anchor.js
[task 2020-08-14T19:42:58.730Z] 19:42:58     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x109f0f400 == 3 [pid = 2333] [id = {c4e0ea2a-ceba-8a45-b983-162bc2c65366}]
[task 2020-08-14T19:42:58.730Z] 19:42:58     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x10860b8c0) [pid = 2333] [serial = 38] [outer = 0x0]
[task 2020-08-14T19:42:58.730Z] 19:42:58     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (0x123958400) [pid = 2333] [serial = 39] [outer = 0x10860b8c0]
[task 2020-08-14T19:42:58.834Z] 19:42:58     INFO - GECKO(2328) | [Child 2335: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x119843800 == 0 [pid = 2335] [id = {e7eb0e8f-fa7c-394f-8363-db5e8e866d9c}] [url = http://example.com/browser/toolkit/components/reader/test/readerModeArticleHiddenNodes.html]
[task 2020-08-14T19:42:58.863Z] 19:42:58     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (0x125d51000) [pid = 2333] [serial = 40] [outer = 0x10860b8c0]
[task 2020-08-14T19:42:59.217Z] 19:42:59     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 23 (0x1261f2800) [pid = 2333] [serial = 41] [outer = 0x10860b8c0]
[task 2020-08-14T19:42:59.322Z] 19:42:59     INFO - GECKO(2328) | [Child 2333, Main Thread] WARNING: Scrolled rect smaller than scrollport?: file /builds/worker/checkouts/gecko/layout/generic/nsGfxScrollFrame.cpp, line 6820
[task 2020-08-14T19:42:59.512Z] 19:42:59     INFO - GECKO(2328) | [Child 2332: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x115890000 == 2 [pid = 2332] [id = {a43a6001-3d7d-4546-b786-eaac82da59bc}]
[task 2020-08-14T19:42:59.513Z] 19:42:59     INFO - GECKO(2328) | [Child 2332: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 17 (0x11606ca40) [pid = 2332] [serial = 37] [outer = 0x0]
[task 2020-08-14T19:42:59.513Z] 19:42:59     INFO - GECKO(2328) | [Child 2332: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (0x115894c00) [pid = 2332] [serial = 38] [outer = 0x11606ca40]
[task 2020-08-14T19:42:59.695Z] 19:42:59     INFO - GECKO(2328) | [Child 2332: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 19 (0x125165000) [pid = 2332] [serial = 39] [outer = 0x11606ca40]
[task 2020-08-14T19:43:00.021Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x109f0d800 == 2 [pid = 2333] [id = {4631a171-28ed-ff4c-b190-55ea776b6c65}] [url = about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticleMedium.html]
[task 2020-08-14T19:43:00.021Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x109f0f400 == 1 [pid = 2333] [id = {c4e0ea2a-ceba-8a45-b983-162bc2c65366}] [url = about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticle.html%23foo#foo]
[task 2020-08-14T19:43:00.021Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 22 (0x109f06800) [pid = 2333] [serial = 27] [outer = 0x0] [url = about:blank]
[task 2020-08-14T19:43:00.021Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 21 (0x1239af000) [pid = 2333] [serial = 31] [outer = 0x0] [url = about:blank]
[task 2020-08-14T19:43:00.021Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 20 (0x1239ae800) [pid = 2333] [serial = 28] [outer = 0x0] [url = about:blank]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x125d55000) [pid = 2333] [serial = 15] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/getCookies.sjs]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x1261eb000) [pid = 2333] [serial = 7] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/getCookies.sjs]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x126b64800) [pid = 2333] [serial = 20] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/getCookies.sjs]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x109f09800) [pid = 2333] [serial = 3] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x125d4e000) [pid = 2333] [serial = 12] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/getCookies.sjs]
[task 2020-08-14T19:43:00.022Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x109f04000 == 0 [pid = 2333] [id = {2b2414ac-0ef1-ef43-975f-3e373797356f}] [url = about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticleShort.html]
[task 2020-08-14T19:43:00.233Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x126265600) [pid = 2333] [serial = 21] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html]
[task 2020-08-14T19:43:00.233Z] 19:43:00     INFO - GECKO(2328) | [Child 2333: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (0x1262657d0) [pid = 2333] [serial = 26] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/readerModeArticleHiddenNodes.html]
[task 2020-08-14T19:43:00.244Z] 19:43:00     INFO - GECKO(2328) | [Child 2332: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x14cf89400) [pid = 2332] [serial = 40] [outer = 0x11606ca40]
[task 2020-08-14T19:43:00.389Z] 19:43:00     INFO - GECKO(2328) | [Child 2332, Main Thread] WARNING: Scrolled rect smaller than scrollport?: file /builds/worker/checkouts/gecko/layout/generic/nsGfxScrollFrame.cpp, line 6820
[task 2020-08-14T19:43:00.420Z] 19:43:00     INFO - GECKO(2328) | JavaScript error: resource://gre/modules/AboutReader.jsm, line 364: TypeError: target.closest is not a function
[task 2020-08-14T19:43:00.522Z] 19:43:00     INFO - TEST-INFO | started process screencapture
[task 2020-08-14T19:43:00.653Z] 19:43:00     INFO - TEST-INFO | screencapture: exit 0
[task 2020-08-14T19:43:00.654Z] 19:43:00     INFO - Buffered messages logged at 19:42:58
[task 2020-08-14T19:43:00.654Z] 19:43:00     INFO - Entering test bound test_loading_withHash
[task 2020-08-14T19:43:00.654Z] 19:43:00     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html#foo" line: 0}]
[task 2020-08-14T19:43:00.655Z] 19:43:00     INFO - Buffered messages logged at 19:42:59
[task 2020-08-14T19:43:00.655Z] 19:43:00     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2020-08-14T19:43:00.655Z] 19:43:00     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2020-08-14T19:43:00.656Z] 19:43:00     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | foo element should be in document - {} == true - 
[task 2020-08-14T19:43:00.656Z] 19:43:00     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (2894) should be within 1 CSS pixel of offsetTop (2894) - 0 <= 1 - 
[task 2020-08-14T19:43:00.656Z] 19:43:00     INFO - Leaving test bound test_loading_withHash
[task 2020-08-14T19:43:00.656Z] 19:43:00     INFO - Entering test bound test_loading_withoutHash
[task 2020-08-14T19:43:00.656Z] 19:43:00     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html" line: 0}]
[task 2020-08-14T19:43:00.657Z] 19:43:00     INFO - Buffered messages logged at 19:43:00
[task 2020-08-14T19:43:00.665Z] 19:43:00     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop should be 0 - 0 == 0 - 
[task 2020-08-14T19:43:00.665Z] 19:43:00     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2020-08-14T19:43:00.665Z] 19:43:00     INFO - Console message: [JavaScript Error: "Not a string"]
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - Console message: [JavaScript Error: "TypeError: target.closest is not a function" {file: "resource://gre/modules/AboutReader.jsm" line: 364}]
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - handleEvent@resource://gre/modules/AboutReader.jsm:364:21
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - synthesizeMouseAtPoint@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:553:13
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - synthesizeMouse/<@resource://testing-common/BrowserTestUtilsChild.jsm:334:34
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - wrapHandlingUserInput@resource://gre/modules/E10SUtils.jsm:981:7
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - synthesizeMouse@resource://testing-common/BrowserTestUtilsChild.jsm:330:15
[task 2020-08-14T19:43:00.666Z] 19:43:00     INFO - receiveMessage@resource://testing-common/BrowserTestUtilsChild.jsm:149:21
[task 2020-08-14T19:43:00.667Z] 19:43:00     INFO - 
[task 2020-08-14T19:43:00.667Z] 19:43:00     INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | foo element should be in document - {} == true - 
[task 2020-08-14T19:43:00.667Z] 19:43:00     INFO - Buffered messages finished
[task 2020-08-14T19:43:00.667Z] 19:43:00     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (0) should be within 1 CSS pixel of offsetTop (2894) - 2894 <= 1 - got 2894, expected 1 (operator <=)
[task 2020-08-14T19:43:00.667Z] 19:43:00     INFO - Stack trace:
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - @chrome://mochitests/content/browser/toolkit/components/reader/test/browser_readerMode_with_anchor.js:67:16
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - execute@resource://specialpowers/SpecialPowersSandbox.jsm:141:12
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.jsm:1809:15
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.jsm:315:21
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - Leaving test bound test_loading_withoutHash
[task 2020-08-14T19:43:00.668Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x11e7e2c00 == 3 [pid = 2330] [id = {83d03049-8fb3-1f4f-9982-d4b652e719a7}] [url = about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticle.html]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x11e7dfc00) [pid = 2330] [serial = 21] [outer = 0x0] [url = about:blank]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x14dad3c00) [pid = 2330] [serial = 16] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/readerModeNonArticle.html]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x1213d6800) [pid = 2330] [serial = 11] [outer = 0x0] [url = http://example.com/browser/toolkit/components/reader/test/readerModeNonArticle.html]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x11e5e8000 == 2 [pid = 2330] [id = {8851e674-7be4-fc4a-b8a0-aa8eaabe8f3d}] [url = about:blank]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | [Child 2330: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x11e6a0000 == 1 [pid = 2330] [id = {3c438fa3-2c52-864d-a353-048e6e72d7a3}] [url = about:reader?url=http%3A%2F%2Fexample.com%2Fbrowser%2Ftoolkit%2Fcomponents%2Freader%2Ftest%2FreaderModeArticleMedium.html]
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - GECKO(2328) | MEMORY STAT | vsize 7717MB | residentFast 341MB | heapAllocated 123MB
[task 2020-08-14T19:43:00.669Z] 19:43:00     INFO - TEST-OK | toolkit/components/reader/test/browser_readerMode_with_anchor.js | took 1927ms
Severity: normal → N/A
Priority: -- → P3

There are 49 total failures in the last 7 days on

[task 2021-06-06T21:58:19.557Z] 21:58:19 INFO - TEST-START | toolkit/components/reader/test/browser_readerMode_with_anchor.js
[task 2021-06-06T21:58:20.532Z] 21:58:20 INFO - GECKO(2993) | JavaScript error: resource://gre/modules/AboutReader.jsm, line 368: TypeError: target.closest is not a function
[task 2021-06-06T21:58:20.536Z] 21:58:20 INFO - TEST-INFO | started process screencapture
[task 2021-06-06T21:58:20.651Z] 21:58:20 INFO - TEST-INFO | screencapture: exit 0
[task 2021-06-06T21:58:20.652Z] 21:58:20 INFO - Buffered messages logged at 21:58:19
[task 2021-06-06T21:58:20.652Z] 21:58:20 INFO - Entering test bound test_loading_withHash
[task 2021-06-06T21:58:20.653Z] 21:58:20 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html#foo" line: 0}]
[task 2021-06-06T21:58:20.653Z] 21:58:20 INFO - Buffered messages logged at 21:58:20
[task 2021-06-06T21:58:20.654Z] 21:58:20 INFO - Console message: [JavaScript Error: "Not a string"]
[task 2021-06-06T21:58:20.654Z] 21:58:20 INFO - Console message: [JavaScript Error: "Not a string"]
[task 2021-06-06T21:58:20.655Z] 21:58:20 INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | foo element should be in document - {} == true -
[task 2021-06-06T21:58:20.655Z] 21:58:20 INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (2893) should be within 1 CSS pixel of offsetTop (2894) - 1 <= 1 -
[task 2021-06-06T21:58:20.656Z] 21:58:20 INFO - Leaving test bound test_loading_withHash
[task 2021-06-06T21:58:20.656Z] 21:58:20 INFO - Entering test bound test_loading_withoutHash
[task 2021-06-06T21:58:20.657Z] 21:58:20 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/toolkit/components/reader/test/readerModeArticle.html" line: 0}]
[task 2021-06-06T21:58:20.657Z] 21:58:20 INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop should be 0 - 0 == 0 -
[task 2021-06-06T21:58:20.658Z] 21:58:20 INFO - Console message: [JavaScript Error: "Not a string"]
[task 2021-06-06T21:58:20.658Z] 21:58:20 INFO - Console message: [JavaScript Error: "Not a string"]
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - Console message: [JavaScript Error: "TypeError: target.closest is not a function" {file: "resource://gre/modules/AboutReader.jsm" line: 368}]
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - handleEvent@resource://gre/modules/AboutReader.jsm:368:19
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - synthesizeMouseAtPoint@chrome://mochikit/content/tests/SimpleTest/EventUtils.js:590:13
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - synthesizeMouse/<@resource://testing-common/BrowserTestUtilsChild.jsm:334:34
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - wrapHandlingUserInput@resource://gre/modules/E10SUtils.jsm:932:7
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - synthesizeMouse@resource://testing-common/BrowserTestUtilsChild.jsm:330:15
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO - receiveMessage@resource://testing-common/BrowserTestUtilsChild.jsm:149:21
[task 2021-06-06T21:58:20.659Z] 21:58:20 INFO -
[task 2021-06-06T21:58:20.660Z] 21:58:20 INFO - TEST-PASS | toolkit/components/reader/test/browser_readerMode_with_anchor.js | foo element should be in document - {} == true -
[task 2021-06-06T21:58:20.660Z] 21:58:20 INFO - Buffered messages finished
[task 2021-06-06T21:58:20.661Z] 21:58:20 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (0) should be within 1 CSS pixel of offsetTop (2894) - 2894 <= 1 - got 2894, expected 1 (operator <=)
[task 2021-06-06T21:58:20.661Z] 21:58:20 INFO - Stack trace:
[task 2021-06-06T21:58:20.661Z] 21:58:20 INFO - @chrome://mochitests/content/browser/toolkit/components/reader/test/browser_readerMode_with_anchor.js:67:16
[task 2021-06-06T21:58:20.661Z] 21:58:20 INFO - execute@resource://specialpowers/SpecialPowersSandbox.jsm:141:12
[task 2021-06-06T21:58:20.661Z] 21:58:20 INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.jsm:1650:15
[task 2021-06-06T21:58:20.662Z] 21:58:20 INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.jsm:310:21
[task 2021-06-06T21:58:20.662Z] 21:58:20 INFO - Leaving test bound test_loading_withoutHash
[task 2021-06-06T21:58:20.663Z] 21:58:20 INFO - GECKO(2993) | MEMORY STAT | vsize 8759MB | residentFast 301MB | heapAllocated 114MB
[task 2021-06-06T21:58:20.663Z] 21:58:20 INFO - TEST-OK | toolkit/components/reader/test/browser_readerMode_with_anchor.js | took 995ms
[task 2021-06-06T21:58:20.663Z] 21:58:20 INFO - checking window state
[task 2021-06-06T21:58:20.664Z] 21:58:20 INFO - GECKO(2993) | Completed ShutdownLeaks collections in process 2993

Recent failures here seem to be due to the osx migration in bug 1713158.

Assignee: nobody → abutkovits
Status: NEW → ASSIGNED
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/45afc65b744a
disable browser_readerMode_with_anchor.js on Mac_qr for frequent failures. r=intermittent-reviewers,bhearsum DONTBUILD
Assignee: abutkovits → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Whiteboard: [stockwell needswork:owner] → [stockwell needswork][stockwell disabled]

There have been 25 total failures in the last 7 days (recent failure log).
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-ccov-qr
  • linux1804-64-qr debug
  • linux1804-64-shippable-qr
  • linux1804-64-tsan-qr
  • windows10-64-2004-ccov-qr
  • windows10-64-2004-qr opt
  • windows10-64-2004-shippable-qr

Gijs, could you please redirect this to someone who can take a look?

Flags: needinfo?(gijskruitbosch+bugs)
Whiteboard: [stockwell unknown] → [stockwell needswork: owner]

Emilio, can you help me understand what's happening here?

I can't reproduce this issue locally. Looking at this log, the test does this:

      let pageShownPromise = BrowserTestUtils.waitForContentEvent(
        browser,
        "AboutReaderContentReady"
      );
      let readerButton = document.getElementById("reader-mode-button");
      readerButton.click();
      await pageShownPromise;

      await SpecialPowers.spawn(browser, [], async function() {
        let foo = content.document.getElementById("foo");
        ok(foo, "foo element should be in document");
        let { scrollTop } = content.document.documentElement;
        let { offsetTop } = foo;
        Assert.lessOrEqual(
          Math.abs(scrollTop - offsetTop),
          1,
          `scrollTop (${scrollTop}) should be within 1 CSS pixel of offsetTop (${offsetTop})`
        );
      });

AboutReader.jsm does this:

    this._goToReference(articleUri.ref); // This just assigns to `location.hash`

    Services.obs.notifyObservers(this._win, "AboutReader:Ready");

    this._doc.dispatchEvent(
      new this._win.CustomEvent("AboutReaderContentReady", {
        bubbles: true,
        cancelable: false,
      })
    );

So the hash navigation is guaranteed to happen before we fire AboutReaderContentReady, for which the test waits.

But the screenshot from the failing test shows that not only have we not scrolled - we haven't even painted reader mode (!) even though the reader mode button indicates that we are in reader mode.

So something is wonky with the assumptions here. The test assumes that when the event fires, scrollTop will have been updated as a result of the hash navigation, and I assumed that paints would at least show reader mode, even if we haven't scrolled.

At a guess, perhaps we could add a waitForCondition to wait for the scrollTop to be non-0, but that's a little yucky. Is there a better way to wait for paints and/or scroll updates?

(As an aside, I noticed that the log complains about sync style flushes, that's from these reads of body width which could probably use getBoundsWithoutFlushing but I'm not confident that would help any of this.)

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(emilio)

Hmm, but that's not the assertion that's failing, right? The assertion that's failing is the second one (this one).

From the log, it seems like this click is not really working out. There's an exception throwing here (log). Since target.closest is not a function, that means that target is a Document or a Text node.

Since we don't fire mouse events on text nodes, my guess is that we're trying to click on there before the document has been laid out, and we fail to actually trigger the click and scroll. Does that make sense?

Flags: needinfo?(emilio)

(In reply to Emilio Cobos Álvarez (:emilio) from comment #79)

Since we don't fire mouse events on text nodes, my guess is that we're trying to click on there before the document has been laid out, and we fail to actually trigger the click and scroll. Does that make sense?

Yes, though it boils down to the same problem: how can the test effectively wait for layout + painting to have happened?

Flags: needinfo?(emilio)

Does something like this._doc.body.getBoundingClientRect(); around here fix it? (Not saying it's the right fix, just for diagnostic purposes).

Sorry I'd usually try it myself but I'm using a bit of PTO time this week for other stuff so trying not to get nerd-sniped too much :)

Flags: needinfo?(emilio) → needinfo?(gijskruitbosch+bugs)

(In reply to Emilio Cobos Álvarez (:emilio) from comment #81)

Does something like this._doc.body.getBoundingClientRect(); around here fix it? (Not saying it's the right fix, just for diagnostic purposes).

Sorry I'd usually try it myself but I'm using a bit of PTO time this week for other stuff so trying not to get nerd-sniped too much :)

I tried but turns out mach try with paths is busted on windows (bug 1749772). Trying again from macOS so we can actually see something. :-\

A no-op trypush doesn't show the intermittent, at least on asan/linux and opt/linux (windows builds are backlogged right now). :-\

https://treeherder.mozilla.org/jobs?repo=try&revision=b9c6e47b0ccb3a675862b1734ea67b9059f980f6

Also, the orange factor link shows no new instances today ( https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2022-01-05&endday=2022-01-12&tree=trunk&bug=1659193 ). Did something change recently on central, perhaps? (I checked, no changes to reader mode itself)

Flags: needinfo?(malexandru)

Both before and after adding a flush there, I see failures on win10 fission, cf:

https://treeherder.mozilla.org/jobs?repo=try&revision=24491555a6d37c10778e755a823a36d5112ad450&selectedTaskRun=YJbtzUvxTXWq3chw0tTZpA.0

https://treeherder.mozilla.org/jobs?repo=try&revision=b9c6e47b0ccb3a675862b1734ea67b9059f980f6&selectedTaskRun=FlQbDpuwQveXpYp8u2qZiw.0

admittedly it's fewer failures on the run with the flush, but not to such a degree that I'm particularly confident it's helped vs. "just" luck...

Emilio: did I mess up the patch, or is there something else I could try?

Flags: needinfo?(gijskruitbosch+bugs) → needinfo?(emilio)

Checked for any related changes but did not find anything out of the ordinary, orange factor shows periodic spikes in failure rate so I'd say it depends on the amount of jobs that ran in a given timeframe.

Flags: needinfo?(malexandru)

No, the patch seems sane... It'd be good to try to get a pernosco recording of this or something, to see what might be going on...

Flags: needinfo?(emilio)

(In reply to Emilio Cobos Álvarez (:emilio) from comment #86)

No, the patch seems sane... It'd be good to try to get a pernosco recording of this or something, to see what might be going on...

https://pernos.co/debug/q_eB6Jelwwapwxw5Urb5kA/index.html

(Passing needinfo back because honestly I'm not sure what to look for in the pernosco session... to be clear, this is from central, without a patch to add more flushes into the reader mode code)

Flags: needinfo?(emilio)

(In reply to :Gijs (he/him) from comment #88)

(In reply to Emilio Cobos Álvarez (:emilio) from comment #86)

No, the patch seems sane... It'd be good to try to get a pernosco recording of this or something, to see what might be going on...

https://pernos.co/debug/q_eB6Jelwwapwxw5Urb5kA/index.html

(Passing needinfo back because honestly I'm not sure what to look for in the pernosco session... to be clear, this is from central, without a patch to add more flushes into the reader mode code)

FWIW the pernosco trace is dead:

so this trace was made in a pretty narrow timeframe where there was an issue with SIGKILLs being received at inopportune moments

But I tried to retrigger it again.

Flags: needinfo?(emilio)

This is a trace with debug info, even better :)

So what's happening is that _goToReference and thus the hash navigation happens before narrate.css has loaded, which then pushes the content down.

Flags: needinfo?(gijskruitbosch+bugs)

From Matrix, since Gijs mentioned that narrate.css shouldn't affect page layout... Ok, so I had only seen the last stylesheet to load (which is what triggers the invalidation and layout), but there are others. Looking into it a bit deeper, here's what happens:

  • We scroll to the anchor. So far so good.
  • The appendchild here happens.
  • The IntersectionObserver callback here happens and toggles the scrolled class.
  • aboutReader.css loads.
  • aboutReaderPocket.css loads.
  • narrate.css loads. This is the last load and the load event fires, triggering layout.
  • The test checks for scroll and offsetTop position, but the offsetTop position is different because of the stylesheets.
Pushed by gijskruitbosch@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/97e59c6d2b71
fix scroll-to-ref support in reader mode to not be racy, r=emilio
Flags: needinfo?(gijskruitbosch+bugs)
Assignee: nobody → gijskruitbosch+bugs
Severity: N/A → S3
Status: NEW → ASSIGNED
Keywords: leave-open
OS: Unspecified → All
Hardware: Unspecified → Desktop
Summary: Intermittent toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (0) should be within 1 CSS pixel of offsetTop (2894) - 2894 <= 1 - got 2894, expected 1 (operator <=) → Reader mode scrolling to hash/reference/ids is unreliable (was: Intermittent toolkit/components/reader/test/browser_readerMode_with_anchor.js | scrollTop (0) should be within 1 CSS pixel of offsetTop (2894) - 2894 <= 1 - got 2894, expected 1 (operator <=)
Whiteboard: [stockwell unknown] → [stockwell fixed]
Pushed by archaeopteryx@coole-files.de:
https://hg.mozilla.org/integration/autoland/rev/5bb0f1a82f05
re-enable browser_readerMode_with_anchor.js on macOS now that the underlying problem is fixed, r=aryx DONTBUILD

https://hg.mozilla.org/mozilla-central/rev/5bb0f1a82f05

Status: ASSIGNED → RESOLVED
Closed: 2 years ago
status-firefox99: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 99 Branch
status-firefox98: --- → affected

Comment on attachment 9262733 [details]
Bug 1659193 - fix scroll-to-ref support in reader mode to not be racy, r?emilio

Beta/Release Uplift Approval Request

  • User impact if declined: Intermittent test failures and race-y behaviour where scrolling to a reference in reader mode doesn't work reliably
  • Is this code covered by automated tests?: Yes
  • Has the fix been verified in Nightly?: No
  • Needs manual test from QE?: No
  • If yes, steps to reproduce:
  • List of other uplifts needed: n/a
  • Risk to taking this patch: Low
  • Why is the change risky/not risky? (and alternatives if risky): Limited to reader mode hash navigation and has automated test coverage
  • String changes made/needed: Nope
Attachment #9262733 - Flags: approval-mozilla-beta?
Attachment #9263152 - Flags: approval-mozilla-beta?

Comment on attachment 9262733 [details]
Bug 1659193 - fix scroll-to-ref support in reader mode to not be racy, r?emilio

Approved for 98 beta 5, thanks.

Attachment #9262733 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Attachment #9263152 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: