Marionette hides log output from Firefox (e.g. app.update.log=True)

RESOLVED INVALID

Status

defect
RESOLVED INVALID
4 years ago
3 years ago

People

(Reporter: whimboo, Unassigned)

Tracking

Trunk
All
Windows
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

For the Firefox update tests we have to enable the app.update.log preference to see detailed status of the application update in the console or log. As it looks like Marionette totally consumes this output. Also the gecko.log only contains the Marionette specific interactions with the application.

What would be good to have is a separate command line option which would us allow to specify a separate log file beside gecko.log, or let us dump the application logs to the console.

Here an example with app.update.log enabled and checking for an update in the about window of Firefox:

*** AUS:SVC Checker: checkForUpdates, force: true
*** AUS:SVC getLocale - getting locale from file: resource://gre/update.locale, locale: en-US
*** AUS:SVC Checker:getUpdateURL - update URL: https://aus4.mozilla.org/update/3/Firefox/39.0a1/20150310030235/Linux_x86_64-gcc3/en-US/nightly/Linux%203.16.0-31-generic%20(GTK%202.24.25)/default/default/update.xml?force=1
*** AUS:SVC gCanCheckForUpdates - able to check for updates
*** AUS:SVC recordInHealthReport - updateCheckStart - 0

Without that information we would not be able to investigate any problems related to update test failures. It's a must have for us.
Summary: Marionette hides logout from Firefox (e.g. app.update.log=True) → Marionette hides log output from Firefox (e.g. app.update.log=True)
We talked about how to get this to work on IRC by using "--gecko-log" to redirect the browser output and keeping marionette's own logging quiet by setting the "marionette.logging" pref to false.
The problem here is that we are logging way too much and log output from Firefox can very easily be overseen. As Chris mentioned Marionette should only log debug lines in a debug build but not with an opt build. But when I run an opt build I clearly see all the debug logging. Shouldn't we better get this stopped doing?

For now I will turn off logging for Marionette completely because it's a too much disturbing factor in gecko.log.
Whiteboard: [qa-automation-blocked]
Adding in here the current status from the POV of someone just coming into the project.

From https://bug1148546.bugzilla.mozilla.org/attachment.cgi?id=8586150 we can see that I already have some of the output described at the very beginning.
firefox-ui-update --binary FirefoxNightly.app/Contents/MacOS/firefox --update-direct-only --gecko-log -
> *** AUS:SVC Checker: checkForUpdates, force: true
> *** AUS:SVC getLocale - getting locale from file: resource://gre/update.locale, locale: en-US
> *** AUS:SVC Checker:getUpdateURL - update URL: https://aus4.mozilla.org/update/3/Firefox/40.0a1/20150330114816/Darwin_x86_64-gcc3-u-i386-x86_64/en-US/nightly/Darwin%2014.1.0/default/default/update.xml?force=1

I don't have these lines (perhaps only show on Linux code paths):
> *** AUS:SVC gCanCheckForUpdates - able to check for updates
> *** AUS:SVC recordInHealthReport - updateCheckStart - 0
So this bug actually only exists on Windows but not Linux and OS X.
OS: All → Windows
Ok, so this is not a bug in Marionette. It's just Firefox which stops logging after the first restart of the application. For details see bug 1008135 and deps.
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.