Selenium: v3.12.0: visit grid console will see"DefaultRemoteProxy unknown version,Failed to connect to ****"

Created on 28 May 2018  路  30Comments  路  Source: SeleniumHQ/selenium

Meta -

OS: Win7

Selenium Version: V3.12.0

Browser:

Browser Version:

Expected Behavior - monitor the Grid via ip(hub): 4444/grid/console, will see the node status list quickly, actually, from V3.9.1 to V3.11.0 really work.

Actual Behavior - show the node status list very slowly and in the top of each node unit will show a message "DefaultRemoteProxy unknown version,Failed to connect to node/...**:5555

Steps to reproduce -


1 start hub by run bat
TITLE SELENIUM_HUB
set SERVER_PORT=4444
set JAR_NAME=selenium-server-standalone-3.12.0.jar
java -jar %JAR_NAME% -port %SERVER_PORT% -role hub -timeout 600 -browserTimeout 3600
2 start one node by run bat(even though change the NODE_HOSTNAME from host name to host ip, still saw the same problem)
TITLE SELENIUM_NODE

set HUB_NAME= ...
set NODE_HOSTNAME=*
set HUB_PORT=4444
set NODE_PORT=5555
set DRIVER_PATH_IE=C:\SeleniumGrid\IEDriverServer.exe
set NODE_CHROME_EXE_PATH=C:/Program Files (x86)/Google/Chrome/Application/chrome.exe
set DRIVER_PATH_CHROME=C:\SeleniumGrid\chromedriver.exe
set DRIVER_PATH_FIREFOX=C:\SeleniumGrid\geckodriver.exe
set JAR_NAME=selenium-server-standalone-3.12.0.jar
set MAX_INSTANCES=3
set MAX_SESSION=3

java -Dwebdriver.chrome.driver=%DRIVER_PATH_CHROME% -Dwebdriver.ie.driver=%DRIVER_PATH_IE% -Dwebdriver.gecko.driver=%DRIVER_PATH_FIREFOX% -jar %JAR_NAME% -maxSession %MAX_SESSION% -role node -browser "browserName=internet explorer,maxInstances=%MAX_INSTANCES%,platform=WINDOWS" -browser "browserName=chrome,maxInstances=%MAX_INSTANCES%,chrome_binary=%NODE_CHROME_EXE_PATH%,platform=WINDOWS" -browser "browserName=firefox,maxInstances=%MAX_INSTANCES%,platform=WINDOWS" -port %NODE_PORT% -host %NODE_HOSTNAME% -hub http://%HUB_NAME%:%HUB_PORT%/grid/register

C-grid
Source
picture oceanchow
👍1

All 30 comments

sc
screenshot for the problem

oceanchow picture oceanchow on 28 May 2018

Hosts that run nodes are not available from the host that runs the hub.
It's a network misconfiguration, not a Selenium issue.

barancev picture barancev on 3 Jun 2018

@barancev As you can see my description, same configuration work from V3.9.1 to V3.11.0, why only V3.12.0 show error?

oceanchow picture oceanchow on 4 Jun 2018

Please run hub with -debug option, attach a node to this hub, and provide the hub log for investigation.
Do the same for a version that works (e.g. 3.11) so we can compare the logs.

barancev picture barancev on 4 Jun 2018

@barancev sure, will do it later. thanks for your help.

oceanchow picture oceanchow on 4 Jun 2018

I have seen the exactly same issue: providing logs from hub side, with -debug option

liulirun picture liulirun on 7 Jun 2018

with v3.12

C:\Selenium>java -jar selenium-server-standalone-3.12.0.jar -role hub -debug 

14:30:39.489 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.12.
0', revision: '7c6e0b3'
14:30:39.492 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on por
t 4444
2018-06-07 14:30:39.906:INFO::main: Logging initialized @849ms to org.seleniumhq
.jetty9.util.log.StdErrLog
14:30:40.131 INFO [Hub.start] - Selenium Grid hub is up and running
14:30:40.132 INFO [Hub.start] - Nodes should register to http://172.24.95.35:444
4/grid/register/
14:30:40.133 INFO [Hub.start] - Clients should connect to http://172.24.95.35:44
44/wd/hub
14:31:20.307 DEBUG [RegistrationServlet.process] - getting the following registr
ation request  : {"class":{"enclosingConstructor":null,"annotations":[],"memberC
lass":false,"declaredConstructors":[null,null,null,null],"declaredFields":[null,
null,null,null,null,null,null],"superclass":{"enclosingConstructor":null,"annota
tions":[],"memberClass":false,"declaredConstructors":[null],"declaredFields":[],
"superclass":null,"canonicalName":"java.lang.Object","package":null,"protectionD
omain":null,"enclosingMethod":null,"enum":false,"declaringClass":null,"construct
ors":[null],"synthetic":false,"declaredClasses":[],"name":"java.lang.Object","fi
elds":[],"classLoader":null,"primitive":false,"methods":[null,null,null,null,nul
l,null,null,null,null],"classes":[],"typeName":"java.lang.Object","declaredMetho
ds":[null,null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,
"interface":false,"genericInterfaces":[],"annotatedSuperclass":null,"typeParamet
ers":[],"array":false,"enumConstants":null,"annotatedInterfaces":[],"class":"jav
a.lang.Class","annotation":false,"componentType":null,"declaredAnnotations":[],"
interfaces":[],"genericSuperclass":null,"localClass":false,"enclosingClass":null
,"signers":null,"simpleName":"Object","anonymousClass":false},"canonicalName":"o
rg.openqa.grid.common.RegistrationRequest","package":{"specificationVendor":"Ora
cle Corporation","declaredAnnotations":[],"implementationVersion":"9.4.7.v201709
14","sealed":false,"annotations":[],"implementationTitle":"HttpComponents Apache
 HttpClient Mime","hCode":-250690871,"packages":[null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null],"specificationTitle":"HttpComp
onents Apache HttpClient Mime","name":"org.openqa.grid.common","implementationVe
ndor":"Eclipse.org - Jetty","class":"java.lang.Package","specificationVersion":"
3.1"},"protectionDomain":{"classLoader":null,"permissions":null,"principals":[],
"codeSource":null,"class":"java.security.ProtectionDomain"},"enclosingMethod":nu
ll,"enum":false,"declaringClass":null,"constructors":[null,null,null,null],"synt
hetic":false,"declaredClasses":[],"name":"org.openqa.grid.common.RegistrationReq
uest","fields":[null,null,null],"classLoader":{"parent":null,"systemClassLoader"
:null,"uRLs":["file:/C:/Selenium/selenium-server-standalone-3.12.0.jar"],"class"
:"sun.misc.Launcher$AppClassLoader"},"primitive":false,"methods":[null,null,null
,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null
],"classes":[],"typeName":"org.openqa.grid.common.RegistrationRequest","declared
Methods":[null,null,null,null,null,null,null,null,null,null],"modifiers":1,"inte
rface":false,"genericInterfaces":[],"annotatedSuperclass":{"declaredAnnotations"
:[],"annotations":[],"type":null,"class":"sun.reflect.annotation.AnnotatedTypeFa
ctory$AnnotatedTypeBaseImpl"},"typeParameters":[],"array":false,"enumConstants":
null,"annotatedInterfaces":[],"class":"java.lang.Class","annotation":false,"comp
onentType":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":{"e
nclosingConstructor":null,"annotations":[],"memberClass":false,"declaredConstruc
tors":[null],"declaredFields":[],"superclass":null,"canonicalName":"java.lang.Ob
ject","package":null,"protectionDomain":null,"enclosingMethod":null,"enum":false
,"declaringClass":null,"constructors":[null],"synthetic":false,"declaredClasses"
:[],"name":"java.lang.Object","fields":[],"classLoader":null,"primitive":false,"
methods":[null,null,null,null,null,null,null,null,null],"classes":[],"typeName":
"java.lang.Object","declaredMethods":[null,null,null,null,null,null,null,null,nu
ll,null,null,null],"modifiers":1,"interface":false,"genericInterfaces":[],"annot
atedSuperclass":null,"typeParameters":[],"array":false,"enumConstants":null,"ann
otatedInterfaces":[],"class":"java.lang.Class","annotation":false,"componentType
":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":null,"localC
lass":false,"enclosingClass":null,"signers":null,"simpleName":"Object","anonymou
sClass":false},"localClass":false,"enclosingClass":null,"signers":null,"simpleNa
me":"RegistrationRequest","anonymousClass":false},"configuration":{"unregisterIf
StillDownAfter":60000,"role":"node","debug":false,"capabilities":[{"browserName"
:"chrome","maxInstances":5,"platform":"WIN8_1","platformName":"WIN8_1","selenium
Protocol":"WebDriver","server:CONFIG_UUID":"f45234a5-19cb-4605-a74a-0b9d922f8c00
"}],"remoteHost":"http://172.24.95.36:5555","custom":{},"nodeStatusCheckTimeout"
:5000,"downPollingLimit":2,"timeout":1800,"nodePolling":2000,"proxy":"org.openqa
.grid.selenium.proxy.DefaultRemoteProxy","cleanUpCycle":2000,"hub":"http://172.2
4.95.35:4444/grid/register","port":19810,"browserTimeout":0,"host":"172.24.95.36
","servlets":[],"enablePlatformVerification":true,"id":"http://172.24.95.36:5555
","withoutServlets":[],"maxSession":5,"registerCycle":10000,"register":true},"de
scription":null,"name":null}
14:31:40.828 DEBUG [BaseRemoteProxy.getNewInstance] - Using class org.openqa.gri
d.selenium.proxy.DefaultRemoteProxy
14:31:40.836 DEBUG [BaseRemoteProxy.setupTimeoutListener] - starting cleanup thr
ead
14:31:40.837 DEBUG [BaseRemoteProxy$CleanUpThread.run] - cleanup thread starting
...
14:31:40.840 INFO [DefaultGridRegistry.add] - Registered a node http://172.24.95
.36:5555
14:31:40.842 DEBUG [RegistrationServlet.lambda$process$0] - proxy added http://1
72.24.95.36:5555
14:31:44.072 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node
: Failed to connect to /172.24.95.36:5555
14:31:47.086 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node
: Failed to connect to /172.24.95.36:5555
14:31:47.088 INFO [DefaultRemoteProxy.onEvent] - Marking the node http://172.24.
95.36:5555 as down: cannot reach the node for 2 tries
14:31:50.094 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node
: Failed to connect to /172.24.95.36:5555
liulirun picture liulirun on 7 Jun 2018

with v3.11

C:\Selenium>java -jar selenium-server-standalone-3.12.0.jar -role hub -debug

14:33:41.940 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.12.
0', revision: '7c6e0b3'
14:33:41.945 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on por
t 4444
2018-06-07 14:33:42.322:INFO::main: Logging initialized @836ms to org.seleniumhq
.jetty9.util.log.StdErrLog
14:33:42.535 INFO [Hub.start] - Selenium Grid hub is up and running
14:33:42.535 INFO [Hub.start] - Nodes should register to http://172.24.95.35:444
4/grid/register/
14:33:42.535 INFO [Hub.start] - Clients should connect to http://172.24.95.35:44
44/wd/hub
14:33:54.753 DEBUG [RegistrationServlet.process] - getting the following registr
ation request  : {"class":{"enclosingConstructor":null,"annotations":[],"memberC
lass":false,"declaredConstructors":[null,null,null,null],"declaredFields":[null,
null,null,null,null,null,null],"superclass":{"enclosingConstructor":null,"annota
tions":[],"memberClass":false,"declaredConstructors":[null],"declaredFields":[],
"superclass":null,"canonicalName":"java.lang.Object","package":null,"protectionD
omain":null,"enclosingMethod":null,"enum":false,"declaringClass":null,"construct
ors":[null],"synthetic":false,"declaredClasses":[],"name":"java.lang.Object","fi
elds":[],"classLoader":null,"primitive":false,"methods":[null,null,null,null,nul
l,null,null,null,null],"classes":[],"typeName":"java.lang.Object","declaredMetho
ds":[null,null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,
"interface":false,"genericInterfaces":[],"annotatedSuperclass":null,"typeParamet
ers":[],"array":false,"enumConstants":null,"annotatedInterfaces":[],"class":"jav
a.lang.Class","annotation":false,"componentType":null,"declaredAnnotations":[],"
interfaces":[],"genericSuperclass":null,"localClass":false,"enclosingClass":null
,"signers":null,"simpleName":"Object","anonymousClass":false},"canonicalName":"o
rg.openqa.grid.common.RegistrationRequest","package":{"specificationVendor":"Ora
cle Corporation","declaredAnnotations":[],"implementationVersion":"9.4.7.v201709
14","sealed":false,"annotations":[],"implementationTitle":"HttpComponents Apache
 HttpClient Mime","hCode":-250690871,"packages":[null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null],"specificationTitle":"HttpComponent
s Apache HttpClient Mime","name":"org.openqa.grid.common","implementationVendor"
:"Eclipse.org - Jetty","class":"java.lang.Package","specificationVersion":"3.1"}
,"protectionDomain":{"classLoader":null,"permissions":null,"principals":[],"code
Source":null,"class":"java.security.ProtectionDomain"},"enclosingMethod":null,"e
num":false,"declaringClass":null,"constructors":[null,null,null,null],"synthetic
":false,"declaredClasses":[],"name":"org.openqa.grid.common.RegistrationRequest"
,"fields":[null,null,null],"classLoader":{"parent":null,"systemClassLoader":null
,"uRLs":["file:/C:/Selenium/selenium-server-standalone-3.11.0.jar"],"class":"sun
.misc.Launcher$AppClassLoader"},"primitive":false,"methods":[null,null,null,null
,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null
],"classes":[],"typeName":"org.openqa.grid.common.RegistrationRequest","declared
Methods":[null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,
"interface":false,"genericInterfaces":[],"annotatedSuperclass":{"declaredAnnotat
ions":[],"annotations":[],"type":null,"class":"sun.reflect.annotation.AnnotatedT
ypeFactory$AnnotatedTypeBaseImpl"},"typeParameters":[],"array":false,"enumConsta
nts":null,"annotatedInterfaces":[],"class":"java.lang.Class","annotation":false,
"componentType":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass
":{"enclosingConstructor":null,"annotations":[],"memberClass":false,"declaredCon
structors":[null],"declaredFields":[],"superclass":null,"canonicalName":"java.la
ng.Object","package":null,"protectionDomain":null,"enclosingMethod":null,"enum":
false,"declaringClass":null,"constructors":[null],"synthetic":false,"declaredCla
sses":[],"name":"java.lang.Object","fields":[],"classLoader":null,"primitive":fa
lse,"methods":[null,null,null,null,null,null,null,null,null],"classes":[],"typeN
ame":"java.lang.Object","declaredMethods":[null,null,null,null,null,null,null,nu
ll,null,null,null,null],"modifiers":1,"interface":false,"genericInterfaces":[],"
annotatedSuperclass":null,"typeParameters":[],"array":false,"enumConstants":null
,"annotatedInterfaces":[],"class":"java.lang.Class","annotation":false,"componen
tType":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":null,"l
ocalClass":false,"enclosingClass":null,"signers":null,"simpleName":"Object","ano
nymousClass":false},"localClass":false,"enclosingClass":null,"signers":null,"sim
pleName":"RegistrationRequest","anonymousClass":false},"configuration":{"remoteH
ost":"http://172.24.95.36:5555","id":"http://172.24.95.36:5555","capabilities":[
{"browserName":"chrome","maxInstances":5,"platform":"WIN8_1","platformName":"WIN
8_1","seleniumProtocol":"WebDriver","server:CONFIG_UUID":"38e19500-492d-4465-87b
f-68881b68f2aa"}],"downPollingLimit":2,"hub":"http://172.24.95.35:4444/grid/regi
ster","nodePolling":2000,"nodeStatusCheckTimeout":5000,"proxy":"org.openqa.grid.
selenium.proxy.DefaultRemoteProxy","register":true,"registerCycle":10000,"unregi
sterIfStillDownAfter":60000,"enablePlatformVerification":true,"cleanUpCycle":200
0,"custom":{},"host":"172.24.95.36","maxSession":5,"servlets":[],"withoutServlet
s":[],"browserTimeout":0,"debug":false,"port":5555,"role":"node","timeout":1800}
,"description":null,"name":null}
14:33:54.811 DEBUG [BaseRemoteProxy.getNewInstance] - Using class org.openqa.gri
d.selenium.proxy.DefaultRemoteProxy
14:33:54.819 DEBUG [BaseRemoteProxy.setupTimeoutListener] - starting cleanup thr
ead
14:33:54.820 DEBUG [BaseRemoteProxy$CleanUpThread.run] - cleanup thread starting
...
14:33:54.822 INFO [DefaultGridRegistry.add] - Registered a node http://172.24.95
.36:5555
14:33:54.824 DEBUG [RegistrationServlet.lambda$process$0] - proxy added http://1
72.24.95.36:5555
liulirun picture liulirun on 7 Jun 2018

thanks @liulirun for your information.
I list mine in the below:
V3.11

C:\SeleniumGrid>TITLE SELENIUM_HUD

C:\SeleniumGrid>set SERVER_PORT=4444

C:\SeleniumGrid>set JAR_NAME=selenium-server-standalone-3.11.0.jar

C:\SeleniumGrid>java -jar selenium-server-standalone-3.11.0.jar -port 4444 -role
hub -debug -timeout 600 -browserTimeout 3600
21:23:02.064 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.11.
0', revision: 'e59cfb3'
21:23:02.064 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on por
t 4444
2018-06-07 21:23:02.892:INFO::main: Logging initialized @2242ms to org.seleniumh
q.jetty9.util.log.StdErrLog
21:23:03.408 INFO [Hub.start] - Selenium Grid hub is up and running
21:23:03.408 INFO [Hub.start] - Nodes should register to http://HubIP:4
444/grid/register/
21:23:03.408 INFO [Hub.start] - Clients should connect to http://HubIP:
4444/wd/hub
21:24:13.362 DEBUG [RegistrationServlet.process] - getting the following registr
ation request : {"class":{"enclosingConstructor":null,"annotations":[],"memberC
lass":false,"declaredConstructors":[null,null,null,null],"declaredFields":[null,
null,null,null,null,null,null],"superclass":{"enclosingConstructor":null,"annota
tions":[],"memberClass":false,"declaredConstructors":[null],"declaredFields":[],
"superclass":null,"canonicalName":"java.lang.Object","package":null,"protectionD
omain":null,"enclosingMethod":null,"enum":false,"declaringClass":null,"construct
ors":[null],"synthetic":false,"declaredClasses":[],"name":"java.lang.Object","fi
elds":[],"classLoader":null,"primitive":false,"methods":[null,null,null,null,nul
l,null,null,null,null],"classes":[],"typeName":"java.lang.Object","declaredMetho
ds":[null,null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,
"interface":false,"genericInterfaces":[],"annotatedSuperclass":null,"typeParamet
ers":[],"array":false,"enumConstants":null,"annotatedInterfaces":[],"class":"jav
a.lang.Class","annotation":false,"componentType":null,"declaredAnnotations":[],"
interfaces":[],"genericSuperclass":null,"localClass":false,"enclosingClass":null
,"signers":null,"simpleName":"Object","anonymousClass":false},"canonicalName":"o
rg.openqa.grid.common.RegistrationRequest","package":{"specificationVendor":"Ora
cle Corporation","declaredAnnotations":[],"implementationVersion":"9.4.7.v201709
14","sealed":false,"annotations":[],"implementationTitle":"HttpComponents Apache
HttpClient Mime","hCode":-250690871,"packages":[null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null],"specificationTitle":"HttpComponents Apache H
ttpClient Mime","name":"org.openqa.grid.common","implementationVendor":"Eclipse.
org - Jetty","class":"java.lang.Package","specificationVersion":"3.1"},"protecti
onDomain":{"classLoader":null,"permissions":null,"principals":[],"codeSource":nu
ll,"class":"java.security.ProtectionDomain"},"enclosingMethod":null,"enum":false
,"declaringClass":null,"constructors":[null,null,null,null],"synthetic":false,"d
eclaredClasses":[],"name":"org.openqa.grid.common.RegistrationRequest","fields":
[null,null,null],"classLoader":{"parent":null,"systemClassLoader":null,"uRLs":["
file:/C:/SeleniumGrid/selenium-server-standalone-3.11.0.jar"],"class":"sun.misc.
Launcher$AppClassLoader"},"primitive":false,"methods":[null,null,null,null,null,
null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"cla
sses":[],"typeName":"org.openqa.grid.common.RegistrationRequest","declaredMethod
s":[null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,"inter
face":false,"genericInterfaces":[],"annotatedSuperclass":{"declaredAnnotations":
[],"annotations":[],"type":null,"class":"sun.reflect.annotation.AnnotatedTypeFac
tory$AnnotatedTypeBaseImpl"},"typeParameters":[],"array":false,"enumConstants":n
ull,"annotatedInterfaces":[],"class":"java.lang.Class","annotation":false,"compo
nentType":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":{"en
closingConstructor":null,"annotations":[],"memberClass":false,"declaredConstruct
ors":[null],"declaredFields":[],"superclass":null,"canonicalName":"java.lang.Obj
ect","package":null,"protectionDomain":null,"enclosingMethod":null,"enum":false,
"declaringClass":null,"constructors":[null],"synthetic":false,"declaredClasses":
[],"name":"java.lang.Object","fields":[],"classLoader":null,"primitive":false,"m
ethods":[null,null,null,null,null,null,null,null,null],"classes":[],"typeName":"
java.lang.Object","declaredMethods":[null,null,null,null,null,null,null,null,nul
l,null,null,null],"modifiers":1,"interface":false,"genericInterfaces":[],"annota
tedSuperclass":null,"typeParameters":[],"array":false,"enumConstants":null,"anno
tatedInterfaces":[],"class":"java.lang.Class","annotation":false,"componentType"
:null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":null,"localCl
ass":false,"enclosingClass":null,"signers":null,"simpleName":"Object","anonymous
Class":false},"localClass":false,"enclosingClass":null,"signers":null,"simpleNam
e":"RegistrationRequest","anonymousClass":false},"configuration":{"remoteHost":"
http://NodeName:5555","id":"http://NodeName:5555","capabilities":[{"brow
serName":"internet explorer","maxInstances":3,"platform":"WINDOWS","platformName
":"WINDOWS","seleniumProtocol":"WebDriver","server:CONFIG_UUID":"56e72e37-4df1-4
41c-bb4f-21bf179694c9"},{"browserName":"chrome","chrome_binary":"C:/Program File
s (x86)/Google/Chrome/Application/chrome.exe","maxInstances":3,"platform":"WINDO
WS","platformName":"WINDOWS","seleniumProtocol":"WebDriver","server:CONFIG_UUID"
:"4783b93e-0974-43dd-95b2-a3c6560b7aae"},{"browserName":"firefox","maxInstances"
:3,"platform":"WINDOWS","platformName":"WINDOWS","seleniumProtocol":"WebDriver",
"server:CONFIG_UUID":"5a052f12-cc48-4d11-b49b-586971462fc6"}],"downPollingLimit"
:2,"hub":"http://HubIP:4444/grid/register","nodePolling":5000,"nodeStat
usCheckTimeout":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemoteProxy"
,"register":true,"registerCycle":5000,"unregisterIfStillDownAfter":60000,"enable
PlatformVerification":true,"custom":{},"host":"NodeName","maxSession":3,"ser
vlets":[],"withoutServlets":[],"browserTimeout":0,"debug":false,"port":5555,"rol
e":"node","timeout":1800},"description":null,"name":null}
21:24:13.675 DEBUG [BaseRemoteProxy.getNewInstance] - Using class org.openqa.gri
d.selenium.proxy.DefaultRemoteProxy
21:24:13.690 DEBUG [BaseRemoteProxy.setupTimeoutListener] - starting cleanup thr
ead
21:24:13.706 DEBUG [BaseRemoteProxy$CleanUpThread.run] - cleanup thread starting
...
21:24:13.706 INFO [DefaultGridRegistry.add] - Registered a node http://NodeName:5555
21:24:13.706 DEBUG [RegistrationServlet.lambda$process$0] - proxy added http://NodeName:5555

oceanchow picture oceanchow on 8 Jun 2018

V3.12

C:\SeleniumGrid>TITLE SELENIUM_HUD

C:\SeleniumGrid>set SERVER_PORT=4444

C:\SeleniumGrid>set JAR_NAME=selenium-server-standalone-3.12.0.jar

C:\SeleniumGrid>java -jar selenium-server-standalone-3.12.0.jar -port 4444 -role
hub -debug -timeout 600 -browserTimeout 3600
21:31:35.561 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.12.
0', revision: '7c6e0b3'
21:31:35.561 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on por
t 4444
2018-06-07 21:31:36.093:INFO::main: Logging initialized @1352ms to org.seleniumh
q.jetty9.util.log.StdErrLog
21:31:36.546 INFO [Hub.start] - Selenium Grid hub is up and running
21:31:36.546 INFO [Hub.start] - Nodes should register to http://HubIP:4
444/grid/register/
21:31:36.546 INFO [Hub.start] - Clients should connect to http://HubIP:
4444/wd/hub
21:31:44.359 DEBUG [RegistrationServlet.process] - getting the following registr
ation request : {"class":{"enclosingConstructor":null,"annotations":[],"memberC
lass":false,"declaredConstructors":[null,null,null,null],"declaredFields":[null,
null,null,null,null,null,null],"superclass":{"enclosingConstructor":null,"annota
tions":[],"memberClass":false,"declaredConstructors":[null],"declaredFields":[],
"superclass":null,"canonicalName":"java.lang.Object","package":null,"protectionD
omain":null,"enclosingMethod":null,"enum":false,"declaringClass":null,"construct
ors":[null],"synthetic":false,"declaredClasses":[],"name":"java.lang.Object","fi
elds":[],"classLoader":null,"primitive":false,"methods":[null,null,null,null,nul
l,null,null,null,null],"classes":[],"typeName":"java.lang.Object","declaredMetho
ds":[null,null,null,null,null,null,null,null,null,null,null,null],"modifiers":1,
"interface":false,"genericInterfaces":[],"annotatedSuperclass":null,"typeParamet
ers":[],"array":false,"enumConstants":null,"annotatedInterfaces":[],"class":"jav
a.lang.Class","annotation":false,"componentType":null,"declaredAnnotations":[],"
interfaces":[],"genericSuperclass":null,"localClass":false,"enclosingClass":null
,"signers":null,"simpleName":"Object","anonymousClass":false},"canonicalName":"o
rg.openqa.grid.common.RegistrationRequest","package":{"specificationVendor":"Ora
cle Corporation","declaredAnnotations":[],"implementationVersion":"9.4.7.v201709
14","sealed":false,"annotations":[],"implementationTitle":"HttpComponents Apache
HttpClient Mime","hCode":-250690871,"packages":[null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null,null,null,null,null,null,null,null,null,n
ull,null,null,null,null,null,null,null],"specificationTitle":"HttpComponents Apa
che HttpClient Mime","name":"org.openqa.grid.common","implementationVendor":"Ecl
ipse.org - Jetty","class":"java.lang.Package","specificationVersion":"3.1"},"pro
tectionDomain":{"classLoader":null,"permissions":null,"principals":[],"codeSourc
e":null,"class":"java.security.ProtectionDomain"},"enclosingMethod":null,"enum":
false,"declaringClass":null,"constructors":[null,null,null,null],"synthetic":fal
se,"declaredClasses":[],"name":"org.openqa.grid.common.RegistrationRequest","fie
lds":[null,null,null],"classLoader":{"parent":null,"systemClassLoader":null,"uRL
s":["file:/C:/SeleniumGrid/selenium-server-standalone-3.12.0.jar"],"class":"sun.
misc.Launcher$AppClassLoader"},"primitive":false,"methods":[null,null,null,null,
null,null,null,null,null,null,null,null,null,null,null,null,null,null,null],"cla
sses":[],"typeName":"org.openqa.grid.common.RegistrationRequest","declaredMethod
s":[null,null,null,null,null,null,null,null,null,null],"modifiers":1,"interface"
:false,"genericInterfaces":[],"annotatedSuperclass":{"declaredAnnotations":[],"a
nnotations":[],"type":null,"class":"sun.reflect.annotation.AnnotatedTypeFactory$
AnnotatedTypeBaseImpl"},"typeParameters":[],"array":false,"enumConstants":null,"
annotatedInterfaces":[],"class":"java.lang.Class","annotation":false,"componentT
ype":null,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":{"enclosi
ngConstructor":null,"annotations":[],"memberClass":false,"declaredConstructors":
[null],"declaredFields":[],"superclass":null,"canonicalName":"java.lang.Object",
"package":null,"protectionDomain":null,"enclosingMethod":null,"enum":false,"decl
aringClass":null,"constructors":[null],"synthetic":false,"declaredClasses":[],"n
ame":"java.lang.Object","fields":[],"classLoader":null,"primitive":false,"method
s":[null,null,null,null,null,null,null,null,null],"classes":[],"typeName":"java.
lang.Object","declaredMethods":[null,null,null,null,null,null,null,null,null,nul
l,null,null],"modifiers":1,"interface":false,"genericInterfaces":[],"annotatedSu
perclass":null,"typeParameters":[],"array":false,"enumConstants":null,"annotated
Interfaces":[],"class":"java.lang.Class","annotation":false,"componentType":null
,"declaredAnnotations":[],"interfaces":[],"genericSuperclass":null,"localClass":
false,"enclosingClass":null,"signers":null,"simpleName":"Object","anonymousClass
":false},"localClass":false,"enclosingClass":null,"signers":null,"simpleName":"R
egistrationRequest","anonymousClass":false},"configuration":{"unregisterIfStillD
ownAfter":60000,"role":"node","debug":false,"capabilities":[{"browserName":"inte
rnet explorer","maxInstances":3,"platform":"WINDOWS","platformName":"WINDOWS","s
eleniumProtocol":"WebDriver","server:CONFIG_UUID":"662d7228-5a0e-47e8-9b1f-52d8e
f3df230"},{"browserName":"chrome","chrome_binary":"C:/Program Files (x86)/Google
/Chrome/Application/chrome.exe","maxInstances":3,"platform":"WINDOWS","platformN
ame":"WINDOWS","seleniumProtocol":"WebDriver","server:CONFIG_UUID":"916359c9-007
a-4418-8b27-5a7f2791f9da"},{"browserName":"firefox","maxInstances":3,"platform":
"WINDOWS","platformName":"WINDOWS","seleniumProtocol":"WebDriver","server:CONFIG
_UUID":"9dca6c84-a35e-469e-b193-bcbe0900c8fd"}],"remoteHost":"http://NodeName:5555","custom":{},"nodeStatusCheckTimeout":5000,"downPollingLimit":2,"timeout"
:1800,"nodePolling":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemotePr
oxy","hub":"http://HubIP:4444/grid/register","port":5555,"browserTimeou
t":0,"host":"NodeName","servlets":[],"enablePlatformVerification":true,"id":
"http://NodeName:5555","withoutServlets":[],"maxSession":3,"registerCycle":5
000,"register":true},"description":null,"name":null}
21:31:44.578 DEBUG [BaseRemoteProxy.getNewInstance] - Using class org.openqa.gri
d.selenium.proxy.DefaultRemoteProxy
21:31:44.593 DEBUG [BaseRemoteProxy.setupTimeoutListener] - starting cleanup thr
ead
21:31:44.609 DEBUG [BaseRemoteProxy$CleanUpThread.run] - cleanup thread starting
...
21:31:44.609 INFO [DefaultGridRegistry.add] - Registered a node http://NodeName:5555
21:31:44.609 DEBUG [RegistrationServlet.lambda$process$0] - proxy added http://NodeName:5555
21:32:11.111 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node
: Failed to connect to NodeName/NodeIP:5555
21:32:37.144 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node
: Failed to connect to NodeName/NodeIP:5555
21:32:37.238 INFO [DefaultRemoteProxy.onEvent] - Marking the node http://NodeName:5555 as down: cannot reach the node for 2 tries

oceanchow picture oceanchow on 8 Jun 2018

Are you using IP6 on these machines too? Or are they only configured for IP4?

shs96c picture shs96c on 13 Jun 2018

I am using IP4.

liulirun picture liulirun on 14 Jun 2018

@shs96c Thanks for your response, in my case, we use IP4 only.
image

oceanchow picture oceanchow on 15 Jun 2018

I saw the same problem in Selenium V3.13.0, any update on this issue? Thanks for your work.

oceanchow picture oceanchow on 4 Jul 2018
👍1

Can you please try to start server v.3.13 with an extra system property -Dwebdriver.http.factory=apache and check if the issue still can be reproduuced?

barancev picture barancev on 9 Jul 2018

@barancev
thanks for your information, I added the option and test it in 3.9.1--still OK, 3.12.0--still same error, 3.13.0--still same error

oceanchow picture oceanchow on 10 Jul 2018

So, we have to figure out whether it's a hub issue or a node one.

Please run again a hub and a node version 3.12 (or 3.13) and when the hub logs "Failed to connect to XXX" try to access the node by this address manually from the hub host. You can use telnet client for this purpose: telnet <node IP or hostname> <node port>.

barancev picture barancev on 10 Jul 2018

@barancev, thanks for your information, sorry on giving you reply a little lately, I did the test about Telnet from 3.9.1, 3.11.0, 3.12.0, even 3.13.0, both of them will show "connecting to **...could not open connection to the host, on port 5555: connection failed, anything else need to do?

oceanchow picture oceanchow on 19 Jul 2018

@oceanchow Do you mean you can't connect by telnet to a node in 3.11 too? But the hub can connect to a node in the same situation? Sounds weird...

barancev picture barancev on 19 Jul 2018

@barancev, yes, that's why I cost couple of days to discuss with our IT team once I found out the result, according to their conclusion, our network is OK without any limitation. do you have any suggestion on continue the debugging? Thanks for your time.

oceanchow picture oceanchow on 20 Jul 2018

I had the same issue and resolved it by setting the Default Gateway on the node.

ArkadiuszKolodynski picture ArkadiuszKolodynski on 23 Jul 2018

I faced the same issue and found out the IP configuration of few nodes is not correct.

Even though Node was able to connect to the hub, Hub was not able to send any request to launch browsers to start test

Resolved after changing the ipconfiguration.

gurunadhd picture gurunadhd on 27 Jul 2018

We recently ran into this problem, and the issue was due to having multiple host routes for the same address on a single box. Our particular issue was caused by a VPN client injecting the additional host route with a lower metric (by design). This theoretically won't always fail, but at some point during our trip across the VPN, and back to the host, the port being used by the node was getting filtered out via firewall.

We worked around this issue by adding the "-host 127.0.0.1" cli option to the grid and hub (we are running the grid/hub locally on our development machines). Since the original reporter appears to be using a non-loopback interface, I would recommend setting the -host option on the hub to NODE_HOSTNAME. If that does not work, there is likely an overriding host route in your routing table that is causing your local IP address to not be treated as a loopback.

aaronmray picture aaronmray on 7 Aug 2018
❤1

@ArkadiuszKolodynski thanks for your information, could you please tell me more about how you modify the default gateway?

@gurunadhd thanks for your sharing, could you please tell me more about how you change the ip configuration?

@aaronmray thanks for your information, if you means the hub should be锛歫ava -jar %JAR_NAME% -port %SERVER_PORT% -host %HUB_HOSTNAME% -role hub -timeout 600 -browserTimeout 3600

oceanchow picture oceanchow on 16 Aug 2018
👍1

i saw the issue for 3.12.0 webdriver version for some VMs and decided do not upgrade libs.
suddenly I was able to reproduce the issue for 3.7.1 WD version as well. I just added new VM to existing hub and reproduce the issue.

After that I verified it for these 2 VMs only. For me it's definitely related to VPN which provides an extra network IP address. I can reproduce the issue if VPN from node was set up before grid node. Otherwise it works OK.

Please see logs:
I have two PC:

PC1 (where grid hub was started):
localIp has been replaced to "192.168.0.19(LOCAL_IP_FROM_HUB)"
VPN IP was not specified in logs.

PC2 (where grid node was started):
localIp has been replaced to "192.168.0.22(LOCAL_IP_FROM_NODE)"
VPN IP has been changed to "10.10.10.10(VPN_IP_FROM_NODE)"

START HUB, LOG FROM HUB:

d:\JenkinsAgents>java -jar selenium-server-standalone-3.7.1.jar -role hub -port 4447 -debug -host 127.0.0.1
01:11:04.880 INFO - Selenium build info: version: '3.7.1', revision: '8a0099a'
01:11:04.880 INFO - Launching Selenium Grid hub
2018-09-19 01:11:07.772:INFO::main: Logging initialized @4298ms to org.seleniumhq.jetty9.util.log.StdErrLog
01:11:07.860 INFO - Will listen on 4447
2018-09-19 01:11:08.125:INFO:osjs.Server:main: jetty-9.4.5.v20170502
2018-09-19 01:11:08.327:INFO:osjs.session:main: DefaultSessionIdManager workerName=node0
2018-09-19 01:11:08.327:INFO:osjs.session:main: No SessionScavenger set, using defaults
2018-09-19 01:11:08.344:INFO:osjs.session:main: Scavenging every 600000ms
2018-09-19 01:11:08.381:INFO:osjsh.ContextHandler:main: Started o.s.j.s.ServletContextHandler@3b94d659{/,null,AVAILABLE}
2018-09-19 01:11:08.506:INFO:osjs.AbstractConnector:main: Started ServerConnector@17baae6e{HTTP/1.1,[http/1.1]}{0.0.0.0:4447}
2018-09-19 01:11:08.508:INFO:osjs.Server:main: Started @5011ms
01:11:08.508 INFO - Nodes should register to http://127.0.0.1:4447/grid/register/
01:11:08.508 INFO - Selenium Grid hub is up and running

CONNECT NODE, LOG FROM NODE:

d:\.jenkins>java -jar selenium-server-standalone-3.7.1.jar -role node -hub http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register -browser "browserName=chrome,maxInstances=11,seleniumProtocol=WebDriver" -debug
01:12:51.883 INFO - Selenium build info: version: '3.7.1', revision: '8a0099a'
01:12:51.885 INFO - Launching a Selenium Grid node
01:12:52.738 DEBUG - CookieSpec selected: default
01:12:52.748 DEBUG - Auth cache not set in the context
01:12:52.749 DEBUG - Connection request: [route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:12:52.763 DEBUG - Connection leased: [id: 0][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:12:52.765 DEBUG - Opening connection {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:52.769 DEBUG - Connecting to /192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:52.772 DEBUG - Connection established 192.168.0.22(LOCAL_IP_FROM_NODE):62779<->192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:52.773 DEBUG - http-outgoing-0: set socket timeout to 10800000
01:12:52.773 DEBUG - Executing request GET /grid/api/hub HTTP/1.1
01:12:52.773 DEBUG - Target auth state: UNCHALLENGED
01:12:52.773 DEBUG - Proxy auth state: UNCHALLENGED
01:12:52.777 DEBUG - http-outgoing-0 >> GET /grid/api/hub HTTP/1.1
01:12:52.778 DEBUG - http-outgoing-0 >> Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:52.778 DEBUG - http-outgoing-0 >> Connection: Keep-Alive
01:12:52.778 DEBUG - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)
01:12:52.778 DEBUG - http-outgoing-0 >> Accept-Encoding: gzip,deflate
01:12:52.779 DEBUG - http-outgoing-0 >> "GET /grid/api/hub HTTP/1.1[\r][\n]"
01:12:52.779 DEBUG - http-outgoing-0 >> "Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447[\r][\n]"
01:12:52.780 DEBUG - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
01:12:52.780 DEBUG - http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)[\r][\n]"
01:12:52.780 DEBUG - http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
01:12:52.780 DEBUG - http-outgoing-0 >> "[\r][\n]"
01:12:52.904 DEBUG - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
01:12:52.905 DEBUG - http-outgoing-0 << "Date: Tue, 18 Sep 2018 22:12:57 GMT[\r][\n]"
01:12:52.905 DEBUG - http-outgoing-0 << "Content-Type: application/json;charset=utf-8[\r][\n]"
01:12:52.905 DEBUG - http-outgoing-0 << "Content-Length: 458[\r][\n]"
01:12:52.905 DEBUG - http-outgoing-0 << "Server: Jetty(9.4.5.v20170502)[\r][\n]"
01:12:52.906 DEBUG - http-outgoing-0 << "[\r][\n]"
01:12:52.906 DEBUG - http-outgoing-0 << "{"success":true,"capabilityMatcher":"org.openqa.grid.internal.utils.DefaultCapabilityMatcher","newSessionWaitTimeout":-1,"throwOnCapabilityNotPresent":true,"registry":"org.openqa.grid.internal.DefaultGridRegistry","cleanUpCycle":5000,"custom":{},"host":"127.0.0.1","servlets":[],"withoutServlets":[],"browserTimeout":0,"debug":true,"port":4447,"role":"hub","timeout":1800,"enablePassThrough":true,"newSessionRequestCount":0,"slotCounts":{"free":0,"total":0}}"
01:12:52.924 DEBUG - http-outgoing-0 << HTTP/1.1 200 OK
01:12:52.924 DEBUG - http-outgoing-0 << Date: Tue, 18 Sep 2018 22:12:57 GMT
01:12:52.925 DEBUG - http-outgoing-0 << Content-Type: application/json;charset=utf-8
01:12:52.925 DEBUG - http-outgoing-0 << Content-Length: 458
01:12:52.925 DEBUG - http-outgoing-0 << Server: Jetty(9.4.5.v20170502)
01:12:52.938 DEBUG - Connection can be kept alive indefinitely
01:12:52.947 DEBUG - Connection [id: 0][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447] can be kept alive indefinitely
01:12:52.949 DEBUG - Connection released: [id: 0][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 1; route allocated: 1 of 2000; total allocated: 1 of 2000]
2018-09-19 01:12:53.138:INFO::main: Logging initialized @1892ms to org.seleniumhq.jetty9.util.log.StdErrLog
01:12:53.202 INFO - Driver class not found: com.opera.core.systems.OperaDriver
01:12:53.246 INFO - Driver provider class org.openqa.selenium.safari.SafariDriver registration is skipped:
 registration capabilities Capabilities {browserName: safari, platform: MAC, version: } does not match the current platform XP
01:12:53.330 INFO - Using the passthrough mode handler
2018-09-19 01:12:53.369:INFO:osjs.Server:main: jetty-9.4.5.v20170502
2018-09-19 01:12:53.418:WARN:osjs.SecurityHandler:main: [email protected]@22295ec4{/,null,STARTING} has uncovered http methods for path: /
2018-09-19 01:12:53.450:INFO:osjsh.ContextHandler:main: Started o.s.j.s.ServletContextHandler@22295ec4{/,null,AVAILABLE}
2018-09-19 01:12:53.479:INFO:osjs.AbstractConnector:main: Started ServerConnector@68be8808{HTTP/1.1,[http/1.1]}{0.0.0.0:5555}
2018-09-19 01:12:53.484:INFO:osjs.Server:main: Started @2238ms
01:12:53.486 INFO - Selenium Grid node is up and ready to register to the hub
01:12:53.527 DEBUG - Using the json request : {"class":"org.openqa.grid.common.RegistrationRequest","name":null,"description":null,"configuration":{"remoteHost":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","hubHost":"192.168.0.19(LOCAL_IP_FROM_HUB)","hubPort":4447,"id":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","capabilities":[{"browserName":"chrome","maxInstances":11,"platform":"XP","seleniumProtocol":"WebDriver"}],"downPollingLimit":2,"hub":"http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register","nodePolling":5000,"nodeStatusCheckTimeout":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemoteProxy","register":true,"registerCycle":5000,"unregisterIfStillDownAfter":60000,"cleanUpCycle":null,"custom":{},"host":"10.10.10.10(VPN_IP_FROM_NODE)","maxSession":5,"servlets":[],"withoutServlets":[],"browserTimeout":0,"debug":true,"jettyMaxThreads":null,"log":null,"port":5555,"role":"node","timeout":1800,"enablePassThrough":true}}
01:12:53.537 INFO - Starting auto registration thread. Will try to register every 5000 ms.
01:12:53.538 INFO - Registering the node to the hub: http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register
01:12:53.558 DEBUG - CookieSpec selected: default
01:12:53.563 DEBUG - Auth cache not set in the context
01:12:53.565 DEBUG - Connection request: [route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 1; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:12:53.567 DEBUG - Connection leased: [id: 0][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:12:53.568 DEBUG - Stale connection check
01:12:53.570 DEBUG - http-outgoing-0 << "[read] I/O error: Read timed out"
01:12:53.571 DEBUG - http-outgoing-0: set socket timeout to 10800000
01:12:53.575 DEBUG - Executing request POST /grid/register HTTP/1.1
01:12:53.576 DEBUG - Target auth state: UNCHALLENGED
01:12:53.577 DEBUG - Proxy auth state: UNCHALLENGED
01:12:53.590 DEBUG - http-outgoing-0 >> POST /grid/register HTTP/1.1
01:12:53.591 DEBUG - http-outgoing-0 >> Content-Length: 811
01:12:53.593 DEBUG - http-outgoing-0 >> Content-Type: text/plain; charset=UTF-8
01:12:53.595 DEBUG - http-outgoing-0 >> Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:53.602 DEBUG - http-outgoing-0 >> Connection: Keep-Alive
01:12:53.602 DEBUG - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)
01:12:53.604 DEBUG - http-outgoing-0 >> Accept-Encoding: gzip,deflate
01:12:53.606 DEBUG - http-outgoing-0 >> "POST /grid/register HTTP/1.1[\r][\n]"
01:12:53.607 DEBUG - http-outgoing-0 >> "Content-Length: 811[\r][\n]"
01:12:53.608 DEBUG - http-outgoing-0 >> "Content-Type: text/plain; charset=UTF-8[\r][\n]"
01:12:53.618 DEBUG - http-outgoing-0 >> "Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447[\r][\n]"
01:12:53.618 DEBUG - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
01:12:53.618 DEBUG - http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)[\r][\n]"
01:12:53.619 DEBUG - http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
01:12:53.620 DEBUG - http-outgoing-0 >> "[\r][\n]"
01:12:53.623 DEBUG - http-outgoing-0 >> "{"class":"org.openqa.grid.common.RegistrationRequest","name":null,"description":null,"configuration":{"remoteHost":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","hubHost":"192.168.0.19(LOCAL_IP_FROM_HUB)","hubPort":4447,"id":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","capabilities":[{"browserName":"chrome","maxInstances":11,"platform":"XP","seleniumProtocol":"WebDriver"}],"downPollingLimit":2,"hub":"http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register","nodePolling":5000,"nodeStatusCheckTimeout":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemoteProxy","register":true,"registerCycle":5000,"unregisterIfStillDownAfter":60000,"cleanUpCycle":null,"custom":{},"host":"10.10.10.10(VPN_IP_FROM_NODE)","maxSession":5,"servlets":[],"withoutServlets":[],"browserTimeout":0,"debug":true,"jettyMaxThreads":null,"log":null,"port":5555,"role":"node","timeout":1800,"enablePassThrough":true}}"
01:12:54.225 DEBUG - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
01:12:54.227 DEBUG - http-outgoing-0 << "Date: Tue, 18 Sep 2018 22:12:58 GMT[\r][\n]"
01:12:54.228 DEBUG - http-outgoing-0 << "Content-Type: text/html;charset=utf-8[\r][\n]"
01:12:54.229 DEBUG - http-outgoing-0 << "Content-Length: 2[\r][\n]"
01:12:54.232 DEBUG - http-outgoing-0 << "Server: Jetty(9.4.5.v20170502)[\r][\n]"
01:12:54.233 DEBUG - http-outgoing-0 << "[\r][\n]"
01:12:54.234 DEBUG - http-outgoing-0 << "ok"
01:12:54.235 DEBUG - http-outgoing-0 << HTTP/1.1 200 OK
01:12:54.236 DEBUG - http-outgoing-0 << Date: Tue, 18 Sep 2018 22:12:58 GMT
01:12:54.239 DEBUG - http-outgoing-0 << Content-Type: text/html;charset=utf-8
01:12:54.241 DEBUG - http-outgoing-0 << Content-Length: 2
01:12:54.241 DEBUG - http-outgoing-0 << Server: Jetty(9.4.5.v20170502)
01:12:54.242 DEBUG - Connection can be kept alive indefinitely
01:12:54.243 INFO - The node is registered to the hub and ready to use
01:12:59.248 DEBUG - CookieSpec selected: default
01:12:59.248 DEBUG - Auth cache not set in the context
01:12:59.249 DEBUG - Connection request: [route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:12:59.252 DEBUG - Connection leased: [id: 1][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 0; route allocated: 2 of 2000; total allocated: 2 of 2000]
01:12:59.253 DEBUG - Opening connection {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:59.254 DEBUG - Connecting to /192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:59.256 DEBUG - Connection established 192.168.0.22(LOCAL_IP_FROM_NODE):62782<->192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:59.256 DEBUG - http-outgoing-1: set socket timeout to 10800000
01:12:59.257 DEBUG - Executing request GET /grid/api/proxy?id=http://10.10.10.10(VPN_IP_FROM_NODE):5555 HTTP/1.1
01:12:59.271 DEBUG - Target auth state: UNCHALLENGED
01:12:59.272 DEBUG - Proxy auth state: UNCHALLENGED
01:12:59.273 DEBUG - http-outgoing-1 >> GET /grid/api/proxy?id=http://10.10.10.10(VPN_IP_FROM_NODE):5555 HTTP/1.1
01:12:59.275 DEBUG - http-outgoing-1 >> Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447
01:12:59.275 DEBUG - http-outgoing-1 >> Connection: Keep-Alive
01:12:59.276 DEBUG - http-outgoing-1 >> User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)
01:12:59.277 DEBUG - http-outgoing-1 >> Accept-Encoding: gzip,deflate
01:12:59.278 DEBUG - http-outgoing-1 >> "GET /grid/api/proxy?id=http://10.10.10.10(VPN_IP_FROM_NODE):5555 HTTP/1.1[\r][\n]"
01:12:59.279 DEBUG - http-outgoing-1 >> "Host: 192.168.0.19(LOCAL_IP_FROM_HUB):4447[\r][\n]"
01:12:59.279 DEBUG - http-outgoing-1 >> "Connection: Keep-Alive[\r][\n]"
01:12:59.283 DEBUG - http-outgoing-1 >> "User-Agent: Apache-HttpClient/4.5.3 (Java/10.0.2)[\r][\n]"
01:12:59.288 DEBUG - http-outgoing-1 >> "Accept-Encoding: gzip,deflate[\r][\n]"
01:12:59.288 DEBUG - http-outgoing-1 >> "[\r][\n]"
01:12:59.323 DEBUG - http-outgoing-1 << "HTTP/1.1 200 OK[\r][\n]"
01:12:59.324 DEBUG - http-outgoing-1 << "Date: Tue, 18 Sep 2018 22:13:04 GMT[\r][\n]"
01:12:59.354 DEBUG - http-outgoing-1 << "Content-Type: application/json;charset=utf-8[\r][\n]"
01:12:59.354 DEBUG - http-outgoing-1 << "Content-Length: 892[\r][\n]"
01:12:59.355 DEBUG - http-outgoing-1 << "Server: Jetty(9.4.5.v20170502)[\r][\n]"
01:12:59.355 DEBUG - http-outgoing-1 << "[\r][\n]"
01:12:59.355 DEBUG - http-outgoing-1 << "{"success":true,"msg":"proxy found !","id":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","request":{"class":"org.openqa.grid.common.RegistrationRequest","name":null,"description":null,"configuration":{"remoteHost":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","hubHost":"192.168.0.19(LOCAL_IP_FROM_HUB)","hubPort":4447,"id":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","capabilities":[{"browserName":"chrome","maxInstances":11,"platform":"XP","seleniumProtocol":"WebDriver"}],"downPollingLimit":2,"hub":"http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register","nodePolling":5000,"nodeStatusCheckTimeout":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemoteProxy","register":true,"registerCycle":5000,"unregisterIfStillDownAfter":60000,"cleanUpCycle":null,"custom":{},"host":"10.10.10.10(VPN_IP_FROM_NODE)","maxSession":5,"servlets":[],"withoutServlets":[],"browserTimeout":0,"debug":true,"jettyMaxThreads":null,"log":null,"port":5555,"role":"node","timeout":1800,"enablePassThrough":true}}}"
01:12:59.356 DEBUG - http-outgoing-1 << HTTP/1.1 200 OK
01:12:59.356 DEBUG - http-outgoing-1 << Date: Tue, 18 Sep 2018 22:13:04 GMT
01:12:59.356 DEBUG - http-outgoing-1 << Content-Type: application/json;charset=utf-8
01:12:59.356 DEBUG - http-outgoing-1 << Content-Length: 892
01:12:59.356 DEBUG - http-outgoing-1 << Server: Jetty(9.4.5.v20170502)
01:12:59.357 DEBUG - Connection can be kept alive indefinitely
01:12:59.357 DEBUG - Connection [id: 1][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447] can be kept alive indefinitely
01:12:59.357 DEBUG - Connection released: [id: 1][route: {}->http://192.168.0.19(LOCAL_IP_FROM_HUB):4447][total kept alive: 1; route allocated: 2 of 2000; total allocated: 2 of 2000]
01:12:59.359 DEBUG - The node is already present on the hub. Skipping registration.

AT THE SAME TIME HUB lOG:

01:12:58.853 DEBUG - getting the following registration request  : {"class":"org.openqa.grid.common.RegistrationRequest","name":null,"description":null,"configuration":{"remoteHost":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","hubHost":"192.168.0.19(LOCAL_IP_FROM_HUB)","hubPort":4447,"id":"http://10.10.10.10(VPN_IP_FROM_NODE):5555","capabilities":[{"browserName":"chrome","maxInstances":11,"platform":"XP","seleniumProtocol":"WebDriver"}],"downPollingLimit":2,"hub":"http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register","nodePolling":5000,"nodeStatusCheckTimeout":5000,"proxy":"org.openqa.grid.selenium.proxy.DefaultRemoteProxy","register":true,"registerCycle":5000,"unregisterIfStillDownAfter":60000,"cleanUpCycle":null,"custom":{},"host":"10.10.10.10(VPN_IP_FROM_NODE)","maxSession":5,"servlets":[],"withoutServlets":[],"browserTimeout":0,"debug":true,"jettyMaxThreads":null,"log":null,"port":5555,"role":"node","timeout":1800,"enablePassThrough":true}}
01:12:59.447 DEBUG - Using class org.openqa.grid.selenium.proxy.DefaultRemoteProxy
01:12:59.452 DEBUG - starting cleanup thread
01:12:59.459 DEBUG - cleanup thread starting...
01:12:59.460 INFO - Registered a node http://10.10.10.10(VPN_IP_FROM_NODE):5555
01:12:59.463 DEBUG - proxy added http://10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:04.537 DEBUG - Closing connections idle longer than 100 MILLISECONDS
01:13:04.600 DEBUG - CookieSpec selected: default
01:13:04.645 DEBUG - Auth cache not set in the context
01:13:04.648 DEBUG - Connection request: [route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:04.696 DEBUG - Connection leased: [id: 0][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:13:04.704 DEBUG - Opening connection {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:04.714 DEBUG - Connecting to /10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:09.797 DEBUG - http-outgoing-0: Shutdown connection
01:13:09.810 DEBUG - Connection discarded
01:13:09.812 DEBUG - Connection released: [id: 0][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:09.813 DEBUG - Failed to check status of node: Connect to 10.10.10.10(VPN_IP_FROM_NODE):5555 [/10.10.10.10(VPN_IP_FROM_NODE)] failed: connect timed out
01:13:14.886 DEBUG - Closing connections idle longer than 100 MILLISECONDS
01:13:14.888 DEBUG - CookieSpec selected: default
01:13:14.888 DEBUG - Auth cache not set in the context
01:13:14.889 DEBUG - Connection request: [route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:14.889 DEBUG - Connection leased: [id: 1][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:13:14.890 DEBUG - Opening connection {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:14.903 DEBUG - Connecting to /10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:19.973 DEBUG - http-outgoing-1: Shutdown connection
01:13:19.975 DEBUG - Connection discarded
01:13:19.975 DEBUG - Connection released: [id: 1][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:19.977 DEBUG - Failed to check status of node: Connect to 10.10.10.10(VPN_IP_FROM_NODE):5555 [/10.10.10.10(VPN_IP_FROM_NODE)] failed: connect timed out
01:13:19.978 INFO - Marking the node http://10.10.10.10(VPN_IP_FROM_NODE):5555 as down: cannot reach the node for 2 tries
01:13:25.045 DEBUG - Closing connections idle longer than 100 MILLISECONDS
01:13:25.046 DEBUG - CookieSpec selected: default
01:13:25.048 DEBUG - Auth cache not set in the context
01:13:25.049 DEBUG - Connection request: [route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:25.049 DEBUG - Connection leased: [id: 2][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 1 of 2000; total allocated: 1 of 2000]
01:13:25.051 DEBUG - Opening connection {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:25.051 DEBUG - Connecting to /10.10.10.10(VPN_IP_FROM_NODE):5555
01:13:30.119 DEBUG - http-outgoing-2: Shutdown connection
01:13:30.119 DEBUG - Connection discarded
01:13:30.122 DEBUG - Connection released: [id: 2][route: {}->http://10.10.10.10(VPN_IP_FROM_NODE):5555][total kept alive: 0; route allocated: 0 of 2000; total allocated: 0 of 2000]
01:13:30.122 DEBUG - Failed to check status of node: Connect to 10.10.10.10(VPN_IP_FROM_NODE):5555 [/10.10.10.10(VPN_IP_FROM_NODE)] failed: connect timed out
01:13:35.189 DEBUG - Closing connections idle longer than 100 MILLISECONDS

Hope it will help to figure out the issue.

Also, please note, I think it's really possible that network routes can impact to the behavior, just because other VMs also use vpn (and it was set before a grid node) and they work OK.

dmitryyu picture dmitryyu on 19 Sep 2018

Also i have verified it for 3.14.0. The behavior is reproduced as well.
Additionally I tried to use "-host 127.0.0.1 option" but in the case grid console for the hub cannot be even opened.

I have two PC:

PC1 (where grid hub was started):
localIp has been replaced to "192.168.0.19(LOCAL_IP_FROM_HUB)"
VPN IP has been changed to ""

PC2 (where grid node was started):
localIp has been replaced to "192.168.0.22(LOCAL_IP_FROM_NODE)"
VPN IP has been changed to "10.10.10.10(VPN_IP_FROM_NODE)"

if hub started with "-host 127.0.0.1"(the option was recommended above) it shows the following log(from hub) and node cannot connect to the hub at all.
Tried to open hub from PC1:
127.0.0.1:4447 - works OK
192.168.0.19(LOCAL_IP_FROM_HUB):4447 - it cannot be opened. (so node cannot connect as well)

LOG FROM HUB if -host 127.0.0.1 is specified:

d:\JenkinsAgents>java -jar selenium-server-standalone-3.14.0.jar -role hub -port 4447 -debug -host 127.0.0.1
02:10:41.476 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.14.0', revision: 'aacccce0'
02:10:41.495 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on port 4447
2018-09-19 02:10:42.373:INFO::main: Logging initialized @2739ms to org.seleniumhq.jetty9.util.log.StdErrLog
02:10:43.839 INFO [Hub.start] - Selenium Grid hub is up and running
02:10:43.840 INFO [Hub.start] - Nodes should register to http://127.0.0.1:4447/grid/register/
02:10:43.840 INFO [Hub.start] - Clients should connect to http://127.0.0.1:4447/wd/hub

if hub started without "-host 127.0.0.1".
START HUB, LOG FROM HUB if -host 127.0.0.1 is NOT specified:

d:\JenkinsAgents>java -jar selenium-server-standalone-3.14.0.jar -role hub -port 4447 -debug
02:18:35.440 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.14.0', revision: 'aacccce0'
02:18:35.452 INFO [GridLauncherV3$2.launch] - Launching Selenium Grid hub on port 4447
2018-09-19 02:18:36.328:INFO::main: Logging initialized @3002ms to org.seleniumhq.jetty9.util.log.StdErrLog
02:18:38.208 INFO [Hub.start] - Selenium Grid hub is up and running
02:18:38.209 INFO [Hub.start] - Nodes should register to http://10.10.10.10(VPN_IP_FROM_NODE):4447/grid/register/
02:18:38.209 INFO [Hub.start] - Clients should connect to http://10.10.10.10(VPN_IP_FROM_NODE):4447/wd/hub

CONNECT NODE, LOG FROM NODE:

d:\.jenkins>java -jar selenium-server-standalone-3.14.0.jar -role node -hub http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register -browser "browserName=chrome,maxInstances=11,seleniumProtocol=WebDriver" -debug
02:19:11.313 INFO [GridLauncherV3.launch] - Selenium build info: version: '3.14.0', revision: 'aacccce0'
02:19:11.375 INFO [GridLauncherV3$3.launch] - Launching a Selenium Grid node on port 34210
2018-09-19 02:19:12.106:INFO::main: Logging initialized @1732ms to org.seleniumhq.jetty9.util.log.StdErrLog
02:19:12.470 INFO [SeleniumServer.boot] - Selenium Server is up and running on port 34210
02:19:12.472 INFO [GridLauncherV3$3.launch] - Selenium Grid node is up and ready to register to the hub
02:19:12.649 DEBUG [SelfRegisteringRemote.startRegistrationProcess] - Using the json request : {
  "class": "org.openqa.grid.common.RegistrationRequest",
  "configuration": {
    "browserTimeout": 0,
    "capabilities": [
      {
        "browserName": "chrome",
        "maxInstances": 11,
        "platform": "XP",
        "platformName": "XP",
        "seleniumProtocol": "WebDriver",
        "server:CONFIG_UUID": "2872f49c-5ab1-4081-affb-673346038328"
      }
    ],
    "custom": {
    },
    "debug": true,
    "downPollingLimit": 2,
    "enablePlatformVerification": true,
    "host": "10.10.10.10(VPN_IP_FROM_NODE)",
    "hub": "http:\u002f\u002f192.168.0.19(LOCAL_IP_FROM_HUB):4447\u002fgrid\u002fregister",
    "id": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
    "maxSession": 5,
    "nodePolling": 5000,
    "nodeStatusCheckTimeout": 5000,
    "port": 34210,
    "proxy": "org.openqa.grid.selenium.proxy.DefaultRemoteProxy",
    "register": true,
    "registerCycle": 5000,
    "remoteHost": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
    "role": "node",
    "servlets": [
    ],
    "timeout": 1800,
    "unregisterIfStillDownAfter": 60000,
    "withoutServlets": [
    ]
  },
  "description": null,
  "name": null
}
02:19:12.657 INFO [SelfRegisteringRemote$1.run] - Starting auto registration thread. Will try to register every 5000 ms.
02:19:12.659 INFO [SelfRegisteringRemote.registerToHub] - Registering the node to the hub: http://192.168.0.19(LOCAL_IP_FROM_HUB):4447/grid/register
02:19:14.396 DEBUG [SelfRegisteringRemote.registerToHub] - Updating the node configuration from the hub
02:19:14.609 DEBUG [SelfRegisteringRemote.registerToHub] - Hub configuration: {
  "browserTimeout": 0,
  "capabilityMatcher": "org.openqa.grid.internal.utils.DefaultCapabilityMatcher",
  "cleanUpCycle": 5000,
  "custom": {
  },
  "debug": false,
  "host": "10.10.10.10(VPN_IP_FROM_NODE)",
  "newSessionWaitTimeout": -1,
  "port": 4447,
  "registry": "org.openqa.grid.internal.DefaultGridRegistry",
  "role": "hub",
  "servlets": [
  ],
  "throwOnCapabilityNotPresent": true,
  "timeout": 1800,
  "withoutServlets": [
  ]
}
02:19:14.625 DEBUG [SelfRegisteringRemote.registerToHub] - Updated node configuration: {
  "browserTimeout": 0,
  "capabilities": [
    {
      "browserName": "chrome",
      "maxInstances": 11,
      "platform": "XP",
      "platformName": "XP",
      "seleniumProtocol": "WebDriver",
      "server:CONFIG_UUID": "2872f49c-5ab1-4081-affb-673346038328"
    }
  ],
  "custom": {
  },
  "debug": true,
  "downPollingLimit": 2,
  "enablePlatformVerification": true,
  "host": "10.10.10.10(VPN_IP_FROM_NODE)",
  "hub": "http:\u002f\u002f192.168.0.19(LOCAL_IP_FROM_HUB):4447\u002fgrid\u002fregister",
  "id": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
  "maxSession": 5,
  "nodePolling": 5000,
  "nodeStatusCheckTimeout": 5000,
  "port": 34210,
  "proxy": "org.openqa.grid.selenium.proxy.DefaultRemoteProxy",
  "register": true,
  "registerCycle": 5000,
  "remoteHost": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
  "role": "node",
  "servlets": [
  ],
  "timeout": 1800,
  "unregisterIfStillDownAfter": 60000,
  "withoutServlets": [
  ]
}
02:19:14.626 INFO [SelfRegisteringRemote.registerToHub] - The node is registered to the hub and ready to use

AT THE SAME TIME HUB lOG:

02:19:13.514 DEBUG [RegistrationServlet.process] - getting the following registration request  : {
  "class": "org.openqa.grid.common.RegistrationRequest",
  "configuration": {
    "browserTimeout": 0,
    "capabilities": [
      {
        "browserName": "chrome",
        "maxInstances": 11,
        "platform": "XP",
        "platformName": "XP",
        "seleniumProtocol": "WebDriver",
        "server:CONFIG_UUID": "2872f49c-5ab1-4081-affb-673346038328"
      }
    ],
    "custom": {
    },
    "debug": true,
    "downPollingLimit": 2,
    "enablePlatformVerification": true,
    "host": "10.10.10.10(VPN_IP_FROM_NODE)",
    "hub": "http:\u002f\u002f192.168.0.19(LOCAL_IP_FROM_HUB):4447\u002fgrid\u002fregister",
    "id": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
    "maxSession": 5,
    "nodePolling": 5000,
    "nodeStatusCheckTimeout": 5000,
    "port": 34210,
    "proxy": "org.openqa.grid.selenium.proxy.DefaultRemoteProxy",
    "register": true,
    "registerCycle": 5000,
    "remoteHost": "http:\u002f\u002f10.10.10.10(VPN_IP_FROM_NODE):34210",
    "role": "node",
    "servlets": [
    ],
    "timeout": 1800,
    "unregisterIfStillDownAfter": 60000,
    "withoutServlets": [
    ]
  },
  "description": null,
  "name": null
}
02:19:14.194 DEBUG [BaseRemoteProxy.getNewInstance] - Using class org.openqa.grid.selenium.proxy.DefaultRemoteProxy
02:19:14.236 DEBUG [BaseRemoteProxy.setupTimeoutListener] - starting cleanup thread
02:19:14.247 DEBUG [BaseRemoteProxy$CleanUpThread.run] - cleanup thread starting...
02:19:14.267 INFO [DefaultGridRegistry.add] - Registered a node http://10.10.10.10(VPN_IP_FROM_NODE):34210
02:19:14.281 DEBUG [RegistrationServlet.lambda$process$0] - proxy added http://10.10.10.10(VPN_IP_FROM_NODE):34210
02:19:42.686 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node: Failed to connect to /10.10.10.10(VPN_IP_FROM_NODE):34210
02:20:08.721 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node: Failed to connect to /10.10.10.10(VPN_IP_FROM_NODE):34210
02:20:08.728 INFO [DefaultRemoteProxy.onEvent] - Marking the node http://10.10.10.10(VPN_IP_FROM_NODE):34210 as down: cannot reach the node for 2 tries
02:20:34.739 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node: Failed to connect to /10.10.10.10(VPN_IP_FROM_NODE):34210
02:21:00.780 DEBUG [DefaultRemoteProxy.isAlive] - Failed to check status of node: Failed to connect to /10.10.10.10(VPN_IP_FROM_NODE):34210
02:21:25.170 INFO [DefaultRemoteProxy.onEvent] - Unregistering the node http://10.10.10.10(VPN_IP_FROM_NODE):34210 because it's been down for 76442 milliseconds
02:21:25.172 WARN [DefaultGridRegistry.removeIfPresent] - Cleaning up stale test sessions on the unregistered node http://10.10.10.10(VPN_IP_FROM_NODE):34210
dmitryyu picture dmitryyu on 19 Sep 2018

UPD:
We played with routes and it doesn't help. We set routes where

  1. VPN metrics > Local interface metrics.
  2. VPN metrics < Local interface metrics.
    No success.

After that we noticed one difference for VMs where it works and doesn't work.
if you print routes for

  1. VM where it works:
    14...00 10 73 45 3d b4 ......VPN Virtual Interface
    11...00 12 5d 00 0b 20 ......Microsoft Hyper-V Network Adapter
  2. VM where it doesn't work
    3...00 10 73 d9 34 fd ......VPN Virtual Interface
    9...00 12 5d 00 0b 2a ......Microsoft Hyper-V Network Adapter
    you can see that the issue is reproduced if VPN interface ID less than Local Interface ID.

So it looks that webdriver gets the information based on the lowest interface ID and ignores Ip address for Hub which is specified during node connection. - i believe it should use default ip which is provided in command line.

To resolve the issue we re-installed vpn client - which set new interface with another ID. as a result we got:
20...00 10 73 d9 34 fd ......VPN Virtual Interface
8...00 12 5d 00 0b 2a ......Microsoft Hyper-V Network Adapter
and it works as expected.

at the same time some other ways exist to change interface ID, for example:
https://docs.microsoft.com/en-us/windows-server/networking/technologies/network-subsystem/net-sub-interface-metric

dmitryyu picture dmitryyu on 19 Sep 2018
👍1

I faced the same issue and found out the IP configuration of few nodes is not correct.

Even though Node was able to connect to the hub, Hub was not able to send any request to launch browsers to start test

Resolved after changing the ipconfiguration.

Could you please explain what the ipconfiguration change you have done ?

MaheshGooner picture MaheshGooner on 6 Feb 2019

same error on windows server, but i fixed it by change firewall rule "inbound rules[鍏ョ珯瑙勫垯]",specified selenium port & grid server ip

gogoyqj picture gogoyqj on 30 Apr 2019

I had a similar issue going across a WIFI router. When the node on host machine A connected to the hub on host machine B, the hub was getting the IP address of the WIFI router, instead of the IP address of host machine A. I resolved the issue by explicitly specifying -host when starting up the node.

java -Dwebdriver.chrome.driver=chromedrivermac -jar selenium-server-standalone-3.141.59.jar -role node -browser platform=MAC,browserName=chrome,maxInstances=5,seleniumProtocol=WebDriver,acceptSslCerts=true -hub http://10.0.0.1:4444/grid/register -port 5562 -host 10.0.0.6

jimarasim picture jimarasim on 28 May 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

SwastikGanguly picture SwastikGanguly  路  35Comments
konstin picture konstin  路  33Comments
etwxabh picture etwxabh  路  31Comments
bilalian picture bilalian  路  37Comments
WooHooDai picture WooHooDai  路  30Comments