1836527 - Reftest logs include new logspam between each test: `console.error: Translations: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))` and another line for Utils.sys.mjs

Status: RESOLVED FIXED

(Firefox :: Translations, defect)

Description

[Daniel Holbert [:dholbert]]

STR:

1. Run some directory of reftests, e.g. here's a relatively short directory (6 tests):

./mach reftest layout/reftests/text-stroke/

2. Look at your terminal output.

ACTUAL RESULTS:
After each REFTEST TEST-LOAD line, the are these two lines:

console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
console.error: Translations: (new Error("Unable to retrieve the translation models.", "resource://gre/actors/TranslationsParent.sys.mjs", 887))

I I'm pretty sure the second line (for TranslationsParent.sys.mjs) was recently-introduced. Not sure about the first one (for Utils.sys.mjs), & whether that's introduced at the same time / for the same reason or not.

EXPECTED RESULTS:
No such log-spam.

Filing in Firefox|Translation to start out, given the TranslationsParent.sys.mjs filename.

Comment 1

[Daniel Holbert [:dholbert]]

This shows up in TreeHerder reftest logs, too -- e.g. this recent one, which has 2622 instances of the message Unable to retrieve the translation models:
https://treeherder.mozilla.org/logviewer?job_id=417740634&repo=mozilla-central
https://firefoxci.taskcluster-artifacts.net/LOO7RqXJQ_mbNSkgu9kTwg/0/public/logs/live_backing.log

Comment 2

[Daniel Holbert [:dholbert]]

For comparion/bisection, this reftest log from April 25 has no such logging:
https://treeherder.mozilla.org/logviewer?job_id=413689151&repo=mozilla-central
https://firefoxci.taskcluster-artifacts.net/cEQaf--jSuW8raUBdFwjOg/0/public/logs/live_backing.log

It's just got back-to-back REFTEST TEST-LOAD log lines, no console.error interspersed between them.

I'll see if I can bisect...

Comment 3

[Daniel Holbert [:dholbert]]

Last good push on m-c:
https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=linux%2Cdebug%2Creftest&revision=c10ba3b6a8ecfaa3bebc0a33d8740e61594766c2

• Its linux debug R1 log: https://firefoxci.taskcluster-artifacts.net/bY2iHMOPTiW0qRWrv6xfQQ/0/public/logs/live_backing.log
• No console.error(...) after each TEST-LOAD line.

First bad push on m-c:
https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=linux%2Cdebug%2Creftest&revision=5eb0c339e4a6c919642f1e70d15347b766ceec00

• Its linux debug R1 log: https://firefoxci.taskcluster-artifacts.net/fyaCOOgYTKCiXxTXvJOh8g/0/public/logs/live_backing.log
• Both of comment 0's console.error(...) lines are logged after each TEST-LOAD line.

Comment 4

[Daniel Holbert [:dholbert]]

In that first-bad-push, this would've been from the stack of patches that landed in bug 1831963.

nordzilla or gtatum, could you take a look? This is adding a lot of noise to reftest logs.

Comment 5

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

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

Comment 6

[Daniel Holbert [:dholbert]]

FWIW, I confirmed that the logspam does go away if I turn off the translations pref (e.g. doing s/true/false/ on the relevant line of all.js).

Comment 7

[Daniel Holbert [:dholbert]]

Also, this affects other testsuites as well (not just traditional reftests).

It affects Web-platform-tests, e.,g. this log:
https://firefoxci.taskcluster-artifacts.net/Bukyir2lRNKIY7E5UNS3cg/0/public/logs/live_backing.log

And mochitests, e.g. this log:
https://firefoxci.taskcluster-artifacts.net/W4iN_Q8MQ6-3m4M4Uw8obg/0/public/logs/live_backing.log

And xpcshell tests, e.g. this log: [EDIT, my mistake -- xpcshell tests don't seem to be affected]

Comment 8

[Erik Nordin [:nordzilla]]

Thank you Daniel!

I first became aware of this yesterday regarding this bug:
https://bugzilla.mozilla.org/show_bug.cgi?id=1836183#c4

The issue is that we are reporting an error when RemoteSettings is not available/fails and this noise appeared when we enabled Translations for Nightly and Early Beta recently in Bug 1831963 because RemoteSettings is not available in tests.

I believe Greg is already working on a patch that will quiet this.

Comment 9

[Daniel Holbert [:dholbert]]

Thanks, Eric! Possibly related to bug 1834155 then (also about RemoteSettings being unavailable and causing logspam).

Comment 10

[Greg Tatum [:gregtatum]]

Attachment: Bug 1836527 - Downgrade translations log levels from error to log; r?nordzilla!

This is a quick fix until we can address the underlying issue.

Comment 11

[Greg Tatum [:gregtatum]]

Our code controls the translations log message, but the Unexpected content-type error is coming from RemoteSettings. Somehow the network response is mocked in tests with a blank response, and it's being reported as an error. I think Bug 1836505 will stop that one from being reported as well.

Comment 12

[Daniel Holbert [:dholbert]]

Thanks!

Comment 13

[Greg Tatum [:gregtatum]]

I'm landing this one since it's not risky, but I confirmed that Bug 1836505 fixes the rest of the stray output. I plan on landing that next week.

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9b72a1daed44
Downgrade translations log levels from error to log; r=nordzilla

Comment 15

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/9b72a1daed44