Comment #58 on issue 3719 by
k.kope...@gmail.com:
hi, this is crazy.
I put timestamp loging in to my code.
Times in my log not equals with times in chromedriver.log (I convert times
in chromedriver.log from relative times to absolute times)
Different times of call Title method:
By my code at 16.06.2014 00:22:35,030
by chormedriver at 16.06.2014 00:24:40,549
And
Why I dont get exception in navigate method? duration is 3 minutes, by
chromedriver.log
CODE:
private static void TryGoToUrl(IWebDriver driver, string url)
{
Trace trace = new Trace(); // Start trace
try
{
trace.Append("Navigate");
driver.Navigate().GoToUrl(url);
trace.Append("Title");
string title = driver.Title;
trace.Append("Check results");
// TODO
}
catch (Exception ex)
{
trace.Append("End trace");
throw new Exception(String.Format("Exception when TryGoToUrl
(params - url: {0}) {1}", url, trace.ToString()), ex);
}
}
EXCEPTION:
System.Exception: Fast refresh XXX - 187,125 secs --->
XXX.Module.ModuleException: FastRefresh --->
System.Exception: Exception when TryGoToUrl (params - url:
http://www.XXX.com/live/en)
16.06.2014 00:21:35,001 - Start trace
16.06.2014 00:21:35,001 - Navigate
16.06.2014 00:22:35,030 - Title
16.06.2014 00:23:35,048 - End trace
--->
OpenQA.Selenium.WebDriverException: The HTTP request to the remote
WebDriver server for URL
http://localhost:2186/session/736835670a5852c26cce654834cbcb18/title timed
out after 60 seconds. --->
System.Net.WebException: The operation has timed out
at System.Net.HttpWebRequest.GetResponse()
at OpenQA.Selenium.Remote.HttpCommandExecutor.CreateResponse(WebRequest
request)
--- End of inner exception stack trace ---
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.get_Title()
at XXX.Common.IWebDriverExtensions.TryGoToUrl(IWebDriver driver, String
url, Int32 attempt)
CHROMEDRIVER LOG:
[16.06.2014 00:21:35,003][INFO]: COMMAND Navigate {
"url": "
http://www.betvictor.com/live/en"
}
[16.06.2014 00:21:35,003][INFO]: Waiting for pending navigations...
[16.06.2014 00:21:35,003][INFO]: Done waiting for pending navigations
[16.06.2014 00:21:35,003][DEBUG]: DEVTOOLS COMMAND Page.navigate (id=7371) {
"url": "
http://www.betvictor.com/live/en"
}
[16.06.2014 00:21:35,005][DEBUG]: DEVTOOLS RESPONSE Page.navigate (id=7371)
{
}
[16.06.2014 00:21:35,005][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate
(id=7372) {
"expression": "document.URL"
}
[16.06.2014 00:21:35,126][DEBUG]: DEVTOOLS EVENT Console.messageAdded {
"message": {
"column": 10991,
"level": "log",
"line": 13,
"parameters": [ {
"className": "Object",
"description": "Object",
"objectId": "{\"injectedScriptId\":170,\"id\":1}",
"preview": {
"lossless": false,
"overflow": true,
"properties": [ {
"name": "readyState",
"type": "number",
"value": "0"
}, {
"name": "getResponseHeader",
"type": "function",
"value": ""
}, {
"name": "getAllResponseHeaders",
"type": "function",
"value": ""
}, {
"name": "setRequestHeader",
"type": "function",
"value": ""
}, {
"name": "overrideMimeType",
"type": "function",
"value": ""
} ]
},
"type": "object"
} ],
"repeatCount": 1,
"source": "console-api",
"stackTrace": [ {
"columnNumber": 10991,
"functionName": "",
"lineNumber": 13,
"scriptId": "24391",
"url": "
http://www.gaming-assets.com/assets/manifests/live-0253aae285d4fd8096cd6f392a981c6d.js"
}, {
"columnNumber": 29270,
"functionName": "fire",
"lineNumber": 2,
"scriptId": "24390",
"url": "
http://www.gaming-assets.com/assets/manifests/all-8c93384329d74eb6e76fd207cffd3cfe.js"
}, {
"columnNumber": 30477,
"functionName": "self.fireWith",
"lineNumber": 2,
"scriptId": "24390",
"url": "
http://www.gaming-assets.com/assets/manifests/all-8c93384329d74eb6e76fd207cffd3cfe.js"
}, {
"columnNumber": 31209,
"functionName": "done",
"lineNumber": 4,
"scriptId": "24390",
"url": "
http://www.gaming-assets.com/assets/manifests/all-8c93384329d74eb6e76fd207cffd3cfe.js"
}, {
"columnNumber": 7428,
"functionName": "callback",
"lineNumber": 5,
"scriptId": "24390",
"url": "
http://www.gaming-assets.com/assets/manifests/all-8c93384329d74eb6e76fd207cffd3cfe.js"
} ],
"text": "[object Object]",
"timestamp": 1402870895.223125,
"type": "log",
"url": "
http://www.gaming-assets.com/assets/manifests/live-0253aae285d4fd8096cd6f392a981c6d.js"
}
}
[16.06.2014 00:21:35,127][DEBUG]: DEVTOOLS EVENT Page.frameStartedLoading {
"frameId": "3860.1"
}
[16.06.2014 00:21:35,127][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate
(id=7372) {
"result": {
"type": "string",
"value": "
http://www.betvictor.com/live/en#485636200_argentina_v_bosnia_and_herzegovina"
},
"wasThrown": false
}
[16.06.2014 00:21:35,127][INFO]: Waiting for pending navigations...
[16.06.2014 00:24:32,990][DEBUG]: DEVTOOLS EVENT Console.messagesCleared {
}
[16.06.2014 00:24:32,990][DEBUG]: DEVTOOLS EVENT Page.frameNavigated {
"frame": {
"id": "3860.1",
"loaderId": "3860.172",
"mimeType": "text/html",
"securityOrigin": "
http://www.betvictor.com",
"url": "
http://www.betvictor.com/live/en"
}
}
[16.06.2014 00:24:32,991][DEBUG]: DEVTOOLS EVENT
Runtime.executionContextCreated {
"context": {
"frameId": "3860.1",
"id": 171,
"isPageContext": true,
"name": ""
}
}
[16.06.2014 00:24:33,019][DEBUG]: DEVTOOLS EVENT
Page.frameScheduledNavigation {
"delay": 0,
"frameId": "3860.1"
}
[16.06.2014 00:24:33,019][DEBUG]: DEVTOOLS EVENT Page.loadEventFired {
"timestamp": 1402871073.109
}
[16.06.2014 00:24:33,019][DEBUG]: DEVTOOLS EVENT DOM.documentUpdated {
}
[16.06.2014 00:24:33,019][DEBUG]: DEVTOOLS COMMAND DOM.getDocument
(id=7373) {
}
[16.06.2014 00:24:33,019][DEBUG]: DEVTOOLS EVENT Page.domContentEventFired {
"timestamp": 1402871073.109
}
[16.06.2014 00:24:33,025][DEBUG]: DEVTOOLS EVENT Page.frameStoppedLoading {
"frameId": "3860.1"
}
[16.06.2014 00:24:33,029][DEBUG]: DEVTOOLS EVENT Page.frameStartedLoading {
"frameId": "3860.1"
}
[16.06.2014 00:24:33,030][DEBUG]: DEVTOOLS EVENT
Page.frameClearedScheduledNavigation {
"frameId": "3860.1"
}
[16.06.2014 00:24:33,048][DEBUG]: DEVTOOLS RESPONSE DOM.getDocument
(id=7373) {
"root": {
"baseURL": "
http://www.betvictor.com/live/en",
"childNodeCount": 1,
"children": [ {
"attributes": [ ],
"childNodeCount": 2,
"children": [ {
"attributes": [ ],
"childNodeCount": 5,
"localName": "head",
"nodeId": 841,
"nodeName": "HEAD",
"nodeType": 1,
"nodeValue": ""
}, {
"attributes": [ "onload", "test()" ],
"childNodeCount": 1,
"localName": "body",
"nodeId": 842,
"nodeName": "BODY",
"nodeType": 1,
"nodeValue": ""
} ],
"localName": "html",
"nodeId": 840,
"nodeName": "HTML",
"nodeType": 1,
"nodeValue": ""
} ],
"documentURL": "
http://www.betvictor.com/live/en",
"localName": "",
"nodeId": 839,
"nodeName": "#document",
"nodeType": 9,
"nodeValue": "",
"xmlVersion": ""
}
}
[16.06.2014 00:24:33,112][DEBUG]: DEVTOOLS EVENT Console.messagesCleared {
}
[16.06.2014 00:24:33,112][DEBUG]: DEVTOOLS EVENT Page.frameNavigated {
"frame": {
"id": "3860.1",
"loaderId": "3860.173",
"mimeType": "text/html",
"securityOrigin": "
http://www.betvictor.com",
"url": "
http://www.betvictor.com/live/en"
}
}
[16.06.2014 00:24:33,112][DEBUG]: DEVTOOLS EVENT
Runtime.executionContextCreated {
"context": {
"frameId": "3860.1",
"id": 172,
"isPageContext": true,
"name": ""
}
}
[16.06.2014 00:24:33,361][DEBUG]: DEVTOOLS EVENT Console.messageAdded {
"message": {
"column": 0,
"level": "error",
"line": 0,
"networkRequestId": "3860.21173",
"repeatCount": 1,
"source": "network",
"text": "Failed to load resource: the server responded with a status
of 404 (Not Found)",
"timestamp": 1402871073.47,
"type": "log",
"url": "
http://www.gaming-assets.com/images/original/missing.png"
}
}
[16.06.2014 00:24:36,142][DEBUG]: DEVTOOLS EVENT DOM.documentUpdated {
}
[16.06.2014 00:24:36,143][DEBUG]: DEVTOOLS COMMAND DOM.getDocument
(id=7374) {
}
[16.06.2014 00:24:36,143][DEBUG]: DEVTOOLS EVENT Page.domContentEventFired {
"timestamp": 1402871076.245
}
[16.06.2014 00:24:36,230][DEBUG]: DEVTOOLS EVENT Console.messageAdded {
"message": {
"column": 0,
"level": "error",
"line": 0,
"networkRequestId": "3860.21189",
"repeatCount": 1,
"source": "network",
"text": "Failed to load resource: the server responded with a status
of 404 (Not Found)",
"timestamp": 1402871076.309,
"type": "log",
"url": "
http://www.gaming-assets.com/images/original/missing.png"
}
}
[16.06.2014 00:24:36,230][DEBUG]: DEVTOOLS EVENT Console.messageAdded {
"message": {
"column": 0,
"level": "error",
"line": 0,
"networkRequestId": "3860.21191",
"repeatCount": 1,
"source": "network",
"text": "Failed to load resource: the server responded with a status
of 404 (Not Found)",
"timestamp": 1402871076.315,
"type": "log",
"url": "
http://www.gaming-assets.com/attachments/original/missing.png"
}
}
[16.06.2014 00:24:39,611][DEBUG]: DEVTOOLS RESPONSE DOM.getDocument
(id=7374) {
"root": {
"baseURL": "
http://www.betvictor.com/live/en",
"childNodeCount": 2,
"children": [ {
"internalSubset": "",
"localName": "",
"nodeId": 844,
"nodeName": "html",
"nodeType": 10,
"nodeValue": "",
"publicId": "",
"systemId": ""
}, {
"attributes":
[ "lang", "en", "ng-app", "Zaynar", "class", "ng-scope" ],
"childNodeCount": 2,
"children": [ {
"attributes": [ ],
"childNodeCount": 22,
"localName": "head",
"nodeId": 846,
"nodeName": "HEAD",
"nodeType": 1,
"nodeValue": ""
}, {
"attributes":
[ "class", " ", "data-allow-utf8", "false", "data-lang", "en-gb", "data-pop-in-upgrade-browser", "false", "data-site", "live", "ontouchmove", "BlockMove(event)", "style", ""
],
"childNodeCount": 8,
"localName": "body",
"nodeId": 847,
"nodeName": "BODY",
"nodeType": 1,
"nodeValue": ""
} ],
"localName": "html",
"nodeId": 845,
"nodeName": "HTML",
"nodeType": 1,
"nodeValue": ""
} ],
"documentURL": "
http://www.betvictor.com/live/en#485636200_argentina_v_bosnia_and_herzegovina",
"localName": "",
"nodeId": 843,
"nodeName": "#document",
"nodeType": 9,
"nodeValue": "",
"xmlVersion": ""
}
}
[16.06.2014 00:24:39,927][DEBUG]: DEVTOOLS EVENT DOM.childNodeCountUpdated {
"childNodeCount": 9,
"nodeId": 847
}
[16.06.2014 00:24:39,928][DEBUG]: DEVTOOLS EVENT DOM.childNodeCountUpdated {
"childNodeCount": 10,
"nodeId": 847
}
[16.06.2014 00:24:39,951][DEBUG]: DEVTOOLS EVENT DOM.childNodeCountUpdated {
"childNodeCount": 11,
"nodeId": 847
}
[16.06.2014 00:24:40,539][DEBUG]: DEVTOOLS EVENT Page.loadEventFired {
"timestamp": 1402871080.633
}
[16.06.2014 00:24:40,549][DEBUG]: DEVTOOLS EVENT Page.frameStoppedLoading {
"frameId": "3860.1"
}
[16.06.2014 00:24:40,549][INFO]: Done waiting for pending navigations
[16.06.2014 00:24:40,549][INFO]: RESPONSE Navigate
[16.06.2014 00:24:40,549][INFO]: COMMAND GetTitle {
}
[16.06.2014 00:24:40,549][INFO]: Waiting for pending navigations...
[16.06.2014 00:24:40,549][INFO]: Done waiting for pending navigations
[16.06.2014 00:24:40,550][DEBUG]: DEVTOOLS COMMAND Runtime.evaluate
(id=7375) {
"expression": "(function() { // Copyright (c) 2012 The Chromium Authors.
All rights reserved.\n// Use of this source code is governed by a BSD-style
license that can be\n// found in the LICENSE file.\n\n/**\n * Enum f...",
"returnByValue": true
}
[16.06.2014 00:24:40,632][DEBUG]: DEVTOOLS RESPONSE Runtime.evaluate
(id=7375) {
"result": {
"type": "object",
"value": {
"status": 0,
"value": "Live In-Play Sports Betting - BetVictor"
}
},
"wasThrown": false
}
[16.06.2014 00:24:40,632][INFO]: Waiting for pending navigations...
[16.06.2014 00:24:40,632][INFO]: Done waiting for pending navigations
[16.06.2014 00:24:40,632][INFO]: RESPONSE GetTitle "Live In-Play Sports
Betting - BetVictor"