1836183 - Intermittent [TV] accessible/tests/browser/telemetry/browser_HCM_telemetry.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. -

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=417707827&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/N0RcHOf4QxioCMY5s6888g/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/N0RcHOf4QxioCMY5s6888g/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

INFO - TEST-PASS | accessible/tests/browser/telemetry/browser_HCM_telemetry.js | System colors scalar is logged as true - true == true - 
[task 2023-05-31T23:11:04.505Z] 23:11:04     INFO - Leaving test bound testSystemColors
[task 2023-05-31T23:11:04.506Z] 23:11:04     INFO - Buffered messages finished
[task 2023-05-31T23:11:04.506Z] 23:11:04     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/telemetry/browser_HCM_telemetry.js | This test exceeded the timeout threshold. It should be rewritten or split up. If that's not possible, use requestLongerTimeout(N), but only as a last resort. - 
[task 2023-05-31T23:11:04.506Z] 23:11:04     INFO - GECKO(1854) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2023-05-31T23:11:04.507Z] 23:11:04     INFO - GECKO(1854) | MEMORY STAT | vsize 16225MB | residentFast 397MB | heapAllocated 186MB
[task 2023-05-31T23:11:04.507Z] 23:11:04     INFO - TEST-OK | accessible/tests/browser/telemetry/browser_HCM_telemetry.js | took 58431ms

Comment 1

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

:morgan, since you are the author of the regressor, bug 1835194, could you take a look?

For more information, please visit BugBot documentation.

Comment 2

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

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

Comment 3

[Morgan Reschenberg [:morgan]]

Hmm, it seems like the portion of this test which takes the longest is the setup / pre-run portion:

23:10:13     INFO - GECKO(1854) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-31T23:10:13.351Z] 23:10:13     INFO - GECKO(1854) | console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))
[task 2023-05-31T23:10:25.816Z] 23:10:25     INFO - GECKO(1854) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-31T23:10:26.070Z] 23:10:26     INFO - GECKO(1854) | console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))
[task 2023-05-31T23:10:37.640Z] 23:10:37     INFO - GECKO(1854) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-31T23:10:37.773Z] 23:10:37     INFO - GECKO(1854) | console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))
[task 2023-05-31T23:10:47.277Z] 23:10:47     INFO - GECKO(1854) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-31T23:10:47.502Z] 23:10:47     INFO - GECKO(1854) | console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))
[task 2023-05-31T23:10:58.007Z] 23:10:58     INFO - GECKO(1854) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-05-31T23:10:58.185Z] 23:10:58     INFO - GECKO(1854) | console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))
[task 2023-05-31T23:11:04.342Z] 23:11:04     INFO - TEST-INFO | started process screencapture
[task 2023-05-31T23:11:04.463Z] 23:11:04     INFO - TEST-INFO | screencapture: exit 0
[task 2023-05-31T23:11:04.464Z] 23:11:04     INFO - Buffered messages logged at 23:10:05
[task 2023-05-31T23:11:04.464Z] 23:11:04     INFO - Entering test bound testInit
[task 2023-05-31T23:11:04.464Z] 23:11:04     INFO - Buffered messages logged at 23:10:18
[task 2023-05-31T23:11:04.465Z] 23:11:04     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:blank" line: 0}]
[task 2023-05-31T23:11:04.465Z] 23:11:04     INFO - Buffered messages logged at 23:10:20

Once the tests actually start running they complete in <1 second. Could this be a translation issue instead?
Not sure who to NI here ... Erik are you working on translation stuff?

Comment 4

[Erik Nordin [:nordzilla]]

Thanks Morgan!

It looks like when we enabled Translations for nightly and early beta in Bug 1831963, that it is causing unrelated tests to report the following error to the console:

console.error: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))

The source of the issue for this exact bug is likely this line of code:
https://searchfox.org/mozilla-central/rev/cde3d4a8d228491e8b7f1bd94c63bbe039850696/browser/components/preferences/main.js#1041-1042

This is understandable, as any random test that opens a page will attempt to trigger the creation of the TranslationsState, which will error out because RemoteSettings is not available during testing.

This error won't necessarily cause a test to fail, but it is adding extra noise to the console and apparently adding enough overhead to cause intermittent timeouts.

While this particular error is in browser/components/preferences/main.js, the error itself affects test cases in more than just the about:preferences test code.

I can verify this by running a non-about:preferences test, such as

./mach wpt testing/web-platform/tests/css/cssom/CSSStyleSheet-constructable.html

 0:06.75 TEST_START: /css/cssom/CSSStyleSheet-constructable.html
 0:06.76 INFO Setting pref dom.animations-api.compositing.enabled to true
 0:06.77 INFO Setting pref layout.css.constructable-stylesheets.enabled to true
 0:06.77 INFO Setting pref layout.css.container-queries.enabled to true
 0:06.77 INFO Setting pref layout.css.import-supports.enabled to true
 0:06.88 console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
 0:06.88 console.error: Translations: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))

Greg, do you have any ideas on how to mitigate this during testing? Reporting an error here is intended behavior if there really were to be an issue with RemoteSettings, but I'm trying to think of ways to lower the impact/noise on other test code.

I'm leaving my NI open as a reminder to keep thinking on this.

Comment 5

[Morgan Reschenberg [:morgan]]

Thanks for taking a look ! :) Updating regressing bug accordingly

Comment 6

[Intermittent Failures Robot]

1 failures in 3471 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1836183&startday=2023-05-29&endday=2023-06-04&tree=all

Comment 7

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

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

Comment 8

[Greg Tatum [:gregtatum]]

I think this has been resolved by the translations perf work and Bug 1836505. I'm not seeing any recently. I'm going to tentatively close and see if we get any re-occurrences.