The HTTP request to the remote WebDriver server for URL.../execute/sync time out after 60.seconds

[biddles]

Hi,
I use ff 49.0.1 with silent install. geckodriver-v0.11.1-win64.zip
Then I use

option.BrowserExecutableLocation = UserDefined.FIREFOX_BINARY_LOCATION;
 theDriver = new QAS.Firefox.FirefoxDriver(option);

Then I run

linkJs = @"$('body>div>div:visible').filter(function(index) {  return $('a',this).length>0;
                    }).filter(function(index) {  return index != 0; }).filter(function(index)   {
                    return index != 4})";
((IJavaScriptExecutor)fdriver).ExecuteScript("return " + linkJs+ ".find('a');");

Then I get the error:
1479094132338   geckodriver     INFO    Listening on 127.0.0.1:49789
1479094133766   mozprofile::profile     INFO    Using profile path C:\Users\LOCALA~1\AppData\Local\Temp\rust_mozprofile.sEANsl1e9p3y
1479094133783   geckodriver::marionette INFO    Starting browser C:\Program Files\Mozilla Firefox\firefox.exe
1479094133797   geckodriver::marionette INFO    Connecting to Marionette on localhost:49794
[INFO] OneDriver - created IWebDriver instance.
-------------------Get Links Start:------------------------
[INFO] CommonTools - GetLinksByUrl -Browser info:firefox
[INFO] CommonTools - GetLinksByUrl - Try to wait document ready.
1---- visiDiv:6
4---- linkJs:$('body>div>div:visible').filter(function(index) {  return $('a',this).length>0;
                    }).filter(function(index) {  return index != 0; }).filter(function(index)   {
                    return index != 4; })
-------------------- Program main exception -------------------------------
[Exception] Program: The HTTP request to the remote WebDriver server for URL 
http://localhost:49789/session/67d89b98-b80d-4ada-a668-4f77afa8c91b/execute/sync timed out after 60 seconds.
please exit,then check input values and run again

Is this a bug or I make any mistake?

Win10 X64 C#

[biddles]

By the way, It work fine on IE, edge,and Chome.
And on Firefox 48.0.2. It failed with Failed to find value field.

[andreastt]

That’s difficult to say. Can you increase the verbosity by setting the {moz:firefoxOptions: {log: {level: "trace"}}} capability?

[biddles]

I add options.SetLoggingPreference(LogType.Browser, LogLevel.All); in my code.

Then add
var entries = fdriver.Manage().Logs.GetLog(LogType.Browser);
foreach (var entry in entries)
{
Console.WriteLine(" ------ " + entry.ToString());
}
When I run my app.
There is no more info in console. And about entries. Because it is behind
((IJavaScriptExecutor)fdriver).ExecuteScript("return " + linkJs+ ".find('a');");.
So, app throw exception and do not run this code.

In Visual Studio:
{"The HTTP request to the remote WebDriver server for URL http://localhost:43043/session/8bb04401-3c8d-44cd-8d18-ea79839e39ff/execute/sync timed out after 60 seconds."}
In InnerException :- InnerException {"The operation has timed out"}
StackTrace " at System.Net.HttpWebRequest.GetResponse()\r\n at OpenQA.Selenium.Remote.HttpCommandExecutor.CreateResponse(WebRequest request)" string

Hope they usefully.

[AutomatedTester]

This is an issue with the client bindings defaulting to timeout connections after 60s, please raise this issue with them.

[AndyUM357]

Perhaps there is an issue with the ExecuteScript() call when executing some JS that returns nothing? I'm seeing the same "Failed to find value field" error with this call (Win10 X64 C# FF48.0.2):
iWebDriver.ExecuteScript("alert('Browser On Top');");

The node says this (notice the 500 Internal Error at 10:45:30.463):

10:45:30.362 INFO - Executing: [execute script: alert('Browser On Top');, []])
10:45:30.364 DEBUG - Executing: executeScript [a03ff577-1fe1-4f7b-805d-00267fbd0c4e, executeScript {script=alert('Browser On Top');, args=[]}]
10:45:30.366 DEBUG - CookieSpec selected: default
10:45:30.367 DEBUG - Auth cache not set in the context
10:45:30.368 DEBUG - Connection request: [route: {}->http://localhost:17228][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
10:45:30.369 DEBUG - Connection leased: [id: 4][route: {}->http://localhost:17228][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
10:45:30.371 DEBUG - Opening connection {}->http://localhost:17228
10:45:30.372 DEBUG - Connecting to localhost/127.0.0.1:17228
10:45:30.377 DEBUG - Connection established 127.0.0.1:52636<->127.0.0.1:17228
10:45:30.379 DEBUG - http-outgoing-4: set socket timeout to 10800000
10:45:30.380 DEBUG - Executing request POST /session/a03ff577-1fe1-4f7b-805d-00267fbd0c4e/execute/sync HTTP/1.1
10:45:30.381 DEBUG - Target auth state: UNCHALLENGED
10:45:30.382 DEBUG - Proxy auth state: UNCHALLENGED
10:45:30.383 DEBUG - http-outgoing-4 >> POST /session/a03ff577-1fe1-4f7b-805d-00267fbd0c4e/execute/sync HTTP/1.1
10:45:30.384 DEBUG - http-outgoing-4 >> Content-Type: application/json; charset=utf-8
10:45:30.387 DEBUG - http-outgoing-4 >> Content-Length: 47
10:45:30.388 DEBUG - http-outgoing-4 >> Host: localhost:17228
10:45:30.389 DEBUG - http-outgoing-4 >> Connection: Keep-Alive
10:45:30.390 DEBUG - http-outgoing-4 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_65)
10:45:30.392 DEBUG - http-outgoing-4 >> Accept-Encoding: gzip,deflate
10:45:30.394 DEBUG - http-outgoing-4 >> "POST /session/a03ff577-1fe1-4f7b-805d-00267fbd0c4e/execute/sync HTTP/1.1[\r][\n]"
10:45:30.396 DEBUG - http-outgoing-4 >> "Content-Type: application/json; charset=utf-8[\r][\n]"
10:45:30.397 DEBUG - http-outgoing-4 >> "Content-Length: 47[\r][\n]"
10:45:30.399 DEBUG - http-outgoing-4 >> "Host: localhost:17228[\r][\n]"
10:45:30.404 DEBUG - http-outgoing-4 >> "Connection: Keep-Alive[\r][\n]"
10:45:30.405 DEBUG - http-outgoing-4 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_65)[\r][\n]"
10:45:30.406 DEBUG - http-outgoing-4 >> "Accept-Encoding: gzip,deflate[\r][\n]"
10:45:30.407 DEBUG - http-outgoing-4 >> "[\r][\n]"
10:45:30.409 DEBUG - http-outgoing-4 >> "{"script":"alert('Browser On Top');","args":[]}"
1480347930417   Marionette      INFO    sendAsync a03ff577-1fe1-4f7b-805d-00267fbd0c4e
1480347930459   Marionette      INFO    sendAsync a03ff577-1fe1-4f7b-805d-00267fbd0c4e
10:45:30.463 DEBUG - http-outgoing-4 << "HTTP/1.1 500 Internal Server Error[\r][\n]"
10:45:30.464 DEBUG - http-outgoing-4 << "Date: Mon, 28 Nov 2016 15:45:30 GMT[\r][\n]"
10:45:30.467 DEBUG - http-outgoing-4 << "Content-Length: 64[\r][\n]"
10:45:30.468 DEBUG - http-outgoing-4 << "Content-Type: application/json[\r][\n]"
10:45:30.470 DEBUG - http-outgoing-4 << "Connection: close[\r][\n]"
10:45:30.473 DEBUG - http-outgoing-4 << "[\r][\n]"
10:45:30.473 DEBUG - http-outgoing-4 << "{"error":"unknown error","message":"Failed to find value field"}"
10:45:30.476 DEBUG - http-outgoing-4 << HTTP/1.1 500 Internal Server Error
10:45:30.476 DEBUG - http-outgoing-4 << Date: Mon, 28 Nov 2016 15:45:30 GMT
10:45:30.481 DEBUG - http-outgoing-4 << Content-Length: 64
10:45:30.482 DEBUG - http-outgoing-4 << Content-Type: application/json
10:45:30.483 DEBUG - http-outgoing-4 << Connection: close
10:45:30.485 DEBUG - http-outgoing-4: Close connection
10:45:30.486 DEBUG - Connection discarded
10:45:30.493 DEBUG - Connection released: [id: 4][route: {}->http://localhost:17228][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
10:45:30.496 DEBUG - Decoding response. Response code was: 500 and content: {"error":"unknown error","message":"Failed to find value field"}
10:45:30.503 DEBUG - Processing an error
10:45:30.534 DEBUG - Executed: [a03ff577-1fe1-4f7b-805d-00267fbd0c4e, executeScript {script=alert('Browser On Top');, args=[]}]
10:45:30.614 DEBUG - Win version: 0x3839000a = 943259658 (Windows Vista)
10:45:31.200 WARN - Exception thrown
org.openqa.selenium.WebDriverException: Failed to find value field
Build info: version: '3.0.1', revision: '1969d75', time: '2016-10-18 09:48:19 -0700'
System info: host: 'W10E-IE11-002-3', ip: '10.181.54.167', os.name: 'Windows 10', os.arch: 'amd64', os.version: '10.0', java.version: '1.8.0_65'
Driver info: org.openqa.selenium.firefox.FirefoxDriver

[AutomatedTester]

Firefox 48 is not supported, please use Firefox 50 or later

[AndyUM357]

I'm seeing the same 500 error above with FF 50.0.1 and geckodriver v0.11.1

16:19:37.469 INFO - Executing: [execute script: alert('Browser On Top');, []])
16:19:37.471 DEBUG - Executing: executeScript [6f488853-6840-47d9-a804-bb37a9f6250a, executeScript {script=alert('Browser On Top');, args=[]}]
16:19:37.476 DEBUG - CookieSpec selected: default
16:19:37.476 DEBUG - Auth cache not set in the context
16:19:37.477 DEBUG - Connection request: [route: {}->http://localhost:38106][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
16:19:37.478 DEBUG - Connection leased: [id: 4][route: {}->http://localhost:38106][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
16:19:37.480 DEBUG - Opening connection {}->http://localhost:38106
16:19:37.481 DEBUG - Connecting to localhost/127.0.0.1:38106
16:19:37.482 DEBUG - Connection established 127.0.0.1:53488<->127.0.0.1:38106
16:19:37.483 DEBUG - http-outgoing-4: set socket timeout to 10800000
16:19:37.483 DEBUG - Executing request POST /session/6f488853-6840-47d9-a804-bb37a9f6250a/execute/sync HTTP/1.1
16:19:37.485 DEBUG - Target auth state: UNCHALLENGED
16:19:37.486 DEBUG - Proxy auth state: UNCHALLENGED
16:19:37.487 DEBUG - http-outgoing-4 >> POST /session/6f488853-6840-47d9-a804-bb37a9f6250a/execute/sync HTTP/1.1
16:19:37.488 DEBUG - http-outgoing-4 >> Content-Type: application/json; charset=utf-8
16:19:37.489 DEBUG - http-outgoing-4 >> Content-Length: 47
16:19:37.489 DEBUG - http-outgoing-4 >> Host: localhost:38106
16:19:37.489 DEBUG - http-outgoing-4 >> Connection: Keep-Alive
16:19:37.490 DEBUG - http-outgoing-4 >> User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_65)
16:19:37.490 DEBUG - http-outgoing-4 >> Accept-Encoding: gzip,deflate
16:19:37.491 DEBUG - http-outgoing-4 >> "POST /session/6f488853-6840-47d9-a804-bb37a9f6250a/execute/sync HTTP/1.1[\r][\n]"
16:19:37.491 DEBUG - http-outgoing-4 >> "Content-Type: application/json; charset=utf-8[\r][\n]"
16:19:37.492 DEBUG - http-outgoing-4 >> "Content-Length: 47[\r][\n]"
16:19:37.492 DEBUG - http-outgoing-4 >> "Host: localhost:38106[\r][\n]"
16:19:37.493 DEBUG - http-outgoing-4 >> "Connection: Keep-Alive[\r][\n]"
16:19:37.493 DEBUG - http-outgoing-4 >> "User-Agent: Apache-HttpClient/4.5.2 (Java/1.8.0_65)[\r][\n]"
16:19:37.494 DEBUG - http-outgoing-4 >> "Accept-Encoding: gzip,deflate[\r][\n]"
16:19:37.494 DEBUG - http-outgoing-4 >> "[\r][\n]"
16:19:37.495 DEBUG - http-outgoing-4 >> "{"script":"alert('Browser On Top');","args":[]}"
16:19:37.570 DEBUG - http-outgoing-4 << "HTTP/1.1 500 Internal Server Error[\r][\n]"
16:19:37.572 DEBUG - http-outgoing-4 << "Connection: close[\r][\n]"
16:19:37.577 DEBUG - http-outgoing-4 << "Content-Length: 64[\r][\n]"
16:19:37.580 DEBUG - http-outgoing-4 << "Content-Type: application/json[\r][\n]"
16:19:37.581 DEBUG - http-outgoing-4 << "Date: Mon, 28 Nov 2016 21:19:37 GMT[\r][\n]"
16:19:37.582 DEBUG - http-outgoing-4 << "[\r][\n]"
16:19:37.583 DEBUG - http-outgoing-4 << "{"error":"unknown error","message":"Failed to find value field"}"
16:19:37.585 DEBUG - http-outgoing-4 << HTTP/1.1 500 Internal Server Error
16:19:37.586 DEBUG - http-outgoing-4 << Connection: close
16:19:37.587 DEBUG - http-outgoing-4 << Content-Length: 64
16:19:37.588 DEBUG - http-outgoing-4 << Content-Type: application/json
16:19:37.589 DEBUG - http-outgoing-4 << Date: Mon, 28 Nov 2016 21:19:37 GMT
16:19:37.591 DEBUG - http-outgoing-4: Close connection
16:19:37.592 DEBUG - Connection discarded
16:19:37.593 DEBUG - Connection released: [id: 4][route: {}->http://localhost:38106][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
16:19:37.595 DEBUG - Decoding response. Response code was: 500 and content: {"error":"unknown error","message":"Failed to find value field"}
16:19:37.595 DEBUG - Processing an error
16:19:37.628 DEBUG - Executed: [6f488853-6840-47d9-a804-bb37a9f6250a, executeScript {script=alert('Browser On Top');, args=[]}]
16:19:37.699 DEBUG - Win version: 0x3839000a = 943259658 (Windows Vista)
16:19:37.982 WARN - Exception thrown
org.openqa.selenium.WebDriverException: Failed to find value field
Build info: version: '3.0.1', revision: '1969d75', time: '2016-10-18 09:48:19 -0700'
System info: host: 'W10E-IE11-001-3', ip: '10.181.54.148', os.name: 'Windows 10', os.arch: 'amd64', os.version: '10.0', java.version: '1.8.0_65'
Driver info: org.openqa.selenium.firefox.FirefoxDriver
Capabilities [{nodeName=W10E-IE11-001-3, rotatable=false, raisesAccessibilityExceptions=false, firefoxOptions={args=[], profile=UEsDBBQACAgIAHCCfEkAAAAAAAAAAAAAAAAHAAAAdXNlci5qc51WTW/bMAy971cMOW3AKqTretlOXdcBA4Z1aFDsKMgSbauRJU0fcfPvR/mjSRNHbndKbJMS+fj4yOjBUeugfLconGnxiXhWQvdf6oo0TLXMAQHNCgVi8eFtyZSH91/exJ2nYAFtrHEhudTAVKj7Z4JGG8ln/DWE1rg1qUOwxNbS19uz9Nky788U6CrU6Pjx8vK52xiwAybwR0AAHkB8l86HK4yFK0C34OJhuKbBvB4pr51pgHrupA3URU2DbJLLxXL6osAKTxAOfauvlfEwnc1oLUyrlWEC79KsSsDWpv1Tg14hWgmpaXeLQdng02W0MYKpGexhE4xRnoBzxnGjvVH7cB+n72WljUbUGmgKcKvu0edz8eC9RKtgkAsOfETcSgyUcsd8nfdVUq+JsaApPAZwmqlUzFczqExlvYt6+rIWCuHkBp8Z54DljBoz90gHysEFP4nEU6Wkt4ptQdycL1e/DDInlfbTtDG+Erf6j9RYX3++JBIvMvd3P9FjwQoTw+dCMb1eHHOuT4gypeiDRzBSnLKH/ji2RysRbrQlbS0DKOkDHvA3SneKCYkGaxnI0E0j6zC5xIUsAIphYbAB8lTzibfRkhq7xuLZtAXFUwdFl0q6OEg5VVt3rCHRYoGBaIS23N6jyat1JNrUSjfZ8IBHJ8MWmaIA/xEfnOSBGicrqak1SvJtnqoaWmw7MuSTqeazQPuTSXq5ikUju1b53b286sj4Mt2cPCab8VN3DoVJRUHLE+q160NMs+34e9yIpizRDs6YtZ4g+0xLiy0VULKowrScjLBzbwf+TEd7zIcs20Y6I/dRqYLbkl4ZO/uPc7bZo0dEbu5/XpELwnZFOk7vgW1YPyGyonpYirFH8jw6jtvBQzfEspf0NE3H5/PcQ5zFYL71SrDiSIIkOufLUxran0o1C/hIYQN6RkH3JuMtMmw2nEIZvu407UWF8sAcrwfazE3dhvTkJiI2Nls0JPmLqPiMLwYBclJMC+qRBh2Kz8X05tOL9dnYfciiEGdG8mB7QlmGFWd+t9kbnL4b67vBiQoUO6nOIpeYNR3EXuuYftJ1K9APfd1vKSeXs2Fk0U6sBMKoK5rkf4YkNeC05DXw9bder772X14/zQgTQqaI2cwgmNyZ/3dXVqaq0sthictK/14vdRlfozRitxZSJfZpWdVBnRh2e67jjf+jbHRsBNLgWtgRcZFWSQcHGO02mbR5IrFxf5xZZXZ9r0ofbb8B7JaMf1BLBwh1hce1pQMAALUMAABQSwECFAAUAAgICABwgnxJdYXHtaUDAAC1DAAABwAAAAAAAAAAAAAAAAAAAAAAdXNlci5qc1BLBQYAAAAAAQABADUAAADaAwAAAAA=}, appBuildId=20161123182536, version=, platform=XP, proxy={}, command_id=1, specificationLevel=0, acceptSslCerts=false, processId=5064, browserVersion=50.0.1, platformVersion=10.0, XULappId={ec8030f7-c20a-464f-9b0e-13a3a9e97384}, browserName=firefox, takesScreenshot=true, takesElementScreenshot=true, platformName=windows_nt}]
Session ID: 6f488853-6840-47d9-a804-bb37a9f6250a
        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:127)
        at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:93)
        at org.openqa.selenium.remote.http.W3CHttpResponseCodec.decode(W3CHttpResponseCodec.java:42)

[biddles]

Hi @AutomatedTester ,
I try my code on FF50.01, the same code failed and get more error message like below. And some times I can see there is a popmessage at the top of the page about "A web page is slowing down your browser. What wourld you link to do?"
Please help to review. If you think it belong to client bindings defaulting.
Please show me correct issue path where I sould open.

Thanks,

[Exception] Program - Detail: at OpenQA.Selenium.Remote.HttpCommandExecutor.CreateResponse(WebRequest request)
at OpenQA.Selenium.Remote.HttpCommandExecutor.Execute(Command commandToExecute)
at OpenQA.Selenium.Remote.DriverServiceCommandExecutor.Execute(Command commandToExecute)
at OpenQA.Selenium.Remote.RemoteWebDriver.Execute(String driverCommandToExecute, Dictionary`2 parameters)
at OpenQA.Selenium.Remote.RemoteWebDriver.ExecuteScriptCommand(String script, String commandName, Object[] args)
at OpenQA.Selenium.Remote.RemoteWebDriver.ExecuteScript(String script, Object[] args)

[lock]

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.