Open Bug 1055863 Opened 5 years ago Updated 5 years ago

server.js logs printed to stdout when running mochitests

Categories

(Testing :: Mochitest, defect)

All
macOS
defect
Not set

Tracking

(Not tracked)

People

(Reporter: akachkach, Unassigned)

Details

Attachments

(2 files)

mwargers reported some differences he noticed between the JSON logs saved to a file and the logs printed to stdout when he runs this command (on MacOSX 10.9.5, with a debug build):

  ./mach mochitest-plain --log-mach=- --log-raw=mochi.json testing/mochitest/tests/Harness_sanity/

Here are the logs dumped to stdout:

https://pastebin.mozilla.org/6060051

Here are the raw JSON logs:

https://pastebin.mozilla.org/6060022

The problem here is some lines in stdout that seem to be dumped directly to stdout (instead of going through our structured logger) like this one:

System JS : WARNING /Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/_tests/testing/mochitest/server.js:444 - assignment to undeclared variable pathPieces

These lines are easily recognizable because they're not formatted (and can't be found in the JSON logs).

I'm not sure what causes this (since we transform unstructured logs to INFO messages: http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#129)
Attached file Logs in stdout
Since the pastebin links are going to expire in a day, here's the stdout logs.
Attached file JSON logs
... and here are the JSON logs.
The example in comment 0 comes from:

http://mxr.mozilla.org/mozilla-central/source/js/xpconnect/src/nsXPConnect.cpp#232

231     if (nsContentUtils::DOMWindowDumpEnabled()) {
232         fprintf(stderr, "System JS : %s %s:%d - %s\n",
233                 JSREPORT_IS_WARNING(rep->flags) ? "WARNING" : "ERROR",
234                 rep->filename, rep->lineno,
235                 message ? message : "<no message>");
236     }
Yep, and the others too. They seem to be all printed to stderr so I wonder what makes us miss some of these and get the others.

NI? ted since he seemed to know something about this on IRC.
Flags: needinfo?(ted)
After puzzling over this for a bit I figured it out. If you look closely at the filenames involved:
System JS : WARNING /Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/_tests/testing/mochitest/server.js:444 - assignment to undeclared variable pathPieces

That's server.js, which is running in the xpcshell process we use for the HTTP server. :)
Flags: needinfo?(ted)
Summary: Some C++ generated logs in mochitest are directly printed to stdout → server.js logs printed to stdout when running mochitests
Thanks ted! Didn't notice that at all, uh :/.

I guess this is sort of problematic (we don't want these logs to be lost when printing structured logs to a file) but probably not high priority.
You need to log in before you can comment on or make changes to this bug.