Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[GeckoDriver v0.23.0 - Selenium 3.14.0 - Firefox v62.0.3] How to configure GeckoDriver to control the Marionette logs through LoggingPreferences? #1392

Closed
Debanjan-B opened this issue Oct 8, 2018 · 9 comments
Closed

[GeckoDriver v0.23.0 - Selenium 3.14.0 - Firefox v62.0.3] How to configure GeckoDriver to control the Marionette logs through LoggingPreferences? #1392

Debanjan-B opened this issue Oct 8, 2018 · 9 comments

Comments

@Debanjan-B
Copy link

Debanjan-B commented Oct 8, 2018 •
edited
Loading

[GeckoDriver v0.23.0 - Selenium 3.14.0 - Firefox v62.0.3] How to configure GeckoDriver to control the Marionette logs through LoggingPreferences?

System

  • Version: 0.23.0
  • Platform: Windows8, Pro
  • Firefox: 62.0.3
  • Selenium: 3.14.0

Testcase:

I am trying to configure the loglevel of BROWSER, CLIENT, DRIVER, PROFILER, PERFORMANCE, and SERVER through an instance of LoggingPreferences setting the LogType to Level.OFF.

With Selenium 3.14.0, GeckoDriver v0.23.0 and Firefox v62.0.3 still unable to control the following logs:

  • Parent xxx, Gecko_IOThread: WARNING
  • Marionette: WARNING, INFO and DEBUG
  • Child xyz, Chrome_ChildThread: WARNING

PS:

This usecase is based on LoggingPreferences avoiding FirefoxDriverLogLevel

MCVE:

package demo;

import java.util.logging.Level;
import org.openqa.selenium.WebDriver;
import org.openqa.selenium.firefox.FirefoxDriver;
import org.openqa.selenium.firefox.FirefoxOptions;
import org.openqa.selenium.logging.LogType;
import org.openqa.selenium.logging.LoggingPreferences;
import org.openqa.selenium.remote.CapabilityType;
import org.openqa.selenium.remote.DesiredCapabilities;

public class A_geckoDriverLogs_LoggingPreferences
{
	public static void main(String[] args) throws Exception 
	{
		System.setProperty("webdriver.gecko.driver", "C:/Utility/BrowserDrivers/geckodriver.exe");
		LoggingPreferences preferences = new LoggingPreferences();
		preferences.enable(LogType.BROWSER, Level.OFF);
		preferences.enable(LogType.CLIENT, Level.OFF);
		preferences.enable(LogType.DRIVER, Level.OFF);
		preferences.enable(LogType.PROFILER, Level.OFF);
		preferences.enable(LogType.PERFORMANCE, Level.OFF);
		preferences.enable(LogType.SERVER, Level.OFF);
		DesiredCapabilities dc = new DesiredCapabilities();
                dc.setCapability(CapabilityType.LOGGING_PREFS, preferences);
		FirefoxOptions opt = new FirefoxOptions();
		opt.merge(dc);
		WebDriver driver =  new FirefoxDriver(opt);
	        driver.get("https://www.google.co.in");
	        Thread.sleep(15000); //Let the user see something
	        driver.quit();
	}
}

Stacktrace

1539004457347	mozrunner::runner	INFO	Running command: "C:\\Program Files\\Mozilla Firefox\\firefox.exe" "-marionette" "-foreground" "-no-remote" "-profile" "C:\\Users\\ATECHM~1\\AppData\\Local\\Temp\\rust_mozprofile.0XHawrEt7mut"
[Parent 1308, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
1539004467818	Marionette	INFO	Listening on port 10659
1539004467844	Marionette	WARN	TLS certificate errors will be ignored for this session
1539004468533	Marionette	DEBUG	[6442450945] Frame script loaded
1539004468536	Marionette	DEBUG	[6442450945] Frame script registered
Oct 08, 2018 6:44:28 PM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: W3C
1539004468847	Marionette	DEBUG	[6442450945] Received DOM event beforeunload for about:blank
1539004469888	Marionette	DEBUG	[6442450945] Received DOM event pagehide for about:blank
1539004470240	Marionette	DEBUG	[6442450945] Received DOM event DOMContentLoaded for https://www.google.co.in/
1539004471236	Marionette	DEBUG	[6442450945] Received DOM event pageshow for https://www.google.co.in/
1539004486265	Marionette	INFO	Stopped listening on port 10659
[Parent 1308, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 4792, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 4792, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 2020, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 2020, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Parent 1308, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 3416, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 3416, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[GPU 3960, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346

###!!! [Child][MessageChannel::SendAndWait] Error: Channel error: cannot send/recv

Trace-level log
@Debanjan-B Debanjan-B changed the title [GeckoDriver v0.23.0 - Selenium 3.14.0 - Firefox v62.0.3] How to configure GeckoDriver to control the Marionette logs? [GeckoDriver v0.23.0 - Selenium 3.14.0 - Firefox v62.0.3] How to configure GeckoDriver to control the Marionette logs through LoggingPreferences? Oct 8, 2018
@andreastt
Copy link
Contributor

See https://firefox-source-docs.mozilla.org/testing/geckodriver/geckodriver/TraceLogs.html for documentation on enabling trace-level logs. There are examples near the bottom.

@Debanjan-B
Copy link
Author

Thanks @andreastt for looking into this issue. As my objective was to control the log messages through LoggingPreferences hence I explicitly mentioned ...This usecase is based on LoggingPreferences avoiding FirefoxDriverLogLevel... as a post script.

However, as per the documentation Enabling trace logs though fatal seems to carry the least bandwidth we can still see the same set of logs:

  • Parent xxx, Gecko_IOThread: WARNING
  • Marionette: WARNING, INFO and DEBUG
  • Child xyz, Chrome_ChildThread: WARNING

#MCVE:

package demo;

import org.openqa.selenium.WebDriver;
import org.openqa.selenium.firefox.FirefoxDriver;
import org.openqa.selenium.firefox.FirefoxDriverLogLevel;
import org.openqa.selenium.firefox.FirefoxOptions;
import org.openqa.selenium.remote.DesiredCapabilities;

public class A_GeckoDriverLogs_FirefoxDriverLogLevel
{
	public static void main(String[] args) throws Exception 
	{
		System.setProperty("webdriver.gecko.driver", "C:/Utility/BrowserDrivers/geckodriver.exe");
		DesiredCapabilities dc = new DesiredCapabilities();
 		FirefoxOptions opt = new FirefoxOptions();
		opt.merge(dc);
		opt.setLogLevel(FirefoxDriverLogLevel.FATAL);
		WebDriver driver =  new FirefoxDriver(opt);
	        driver.get("https://www.google.co.in");
	        Thread.sleep(15000); //Let the user see something
	        driver.quit();
	}
}

Stacktrace:

1539007556817	Marionette	DEBUG	[6442450945] Frame script loaded
1539007556819	Marionette	DEBUG	[6442450945] Frame script registered
Oct 08, 2018 7:35:56 PM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: W3C
1539007556902	Marionette	DEBUG	[6442450945] Received DOM event beforeunload for about:blank
1539007558891	Marionette	DEBUG	[6442450945] Received DOM event pagehide for about:blank
1539007559079	Marionette	DEBUG	[6442450945] Received DOM event DOMContentLoaded for https://www.google.co.in/
1539007560177	Marionette	DEBUG	[6442450945] Received DOM event pageshow for https://www.google.co.in/
[Child 2356, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 2356, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Parent 5804, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 4840, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 4840, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 1340, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 1340, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Parent 5804, Gecko_IOThread] WARNING: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 188
[GPU 6104, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346

@andreastt
Copy link
Contributor

You should ask the Selenium people for Selenium API specific questions.

@andreastt
Copy link
Contributor

Parent xxx, Gecko_IOThread: WARNING
Marionette: WARNING, INFO and DEBUG
Child xyz, Chrome_ChildThread: WARNING

Setting the log level through geckodriver only controls the Marionette logger. The others cannot be controlled.

@Debanjan-B
Copy link
Author

Thanks again @andreastt Perhaps I need your help to understand your comment. When you say ...Setting the log level through geckodriver only controls the Marionette logger... I understand Marionette shouldn't produce the logs. But we still see Marionette: WARNING, INFO and DEBUG. So isn't the issue GeckoDriver specific issue? Apologies if I am on the wrong track.

@andreastt
Copy link
Contributor

andreastt commented Oct 8, 2018 •
edited
Loading

Well, I don’t know what opt.setLogLevel(FirefoxDriverLogLevel.FATAL) does since that is a Selenium API. Whatever that API does, it should end up sending {"moz:firefoxOptions": {"log": {"level": "fatal"}}} to geckodriver, but without a trace-level log it’s hard to tell what’s going on.

And yes, if you set that to fatal I wouldn’t expect to see either INFO or DEBUG from the Marionette logger at all.

@Debanjan-B
Copy link
Author

Thanks again @andreastt for the beautiful explanation. I will take up this with Selenium team.

@whimboo
Copy link
Collaborator

whimboo commented Oct 16, 2018

See also #619 for the Firefox log output.

@lock
Copy link

lock bot commented Aug 16, 2019

This issue has been automatically locked since there has not been any recent activity after it was closed. If you have run into an issue you think is related, please open a new issue.

@lock lock bot locked and limited conversation to collaborators Aug 16, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@whimboo @andreastt @Debanjan-B