Why do Windows runs of tt(c) not log from the background update process, but Mac runs do?
Categories
(Toolkit :: Telemetry, task, P3)
Tracking
()
People
(Reporter: chutten, Unassigned)
Details
Windows runs of tt(c) do not log from the background update process. But MacOSX runs do (failing run, succeeding run).
Why is that? Is it something that can be fixed?
(( I have no data for Linux as the feature (and thus the test) do not run on Linux ))
|
||
Comment 2•3 years ago
|
||
(In reply to Chris H-C :chutten from comment #1)
:raphael, I don't suppose you know?
No, I don't know why the Windows runs wouldn't show these logs. Could that be because of the implementation of the background update? The way we're calling Marionette?
:whimboo do you have an idea, maybe?
|
||
Comment 3•3 years ago
|
||
It's not clear to me which specific logging you are referring to here. Maybe you can clarify and directly link to some logs? Maybe the background update doesn't set browser.dom.window.dump.enabled to true?
|
Reporter | |
Comment 4•3 years ago
|
||
Whatever it is it's Windows-specific. Mac logs just fine.
For an example of the logs I'd expect, see this line:
[task 2021-09-09T20:16:54.225Z] 20:16:54 INFO - [Parent 1237: Unnamed thread 11a40caa0]: I/glean_core::* [glean_core] The ping 'background-update' was submitted and will be sent as soon as possible
That can only come from the background update "app". And we can see the marionette process logging that it received the "background-update" ping.
On Windows, the marionette process logs that it received the ping, but there's no log saying it was ever submitted.
Lemme try a build where it sets that bool pref and see where it gets me.
|
|
Reporter | |
Comment 5•3 years ago
|
||
Alas, no luck locally.
I added
Services.prefs.setBoolPref("browser.dom.window.dump.enabled", true);
Just before this line, and there was no change to logging.
|
|
||
Comment 6•3 years ago
|
||
So glean is written in Rust, right? With Marionette we do not modify any log reporting on the Firefox side. Do you see these log entries on Windows when you just run mach run? If not there might be a lower level issue, which prevents even INFO level logs from Rust being written out.
|
|
Reporter | |
Comment 7•3 years ago
|
||
Glean is written in Rust, correct, but the Background Update task is written in a JSM over here and also logs (see lines like this from the JSM). There are also additional missing logs from the headless background process like these from nsAppRunner.cpp suggesting that this is affecting all logs, not just Rust ones.
I had a random thought the other day that this could be due to platform differences in inheriting file descriptors coupled with redirection of stdout/stderr in test mode... but I have no way to check that. Does that make any sense?
|
|
||
Comment 8•3 years ago
|
||
The only problem I'm aware of on Windows is the requirement for browser.dom.window.dump.enabled=true to see some logging output. But given that you already tried that I have no idea what else could cause that behavior. Maybe someone from the platform team could help out?
|
|
Reporter | |
Comment 9•3 years ago
•
|
||
Sounds very reasonable. Since I've worked Background Tasks with him before, I wonder if :nalexander might have some suspicions.
To sum: On Windows the background update task doesn't log in a way that local console or CI's capturing can see. But on the MacOS CI runs it does (I don't have Apple hw to test local, but I assume it logs there). I've tried a local run on Windows with browser.dom.window.dump.enabled set true at this point to no avail.
Any ideas how we might get logging from that process from Windows in CI and locally?
|
||
Comment 10•3 years ago
|
||
(In reply to Chris H-C :chutten from comment #9)
Sounds very reasonable. Since I've worked Background Tasks with him before, I wonder if :nalexander might have some suspicions.
To sum: On Windows the background update task doesn't log in a way that local console or CI's capturing can see. But on the MacOS CI runs it does (I don't have Apple hw to test local, but I assume it logs there). I've tried a local run on Windows with
browser.dom.window.dump.enabledsettrueat this point to no avail.Any ideas how we might get logging from that process from Windows in CI and locally?
Sorry for the delayed reply. I think this is a repercussion of a fairly deep structural difference between *nix and Windows: namely, Windows programs don't have open console handles by default. You can force Firefox (and --backgroundtask) invocations to create a console by including --console, but the console so opened doesn't hang around for you to see the output, so it's not much use. The closest to what you want is to attach to an existing parent console by including --attach-console. Hopefully that unblocks your immediate concern.
It's possible that we should do that by default on Windows when we're running in CI, but there's a great deal of history in the area so I expect it might require some thought. I vaguely recall that it's possible to interrogate whether a parent console exists and attach to it if the answer is yes, but I don't recall why we don't do that automatically at the moment.
|
|
Reporter | |
Comment 11•3 years ago
|
||
Thank you for the resolution. The severity's deflated out of this now that the related failures have been diagnosed. An explanation and a workaround for next time is a perfectly fine way to call this done.
Description
•