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.

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

Calling Delete Session after Close Window returns error #966

Closed
ghost opened this issue Sep 21, 2017 · 16 comments
Closed

Calling Delete Session after Close Window returns error #966

ghost opened this issue Sep 21, 2017 · 16 comments

Comments

@ghost
Copy link

ghost commented Sep 21, 2017

System

  • Version: 0.19.0
  • Platform: Windows 10 64 Bit
  • Firefox: 55.0.3 (64-bit)
  • Selenium: Selenium-Java 3.5.3
  • Java: 1.8.0_144

Testcase

The following code attempts to simply open the browser, request "https://www.google.com/" and close the browser again.

package your_package_name

import org.openqa.selenium.WebDriver;
import org.openqa.selenium.firefox.FirefoxDriver;

public class Main {
	
	public static void main(String[] args) {
		System.setProperty("webdriver.gecko.driver", "C:\\dev\\Webdev\\Binaries\\geckodriver.exe");
		WebDriver driver = new FirefoxDriver(new FirefoxOptions().setLogLevel(Level.ALL));
		
		driver.get("https://www.google.com");
		driver.close();
	}

}

Stacktrace

There is no direct stacktrace, since there's no "Exception" happening within the JVM per se, however I get a windows notification, that "Mozilla Firefox stopped working correctly". If you need any logs from that, I'd gladly provide them if you tell me where I can find them.

In addition to that, after Mozilla crashes, it leaves a "geckodriver.exe" zombie process, which can be only killed through
taskkill /im geckodriver.exe /f
constantly draining 20 MB RAM, as well as small amounts of CPU usage, even though the JVM finished execution.

Trace-level log

I have decided to set the Log-Level to "ALL", since the Java geckodriver doesn't support Log.TRACE.

1505982734793	geckodriver	INFO	geckodriver 0.19.0
1505982734810	geckodriver	INFO	Listening on 127.0.0.1:29414
1505982735553	mozrunner::runner	INFO	Running command: "C:\\Program Files\\Mozilla Firefox\\firefox.exe" "-marionette" "-profile" "C:\\Users\\WMESCH~1\\AppData\\Local\\Temp\\rust_mozprofile.pUG9YPIn5vtA"
1505982737086	addons.xpi	WARN	Error parsing extensions state: [Exception... "Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [amIAddonManagerStartup.readStartupData]"  nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: loadExtensionState :: line 1596"  data: no] Stack trace: loadExtensionState()@resource://gre/modules/addons/XPIProvider.jsm:1596 < getInstallState()@resource://gre/modules/addons/XPIProvider.jsm:1631 < checkForChanges()@resource://gre/modules/addons/XPIProvider.jsm:3152 < startup()@resource://gre/modules/addons/XPIProvider.jsm:2246 < callProvider()@resource://gre/modules/AddonManager.jsm:271 < _startProvider()@resource://gre/modules/AddonManager.jsm:741 < startup()@resource://gre/modules/AddonManager.jsm:908 < startup()@resource://gre/modules/AddonManager.jsm:3122 < observe()@jar:file:///C:/Program%20Files/Mozilla%20Firefox/omni.ja!/components/addonManager.js:65
1505982737608	geckodriver::marionette	TRACE	  connection attempt 0/600
1505982737809	Marionette	DEBUG	Received observer notification "profile-after-change"
1505982738211	Marionette	DEBUG	Received observer notification "command-line-startup"
1505982738211	Marionette	INFO	Enabled via --marionette
1505982739714	geckodriver::marionette	TRACE	  connection attempt 1/600
1505982740840	Marionette	DEBUG	Received observer notification "sessionstore-windows-restored"
1505982740841	Marionette	DEBUG	Received observer notification "sessionstore-windows-restored"
1505982741046	Marionette	DEBUG	Received observer notification "domwindowclosed"
1505982741048	Marionette	DEBUG	Received observer notification "domwindowclosed"
Unable to read VR Path Registry from C:\Users\wmeschalin\AppData\Local\openvr\openvrpaths.vrpath
[Child 8348] WARNING: pipe error: 109: file c:/builds/moz2_slave/m-rel-w64-00000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
[Child 8348] WARNING: pipe error: 109: file c:/builds/moz2_slave/m-rel-w64-00000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
1505982741473	Marionette	DEBUG	Setting recommended pref toolkit.cosmeticAnimations.enabled to false
1505982741475	Marionette	DEBUG	Setting recommended pref datareporting.policy.dataSubmissionPolicyAccepted to false
1505982741477	Marionette	INFO	Listening on port 57240
1505982741579	Marionette	INFO	Listening on port 57240
1505982741823	geckodriver::marionette	TRACE	  connection attempt 2/600
1505982741924	geckodriver::marionette	DEBUG	Connected to Marionette on localhost:57240
1505982741934	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:57258
1505982741940	geckodriver::marionette	TRACE	<- {"applicationType":"gecko","marionetteProtocol":3}
1505982741941	geckodriver::marionette	TRACE	-> 62:[0,1,"newSession",{"capabilities":{"desiredCapabilities":{}}}]
1505982741943	Marionette	TRACE	0 -> [0,1,"newSession",{"capabilities":{"desiredCapabilities":{}}}]
1505982741946	Marionette	CONFIG	Matched capabilities: {"browserName":"firefox","browserVersion":"55.0.3","platformName":"windows_nt","platformVersion":"10.0","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":7856,"moz:profile":"C:\\Users\\WMESCH~1\\AppData\\Local\\Temp\\rust_mozprofile.pUG9YPIn5vtA","moz:accessibilityChecks":false}
1505982741997	Marionette	DEBUG	loaded listener.js
1505982742023	Marionette	TRACE	0 <- [1,1,null,{"sessionId":"59a4038e-62cd-44e9-b4b3-14c4b10d5f16","capabilities":{"browserName":"firefox","browserVersion":"55.0.3","platformName":"windows_nt","platformVersion":"10.0","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":7856,"moz:profile":"C:\\Users\\WMESCH~1\\AppData\\Local\\Temp\\rust_mozprofile.pUG9YPIn5vtA","moz:accessibilityChecks":false}}]
1505982742032	geckodriver::marionette	TRACE	<- [1,1,null,{"sessionId":"59a4038e-62cd-44e9-b4b3-14c4b10d5f16","capabilities":{"browserName":"firefox","browserVersion":"55.0.3","platformName":"windows_nt","platformVersion":"10.0","pageLoadStrategy":"normal","acceptInsecureCerts":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"rotatable":false,"specificationLevel":0,"moz:processID":7856,"moz:profile":"C:\\Users\\WMESCH~1\\AppData\\Local\\Temp\\rust_mozprofile.pUG9YPIn5vtA","moz:accessibilityChecks":false}}]
1505982742032	webdriver::server	DEBUG	<- 200 OK {"value": {"sessionId":"59a4038e-62cd-44e9-b4b3-14c4b10d5f16","capabilities":{"acceptInsecureCerts":false,"browserName":"firefox","browserVersion":"55.0.3","moz:accessibilityChecks":false,"moz:processID":7856,"moz:profile":"C:\\Users\\WMESCH~1\\AppData\\Local\\Temp\\rust_mozprofile.pUG9YPIn5vtA","pageLoadStrategy":"normal","platformName":"windows_nt","platformVersion":"10.0","rotatable":false,"specificationLevel":0,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000}}}}
Sep 21, 2017 10:32:22 AM org.openqa.selenium.remote.ProtocolHandshake createSession
INFORMATION: Detected dialect: W3C
1505982742191	webdriver::server	DEBUG	-> POST /session/59a4038e-62cd-44e9-b4b3-14c4b10d5f16/url {"url":"https://www.google.com"}
1505982742192	geckodriver::marionette	TRACE	-> 44:[0,2,"get",{"url":"https://www.google.com"}]
1505982742206	Marionette	TRACE	0 -> [0,2,"get",{"url":"https://www.google.com"}]
1505982742211	Marionette	DEBUG	Received DOM event "beforeunload" for "about:blank"
1505982742676	Marionette	DEBUG	Received DOM event "pagehide" for "about:blank"
1505982742677	Marionette	DEBUG	Received DOM event "unload" for "about:blank"
1505982742967	Marionette	DEBUG	Received DOM event "DOMContentLoaded" for "https://www.google.de/?gfe_rd=cr&dcr=0&ei=FnnDWfSIEsL68AeYtIGAAw"
1505982743480	Marionette	DEBUG	Received observer notification "outer-window-destroyed" for "4294967301"
1505982743724	Marionette	DEBUG	Received DOM event "DOMContentLoaded" for "https://www.google.de/?gfe_rd=cr&dcr=0&ei=FnnDWfSIEsL68AeYtIGAAw"
1505982743726	Marionette	DEBUG	Received DOM event "pageshow" for "https://www.google.de/?gfe_rd=cr&dcr=0&ei=FnnDWfSIEsL68AeYtIGAAw"
1505982743802	Marionette	DEBUG	Received DOM event "pageshow" for "https://www.google.de/?gfe_rd=cr&dcr=0&ei=FnnDWfSIEsL68AeYtIGAAw"
1505982743804	Marionette	TRACE	0 <- [1,2,null,{}]
1505982743809	geckodriver::marionette	TRACE	<- [1,2,null,{}]
1505982743809	webdriver::server	DEBUG	<- 200 OK {"value": {}}
1505982743818	webdriver::server	DEBUG	-> DELETE /session/59a4038e-62cd-44e9-b4b3-14c4b10d5f16/window 
1505982743819	geckodriver::marionette	TRACE	-> 16:[0,3,"close",{}]
1505982743821	Marionette	TRACE	0 -> [0,3,"close",{}]
1505982743823	Marionette	TRACE	0 <- [1,3,null,[]]
1505982743829	geckodriver::marionette	TRACE	<- [1,3,null,[]]
1505982743829	webdriver::server	DEBUG	Last window was closed, deleting session
1505982743829	webdriver::server	DEBUG	Deleting session
1505982743829	geckodriver::marionette	DEBUG	Stopping browser process
1505982744533	webdriver::server	DEBUG	<- 200 OK {"value": []}

If you need additional information I will provide them as soon as possible.
Best regards,
WM

@curtisy1
Copy link

What happens if you properly call driver.quit() after dirver.close()? The trace log looks like everything went without issues.

@ghost
Copy link
Author

ghost commented Sep 21, 2017

Same log as before, however, this is appended:

1505996023009	webdriver::server	DEBUG	-> DELETE /session/38238f7a-29a7-4a6f-806a-a8cac01a783d 
1505996023012	webdriver::server	DEBUG	<- 500 Internal Server Error {"value":{"error":"session not created","message":"Tried to run command without establishing a connection","stacktrace":"stack backtrace:\n   0:           0x4821c4 - <no info>\n   1:           0x482933 - <no info>\n   2:           0x445281 - <no info>\n   3:           0x42fef7 - <no info>\n   4:           0x40ba4e - <no info>\n   5:           0x4119b9 - <no info>\n   6:           0x6d2c89 - <no info>\n   7:           0x426006 - <no info>\n   8:           0x6cd490 - <no info>\n   9:     0x7ff9c77f2774 - BaseThreadInitThunk"}}
1505996023066	webdriver::server	DEBUG	-> GET /shutdown 
1505996023068	webdriver::server	DEBUG	<- 404 Not Found {"value":{"error":"unknown command","message":"GET /shutdown did not match a known command","stacktrace":"stack backtrace:\n   0:           0x4821c4 - <no info>\n   1:           0x482933 - <no info>\n   2:           0x445159 - <no info>\n   3:           0x43f00a - <no info>\n   4:           0x409e7b - <no info>\n   5:           0x41198a - <no info>\n   6:           0x6d2c89 - <no info>\n   7:           0x426245 - <no info>\n   8:           0x6cd490 - <no info>\n   9:     0x7ff9c77f2774 - BaseThreadInitThunk"}}
Sep 21, 2017 2:13:52 PM org.openqa.selenium.os.UnixProcess destroy
INFORMATION: Unable to drain process streams. Ignoring but the exception being swallowed follows.
org.apache.commons.exec.ExecuteException: The stop timeout of 2000 ms was exceeded (Exit value: -559038737)
	at org.apache.commons.exec.PumpStreamHandler.stopThread(PumpStreamHandler.java:295)
	at org.apache.commons.exec.PumpStreamHandler.stop(PumpStreamHandler.java:181)
	at org.openqa.selenium.os.UnixProcess.destroy(UnixProcess.java:137)
	at org.openqa.selenium.os.CommandLine.destroy(CommandLine.java:153)
	at org.openqa.selenium.remote.service.DriverService.stop(DriverService.java:220)
	at org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:94)
	at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:646)
	at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:703)
	at org.openqa.selenium.remote.RemoteWebDriver.quit(RemoteWebDriver.java:542)
	at cucumberTest.SeleniumTest.main(SeleniumTest.java:17)

Sep 21, 2017 2:13:52 PM org.openqa.selenium.os.UnixProcess destroy
CRITICAL: Unable to kill process with PID 12752
Exception in thread "main" org.openqa.selenium.SessionNotCreatedException: Tried to run command without establishing a connection
Build info: version: 'unknown', revision: 'unknown', time: 'unknown'
System info: host: 'R1002-WME', ip: 'XXX.XXX.XXX.XXX', os.name: 'Windows 10', os.arch: 'amd64', os.version: '10.0', java.version: '1.8.0_144'
Driver info: org.openqa.selenium.firefox.FirefoxDriver
Capabilities [{moz:profile=C:\Users\WMESCH~1\AppData\Local\Temp\rust_mozprofile.4xs3beHcB9x2, rotatable=false, timeouts={implicit=0, pageLoad=300000, script=30000}, pageLoadStrategy=normal, platform=XP, specificationLevel=0, moz:accessibilityChecks=false, acceptInsecureCerts=false, browserVersion=55.0.3, platformVersion=10.0, moz:processID=10204, browserName=firefox, javascriptEnabled=true, platformName=XP}]
Session ID: 38238f7a-29a7-4a6f-806a-a8cac01a783d
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
	at java.lang.reflect.Constructor.newInstance(Unknown Source)
	at org.openqa.selenium.remote.http.W3CHttpResponseCodec.createException(W3CHttpResponseCodec.java:185)
	at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:120)
	at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:49)
	at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:164)
	at org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:82)
	at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:646)
	at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:703)
	at org.openqa.selenium.remote.RemoteWebDriver.quit(RemoteWebDriver.java:542)
	at cucumberTest.SeleniumTest.main(SeleniumTest.java:17)

Same thing, another zombie process, another crash.

@andreastt
Copy link
Contributor

This is expected behaviour. The Close Window command should end the session if it closes the last window. The subsequent Delete Session command then returns an error because the session has already been ended.

Please file a bug with your client.

@ghost
Copy link
Author

ghost commented Sep 25, 2017

So the zombie geckodriver.exe Thread is also "expected behavior" since it doesn't really ever end, right?
I would expect geckodriver to properly close Firefox instead of just crashing it, since the IEDriver and chromedriver both manage to close their browsers without crashing them.

Also, if I run a hundred different selenium tests, and all of them leave a zombie process draining 20 MB, I will effectively waste 2 GB in RAM.
You can close threads all you like, if I need to write workarounds for an obvious programming flaw then this is actually quite sad for a company of the size of mozilla.

@curtisy1
Copy link

curtisy1 commented Sep 25, 2017 via email

@ghost
Copy link
Author

ghost commented Sep 26, 2017

You're referencing my own ticket @curtisy1. I'm refering to THIS issue, if the geckodriver leaves zombie threads then this is not good. It's not something that can be simply overlooked, since it might be detrimental to the testing environment, since it's wasting RAM and ports.

I consider to have a right to criticize other programmers if they're producing potentially dangerous errors. Especially if they're doing this for a big name as mozilla, free-time or not. There's no excuse for leaving flaws in software, if they're avoidable. And this really seems like a geckodriver issue instead of other issues, since I can literally use "driver.quit();" and it doesn't produce the error explained here, however doesn't have the behavior I want to have.

I'm going to look into different versions of Firefox, I'll see if that makes any difference and if it does I'll provide my answer here.

@curtisy1
Copy link

curtisy1 commented Sep 26, 2017 via email

@whimboo
Copy link
Collaborator

whimboo commented Sep 26, 2017

@KrypTheBear can you please test with Firefox 56.0 which will be released today? I'm fairly sure you won't see the crash anymore. If you want to test right away you can use the latest beta release.

I would like to know if that makes a difference to you. But generally it's correct that geckodriver should better handle that.

@whimboo
Copy link
Collaborator

whimboo commented Sep 26, 2017

Btw. for handling the crash we have issue #954 and bug 1401109

@ghost
Copy link
Author

ghost commented Sep 26, 2017

@whimboo Alright, using the newest version of the Firefox at least prevents it from crashing, hooray :)

As to why I'm unwilling to use driver.quit() => After using driver.close(); to close the active window, and then calling driver.quit(); I recieve an org.openqa.selenium.SessionNotCreatedException which messes up the execution by a good bit. (Like I mentioned in my log before that you were asking for. @curtisy1 ) This should not be expected behavior. I suspect that we don't check here for the case of "We just want to close the driver and have no open Firefox sessions".

And thanks again for the help, I really do appreciate it.

@whimboo
Copy link
Collaborator

whimboo commented Sep 27, 2017

For details in how close should be handled see here:
https://w3c.github.io/webdriver/webdriver-spec.html#close-window

That said, if only a single tab/window is open it will be closed, and as such the session will be closed too. A following call to quit will indeed cause an issue as layed out above.

But reading the spec about Delete Session I see:

  1. If the current session is an active session, try to close the session.
  2. Return success with data null.

There is nothing specified how an already deleted session should be handled. By the above words I assume we should do nothing, and still return success.

@andreastt can you please have a closer look here? I'm reopening it for now.

@whimboo whimboo reopened this Sep 27, 2017
@andreastt
Copy link
Contributor

@whimboo I made a change to the Delete Session command some time ago so that it always return success. I don’t think this is reflected in geckodriver yet.

@andreastt andreastt changed the title geckodriver 0.19.0 crashes Mozilla Firefox after invoking driver.close(); Calling Delete Session after Close Window returns error Sep 27, 2017
@andreastt
Copy link
Contributor

Filed https://bugzilla.mozilla.org/show_bug.cgi?id=1403510 to track this.

@whimboo
Copy link
Collaborator

whimboo commented Sep 27, 2017

Ok, so it's a geckodriver and not Selenium issue. Thanks.

@whimboo
Copy link
Collaborator

whimboo commented Jun 1, 2018

Dupe of issue #732.

@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.
Projects
None yet
Development

No branches or pull requests

3 participants