mozilla / geckodriver

WebDriver for Firefox
https://firefox-source-docs.mozilla.org/testing/geckodriver/
Mozilla Public License 2.0
7.16k stars 1.52k forks source link

latest gecko driver downloads updates during tests which highly impacts performance #686

Closed serpro69 closed 7 years ago

serpro69 commented 7 years ago

In order to help us efficiently investigate your issue, please provide the following information:

Firefox Version

53.0 x64

Platform

Windows 7 x64

Steps to reproduce -

Please provide a description of how to reproduce the problem, including the following essential elements:

When running my tests firefox driver stops executing commands because it starts downloading some things. Sometimes it resumes after download, sometimes fails because of timeout for page load. Still, even if it resumes, the delay for download is big, like a few minutes sometimes. And the starting point for download is very random, sometimes it starts before running tests, sometimes in the middle of test suite.

Here's the log:

1493190654998   addons.productaddons    INFO    sending request to: https://aus5.mozilla.org/update/3/GMP/53.0/20170413192749/WINNT_x86_64-msvc-x64/en-US/release/Windows_NT%206.1.1.0
%20(x64)/default/default/update.xml
1493190656309   addons.productaddons    INFO    Completed downloading document
1493190656675   addons.productaddons    INFO    downloadXHR File download. status=200
1493190656684   addons.productaddons    INFO    Downloaded file will be saved to C:\Users\L094540\AppData\Local\Temp\tmpaddon-c40aec
1493190658529   addons.productaddons    INFO    downloadXHR File download. status=200
1493190658536   addons.productaddons    INFO    Downloaded file will be saved to C:\Users\L094540\AppData\Local\Temp\tmpaddon-2e96c4

I have added the following preferences to the profile that I'm creating in test setup method

ffprofile.setPreference("app.update.enabled", false);
ffprofile.setPreference("app.update.service.enabled", false);
ffprofile.setPreference("app.update.auto", false);
ffprofile.setPreference("app.update.staging", false);
ffprofile.setPreference("app.update.silent", false);

however the result is the same.

Haven't noticed this behavior with selenium 3.3.* and firefox 49.0.2, only started with latest selenium+geckodriver

andreastt commented 7 years ago

@whimboo Do you know what’s going on here, given that you’re somewhat familiar with update tests? Are we missing setting some prefs in https://github.com/mozilla/geckodriver/blob/master/src/prefs.rs?

andreastt commented 7 years ago

@SergioLeone When you say “latest geckodriver”, do you mean you’re using 0.16.0?

whimboo commented 7 years ago

The above is not for application updates but its a download of GMP plugins (https://wiki.mozilla.org/GeckoMediaPlugins). So if you don't need those the appropriate prefs should be turned off. Just search for gmp in about:config to disable particular plugins.

serpro69 commented 7 years ago

@andreastt yes, 0.16.0

@whimboo Thanks, I'll look into that. But shouldn't this by default be set to false? I created a clean profile for my tests, and still I'm getting all sorts of updates for extensions and plugins every time I run the tests. So I have to explicitly disable a lot of things to insure a "clean" run. Wouldn't it make more sense if the default value would be set to false by the driver?

serpro69 commented 7 years ago

@whimboo could you please shed some light on the following. I'm not sure if this is an issue so I didn't want to open a new issue.

I often get this error while driver is executing commands, sometimes very often (after every test method or so) and it hangs the test execution as it repeatedly looks for some file and can not find it.

1493271206524   DeferredSave.extensions.json    DEBUG   Save changes
1493271206526   DeferredSave.extensions.json    DEBUG   Starting timer
1493271206547   DeferredSave.extensions.json    DEBUG   Starting write
1493271206554   DeferredSave.extensions.json    DEBUG   Write succeeded
JavaScript error: resource://app/modules/WindowsJumpLists.jsm, line 403: NS_ERROR_FILE_NOT_FOUND: Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [nsIJumpListSh
ortcut.app]
JavaScript error: resource://app/modules/WindowsJumpLists.jsm, line 403: NS_ERROR_FILE_NOT_FOUND: Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [nsIJumpListSh
ortcut.app]
JavaScript error: resource://app/modules/WindowsJumpLists.jsm, line 403: NS_ERROR_FILE_NOT_FOUND: Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [nsIJumpListSh
ortcut.app]

Couldn't find any information with regards to this error.

My current setup is as follows:

            log.info("Building firefox driver.");

            LoggingPreferences preferences = new LoggingPreferences();
            preferences.enable("INFO", Level.INFO);

            DesiredCapabilities caps = DesiredCapabilities.firefox();
            caps.setCapability(CapabilityType.BROWSER_NAME, "firefox");
            caps.setCapability(CapabilityType.BROWSER_VERSION, "53.0");
//            caps.setCapability(CapabilityType.ACCEPT_INSECURE_CERTS, true);
//            caps.setCapability(CapabilityType.ACCEPT_SSL_CERTS, true);
//            caps.setCapability(CapabilityType.SUPPORTS_JAVASCRIPT, true);
//            caps.setCapability(CapabilityType.HAS_NATIVE_EVENTS, true);
            caps.setCapability(CapabilityType.LOGGING_PREFS, preferences);
//            caps.setCapability(CapabilityType.ENABLE_PROFILING_CAPABILITY, true);
            caps.setCapability(CapabilityType.ForSeleniumServer.ENSURING_CLEAN_SESSION, true);
            caps.setCapability(CapabilityType.ELEMENT_SCROLL_BEHAVIOR, 0);
            caps.setPlatform(Platform.WINDOWS);
            caps.setCapability("marionette", true);

            ProfilesIni profilesIni = new ProfilesIni();
            FirefoxProfile ffprofile = profilesIni.getProfile(firefoxProfileName);
            ffprofile.setAcceptUntrustedCertificates(true);
            ffprofile.setAssumeUntrustedCertificateIssuer(true);
            ffprofile.setPreference("javascript.enabled", true);

            ffprofile.setPreference("app.update.enabled", false);
            ffprofile.setPreference("app.update.service.enabled", false);
            ffprofile.setPreference("app.update.auto", false);
            ffprofile.setPreference("app.update.staging.enabled", false);
            ffprofile.setPreference("app.update.silent", false);

            ffprofile.setPreference("media.gmp-provider.enabled", false);

            ffprofile.setPreference("extensions.update.autoUpdate", false);
            ffprofile.setPreference("extensions.update.autoUpdateEnabled", false);
            ffprofile.setPreference("extensions.update.enabled", false);
            ffprofile.setPreference("extensions.update.autoUpdateDefault", false);

            ffprofile.setPreference("lightweightThemes.update.enabled", false);

            FirefoxOptions options = new FirefoxOptions();
            options.setBinary(browserBinary);
            options.setProfile(ffprofile);
            options.setLogLevel(Level.SEVERE);

            System.setProperty("webdriver.gecko.driver", driverBinary);
whimboo commented 7 years ago

All those warnings/failures you can see here in the output are Firefox internal. The same applies to the listed add-ons. Those are the ones integrated in Firefox directly. So you don't have to worry about those.

Also a couple of the prefs you are setting yourself will be set by geckodriver anyway. So you can remove a couple of those. Just compare your list with the following one:

https://github.com/mozilla/geckodriver/blob/2e0054b90ecf1acbe8b442af54441e3cc746933f/src/prefs.rs

Please also have a look at issue #619. We might want to just stop the JS logging from the browser, which can be annoying.

whimboo commented 7 years ago

So I had a look into the logging capabilities of Firefox and the problem we have is that mostly each component can define it's own logger with a specific level. Means the log level of the root logger is not taking into account. Here an example of the addons logger:

https://dxr.mozilla.org/mozilla-central/rev/0b77ed3f26c5335503bc16e85b8c067382e7bb1e/toolkit/mozapps/extensions/AddonManager.jsm#171

It means that whatever the root logger is set to we will see even DEBUG output from this logger, until we would set the level of the root logger to eg. Info during the initialization of Marionette. But that would not stop all the output during startup of Firefox.

The only option I currently see is to really disable any kind of logging for modules you do not need. Actually I have no idea where addons.productaddons is coming from. But at least its under addons and should be controllable via the preference extensions.logging.enabled set to False. Given that it is disabled by default, I wonder where it could be enabled. It's not listed in your code above.

whimboo commented 7 years ago

@andreastt, I wonder if we should at least update the root logger level dependening on which log level we allow for Marionette. So that once Marionette has been initialized, we only log what the user has allowed.

serpro69 commented 7 years ago

@whimboo thank you for your input. You are correct, I don't have any browser logging enabled anywhere in my code except for the setup I've specified above. However, I've tried explicitly providing this preference ffprofile.setPreference("extensions.logging.enabled", false); and I'm getting the following exception Java.lang.IllegalArgumentException: Preference extensions.logging.enabled may not be overridden: frozen value=true, requested value=false

whimboo commented 7 years ago

Hm, are you using the Java or Javascript binding? At least for the former one I can see that a lot of preferences are frozen which will cause those massive log output:

https://github.com/SeleniumHQ/selenium/blob/282e7e882782c8ef18ec418212eba10f30dab9ed/javascript/firefox-driver/webdriver.json

serpro69 commented 7 years ago

@whimboo I'm using java bindings.

whimboo commented 7 years ago

So you will have to do some investigation on your side with the Java bindings why this preference is locked. Maybe @barancev can help, given that he already contributed to the Java bindings in the Selenium repository.

barancev commented 7 years ago

One can't change "frozen" preferences in a custom profile due to legacy FirefoxDriver restrictions.

But geckodriver provides a better way to pass preferences without creating a custom profile.

FirefoxOptions options = new FirefoxOptions();
options.addPreference("extensions.logging.enabled", false);
WebDriver driver = new FirefoxDriver(options);

It should allow to pass any preferences, there are no restrictions on the binding side.

whimboo commented 7 years ago

Btw is there a reason why extensions.logging.enabled is True by default?

whimboo commented 7 years ago

Maybe it was enabled due to the former FirefoxDriver which was implemented as an extension, and with extension logging it was possible to see failures in loading it? Now with Marionette in-place there is no extension anymore. So I would say that it should not turned on by default.

whimboo commented 7 years ago

Well, now I see the point. When using Geckodriver the profile class shouldn't be used at all, but every preference has to be passed via FirefoxOptions.

@SergioLeone, does the above proposal fixes your issue with the logging output?

What else remains for this issue on your side? I think that we can close it, or?

serpro69 commented 7 years ago

I have just tried the fix proposed by @barancev and it gives the same exception.

LoggingPreferences preferences = new LoggingPreferences();
preferences.enable("WARNING", Level.WARNING);

DesiredCapabilities caps = DesiredCapabilities.firefox();
caps.setCapability(CapabilityType.BROWSER_NAME, "firefox");
caps.setCapability(CapabilityType.BROWSER_VERSION, "53.0");
caps.setCapability(CapabilityType.LOGGING_PREFS, preferences);
caps.setCapability(CapabilityType.ENABLE_PROFILING_CAPABILITY, true);
caps.setCapability(CapabilityType.ELEMENT_SCROLL_BEHAVIOR, 1);
caps.setPlatform(Platform.WINDOWS);

String profilePath = "C:\\Users\\L094540\\AppData\\Roaming\\Mozilla\\Firefox\\Profiles\\pj8i6838.luke.skywalker";
FirefoxProfile ffprofile = new FirefoxProfile(new File(profilePath));

FirefoxOptions options = new FirefoxOptions();
options.addPreference("extensions.logging.enabled", false);

return new FirefoxDriver(options.addTo(caps));

getting: java.lang.IllegalArgumentException: Preference extensions.logging.enabled may not be overridden: frozen value=true, requested value=false

serpro69 commented 7 years ago

Sorry, my bad, I was still passing custom profile through options via options.setProfile(ffProfile) After I removed this line I'm not able to see addons logs anymore.

whimboo commented 7 years ago

Good, and with GMP disabled, I assume you do no longer have the issues as described in the initial comment?

serpro69 commented 7 years ago

Yes, so far so good. At least for now I don't see the driver attempting gmp update downloads. I still have an issue with tests hanging, but it seems like testng dataprovider issue, not geckodriver (Unfortunately I can not verify my tests on another browser to be sure completely so I'll have to dig into this further.)

Thank you @whimboo and @barancev for the help, have been fighting with this for the past two days.

nir20ane commented 7 years ago

@whimboo , @SergioLeone

I am facing the same issue:

Firefox 52.0 Gecko driver 15.0 Selenium 3.3

System.setProperty("webdriver.gecko.driver","\\geckodriver-v0.15.0-win64/geckodriver.exe");
FirefoxProfile firefoxProfile = new FirefoxProfile();       
firefoxProfile.setPreference("browser.helperApps.alwaysAsk.force", false);
firefoxProfile.setPreference("browser.download.folderList",2);
firefoxProfile.setPreference("browser.download.manager.showWhenStarting",false);
firefoxProfile.setPreference("browser.download.panel.shown",false);
    firefoxProfile.setPreference("extensions.blocklist.enabled", false);
firefoxProfile.setPreference("browser.download.manager.alertOnEXEOpen", false);
firefoxProfile.setPreference("browser.download.manager.focusWhenStarting", false);
firefoxProfile.setPreference("browser.download.manager.useWindow", true);
firefoxProfile.setPreference("browser.download.manager.closeWhenDone", true);
firefoxProfile.setPreference("media.gmp-manager.cert.requireBuiltIn",false);
firefoxProfile.setPreference("media.gmp-manager.cert.checkAttributes",false);
firefoxProfile.setPreference("media.gmp-provider.enabled",false);
firefoxProfile.setPreference("media.gmp-widevinecdm.enabled",false);
firefoxProfile.setPreference("media.gmp-widevinecdm.visible",false);
firefoxProfile.setPreference("media.gmp.trial-create.enabled",false);

DesiredCapabilities dc = DesiredCapabilities.firefox(); FirefoxOptions options = new FirefoxOptions(); options.addPreference("log", "{level: trace}"); options.setBinary("C:/Program Files (x86)/Mozilla Firefox/firefox.exe"); //options.addPreference("extensions.logging.enabled", false); dc.setCapability(FirefoxDriver.PROFILE, firefoxProfile); dc.setCapability("marionette", true); dc.setCapability("moz:firefoxOptions", options); driver = new FirefoxDriver(dc); baseURL = "http://";
driver.manage().timeouts().implicitlyWait(8000, TimeUnit.SECONDS); driver.manage().window().maximize();

My Log:

1493190654998 addons.productaddons INFO sending request to: https://aus5.mozilla.org/update/3/GMP/53.0/20170413192749/WINNT_x86_64-msvc-x64/en-US/release/Windows_NT%206.1.1.0 %20(x64)/default/default/update.xml 1493190656309 addons.productaddons INFO Completed downloading document 1493190656675 addons.productaddons INFO downloadXHR File download. status=200

Please help me in resolving this

whimboo commented 7 years ago

@nir20ane please read through the issue first before commenting me too. The answer can be found here: https://github.com/mozilla/geckodriver/issues/686#issuecomment-297694079. And what I read you are exactly doing the same.

nir20ane commented 7 years ago

@whimboo , I am not passing any custom profile here. I am not getting the mistake. Could you please help me by letting me know the mistake. thank you.

barancev commented 7 years ago

Yes you do:

dc.setCapability(FirefoxDriver.PROFILE, firefoxProfile);

Use FirefoxOptions to pass all the required preferences.

nir20ane commented 7 years ago

Thank you very much for your help @barancev , @whimboo. It works now.

javaversion commented 6 years ago

Hi guys,

I'am using Firefox 47.0.1 with selenium 3.4.0

Could you advise how to change "frozen" preferences if we don't use geckodriver? I would like to turn off all prefs related to GMP. If my understanding is correct FirefoxOptions manage specific settings in a way that geckodriver can understand.

Any help will be highly appreciated @barancev

whimboo commented 6 years ago

@javaversion not sure what else beside geckodriver you want to use?

andreastt commented 6 years ago

@javaversion Firefox 47 isn’t supported by geckodriver. You can set Firefox preferences through the moz:firefoxOptions dictionary. See the README for details.

lock[bot] commented 5 years ago

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.