1919366 - Intermittent TV accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Timeout while waiting for cache update -

Status: NEW

(Core :: Disability Access APIs, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=474679472&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QzOmeYWSS3Knuv3CfX1ndw/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QzOmeYWSS3Knuv3CfX1ndw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2024-09-17T16:29:46.712Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | IFRAME is in the same process. - 
[task 2024-09-17T16:29:46.712Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | viewport is present in the cache - 
[task 2024-09-17T16:29:46.713Z] 16:29:46     INFO - Leaving test bound 
[task 2024-09-17T16:29:46.713Z] 16:29:46     INFO - Entering test bound 
[task 2024-09-17T16:29:46.713Z] 16:29:46     INFO - Buffered messages logged at 16:29:41
[task 2024-09-17T16:29:46.713Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Received document load complete event - 
[task 2024-09-17T16:29:46.714Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Received document load complete event - 
[task 2024-09-17T16:29:46.718Z] 16:29:46     INFO - Console message: [JavaScript Warning: "Partitioned cookie or storage access was provided to “http://example.net/document-builder.sjs?html=%3C%21doctype+html%3E%0A++++++++%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cdiv+id%3D%22test%22%3Etest%3C%2Fdiv%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E” because it is loaded in the third-party context and dynamic state partitioning is enabled."]
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Actually remote browser - 
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - TEST-PASS | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Remote IFRAME is in a different process. - 
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - Buffered messages finished
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | Timeout while waiting for cache update - 
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - Stack trace:
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:test_ok:1597
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:timeout:913
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - setTimeout handler*chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest_setTimeoutShim:922
[task 2024-09-17T16:29:46.719Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:untilCacheCondition/<:920
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:untilCacheCondition:895
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:untilCacheOk:929
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/head.js:verifyAttributeCached:33
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/head.js:testCachingPerPlatform:117
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/browser_viewport_domain.js:null:14
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:accessibleTask/</<:602
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:121
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:accessibleTask/<:521
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:handleTask:1145
[task 2024-09-17T16:29:46.720Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1217
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1358
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1128
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | viewport is present in the cache - 
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - Stack trace:
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:test_ok:1597
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:untilCacheOk/<:932
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - promise callback*chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:untilCacheOk:932
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/head.js:verifyAttributeCached:33
[task 2024-09-17T16:29:46.721Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/head.js:testCachingPerPlatform:117
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/caching_granularity/browser_viewport_domain.js:null:14
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:accessibleTask/</<:602
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - resource://testing-common/BrowserTestUtils.sys.mjs:withNewTab:121
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:accessibleTask/<:521
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:handleTask:1145
[task 2024-09-17T16:29:46.722Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1217
[task 2024-09-17T16:29:46.723Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1358
[task 2024-09-17T16:29:46.723Z] 16:29:46     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1128
[task 2024-09-17T16:29:46.723Z] 16:29:46     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-09-17T16:29:46.723Z] 16:29:46     INFO - Leaving test bound 
[task 2024-09-17T16:29:46.811Z] 16:29:46     INFO - GECKO(4336) | [Child 4656: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 7f2bd5b46c00 == 0 [pid = 4656] [id = 0] [url = http://example.net/document-builder.sjs?html=%3C%21doctype+html%3E%0A++++++++%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cdiv+id%3D%22test%22%3Etest%3C%2Fdiv%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2024-09-17T16:29:46.820Z] 16:29:46     INFO - GECKO(4336) | [Child 4656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (7f2bd5b49000) [pid = 4656] [serial = 3] [outer = 0] [url = http://example.net/document-builder.sjs?html=%3C%21doctype+html%3E%0A++++++++%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cdiv+id%3D%22test%22%3Etest%3C%2Fdiv%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2024-09-17T16:29:46.821Z] 16:29:46     INFO - GECKO(4336) | [Child 4656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (7f2bd5b47400) [pid = 4656] [serial = 2] [outer = 0] [url = about:blank]
[task 2024-09-17T16:29:46.822Z] 16:29:46     INFO - GECKO(4336) | [Child 4656: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (7f2bd5261000) [pid = 4656] [serial = 1] [outer = 0] [url = http://example.net/document-builder.sjs?html=%3C%21doctype+html%3E%0A++++++++%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cdiv+id%3D%22test%22%3Etest%3C%2Fdiv%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2024-09-17T16:29:46.988Z] 16:29:46     INFO - GECKO(4336) | MEMORY STAT | vsize 3483MB | residentFast 549MB | heapAllocated 235MB
[task 2024-09-17T16:29:46.989Z] 16:29:46     INFO - TEST-OK | accessible/tests/browser/caching_granularity/browser_viewport_domain.js | took 8157ms

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

:nlapre, since you are the author of the regressor, bug 1917741, could you take a look?

For more information, please visit BugBot documentation.

Comment 2

[Nathan LaPré]

Looking at this now, attempting to get it to fail on Linux locally - no luck so far. FWIW, I don't think that bug 1917741 directly caused this, since that change only affected macOS test behavior. We may have to turn this test off for Linux entirely if it's truly flaky like this. This is the first caching granularity test issue I've seen where the attribute isn't cached; in every prior case there was too much cached because of platform code.

Comment 3

[Nathan LaPré]

I was able to reproduce this locally on Linux, but only with chaos mode (--repeat doesn't seem to be enough). I'm now pretty sure that this isn't a regression spawned by bug 1917741, because I managed to reproduce this failure on this commit, before the fix for bug 1917741 landed. Instead, I think bug 1794974 (which added the test in the first place) is the actual culprit.

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1794974