Open titusfortner opened 6 months ago
@krmahadevan do you have time to look at this? I'm in the middle of several other things and don't want to jump down this particular rabbit hole right now. Thanks.
Having the same issue with docker selenium. Tried to get some insight with --log-level "ALL" but it doesn't seem very helpful. Any suggestions how to get more insight?
$ docker run -d -e SE_NODE_ENABLE_MANAGED_DOWNLOADS=true -e SE_LOG_LEVEL=ALL selenium/standalone-firefox:4.22.0-20240621
$ curl localhost:4444/status
{
"value": {
"ready": true,
"message": "Selenium Grid ready.",
"nodes": [
{
"id": "9c78b7de-380b-4a97-ace4-429f3842108d",
"uri": "http:\u002f\u002f172.17.0.5:4444",
"maxSessions": 1,
"osInfo": {
"arch": "amd64",
"name": "Linux",
"version": "5.4.0-186-generic"
},
"heartbeatPeriod": 30000,
"availability": "UP",
"version": "4.22.0 (revision c5f3146703)",
"slots": [
{
"id": {
"hostId": "9c78b7de-380b-4a97-ace4-429f3842108d",
"id": "c59cd67b-d13c-4745-ac2c-0b461be8e5c4"
},
"lastStarted": "1970-01-01T00:00:00Z",
"session": null,
"stereotype": {
"browserName": "firefox",
"browserVersion": "127.0",
"moz:firefoxOptions": {
"binary": "\u002fusr\u002fbin\u002ffirefox"
},
"platformName": "linux",
"se:downloadsEnabled": true,
"se:noVncPort": 7900,
"se:vncEnabled": true
}
}
]
}
]
}
}
>>> driver = Remote("http://localhost:4444/wd/hub")
Traceback (most recent call last):
File "<stdin>", line 1, in <module>
File "/usr/lib/python3/dist-packages/selenium/webdriver/remote/webdriver.py", line 152, in __init__
self.start_session(capabilities, browser_profile)
File "/usr/lib/python3/dist-packages/selenium/webdriver/remote/webdriver.py", line 249, in start_session
response = self.execute(Command.NEW_SESSION, parameters)
File "/usr/lib/python3/dist-packages/selenium/webdriver/remote/webdriver.py", line 318, in execute
self.error_handler.check_response(response)
File "/usr/lib/python3/dist-packages/selenium/webdriver/remote/errorhandler.py", line 242, in check_response
raise exception_class(message, screen, stacktrace)
selenium.common.exceptions.SessionNotCreatedException: Message: Could not start a new session. New session request timed out
Host info: host: 'f6045c8ff6cb', ip: '172.17.0.5'
Build info: version: '4.22.0', revision: 'c5f3146703'
System info: os.name: 'Linux', os.arch: 'amd64', os.version: '5.4.0-186-generic', java.version: '17.0.11'
Driver info: driver.version: unknown
14:41:11.296 DEBUG [RequestConverter.channelRead0] - Start of http request: DefaultHttpRequest(decodeResult: success, version: HTTP/1.1)
POST /wd/hub/session HTTP/1.1
Host: 127.0.0.1:4444
Accept-Encoding: identity
Content-Length: 84
Accept: application/json
Content-Type: application/json;charset=UTF-8
User-Agent: selenium/4.0.0a1 (python linux)
Connection: keep-alive
14:41:11.299 DEBUG [RequestConverter.channelRead0] - Incoming message: DefaultLastHttpContent(data: PooledSlicedByteBuf(ridx: 0, widx: 84, cap: 84/84, unwrapped: PooledUnsafeDirectByteBuf(ridx: 327, widx: 327, cap: 2048)), decoderResult: success)
14:41:11.300 DEBUG [RequestConverter.channelRead0] - End of http request: DefaultLastHttpContent(data: PooledSlicedByteBuf(ridx: 84, widx: 84, cap: 84/84, unwrapped: PooledUnsafeDirectByteBuf(ridx: 327, widx: 327, cap: 2048)), decoderResult: success)
14:41:11.323 DEBUG [SpanWrappedHttpHandler.execute] - Wrapping request. Before OpenTelemetryContext{tracer=io.opentelemetry.sdk.trace.SdkTracer@551bdc27, context={}, span id=0000000000000000, trace id=00000000000000000000000000000000} and after OpenTelemetryContext{tracer=io.opentelemetry.sdk.trace.SdkTracer@551bdc27, context={opentelemetry-trace-span-key=SdkSpan{traceId=3936a1296e9b4d320009deaffa66fdbb, spanId=1758b3fbed896d1b, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, name=session_queue, kind=INTERNAL, attributes=AttributesMap{data={random.key=d23419b9-223e-4cad-b4e9-603d59893273}, capacity=128, totalAddedValues=1}, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1719585671319058518, endEpochNanos=0}}, span id=1758b3fbed896d1b, trace id=3936a1296e9b4d320009deaffa66fdbb}
14:41:11.326 DEBUG [HttpTracing.inject] - Injecting (POST) /session into OpenTelemetrySpan{traceId=3936a1296e9b4d320009deaffa66fdbb,spanId=1758b3fbed896d1b} at org.openqa.selenium.remote.tracing.SpanWrappedHttpHandler:85
14:42:55.808 DEBUG [LocalDistributor.lambda$asRunnableHealthCheck$9] - Running healthcheck for Node http://172.17.0.5:4444
14:42:55.809 DEBUG [LocalDistributor.updateNodeAvailability] - Health check result for http://172.17.0.5:4444 was UP
14:44:55.807 DEBUG [LocalDistributor.lambda$asRunnableHealthCheck$9] - Running healthcheck for Node http://172.17.0.5:4444
14:44:55.808 DEBUG [LocalDistributor.updateNodeAvailability] - Health check result for http://172.17.0.5:4444 was UP
14:46:11.351 DEBUG [SeleniumSpanExporter$1.lambda$export$4] - SpanData{spanContext=ImmutableSpanContext{traceId=3936a1296e9b4d320009deaffa66fdbb, spanId=8a8eb21376ffe535, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=3936a1296e9b4d320009deaffa66fdbb, spanId=1758b3fbed896d1b, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=true, valid=true}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.39.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=default, version=null, schemaUrl=null, attributes={}}, name=sessionqueue.add_to_queue, kind=INTERNAL, startEpochNanos=1719585671335607066, endEpochNanos=1719585971350612266, attributes={}, totalAttributeCount=0, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true}
14:46:11.353 DEBUG [SeleniumSpanExporter$1.lambda$export$4] - SpanData{spanContext=ImmutableSpanContext{traceId=3936a1296e9b4d320009deaffa66fdbb, spanId=1758b3fbed896d1b, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.39.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=default, version=null, schemaUrl=null, attributes={}}, name=session_queue, kind=INTERNAL, startEpochNanos=1719585671319058518, endEpochNanos=1719585971353526540, attributes=AttributesMap{data={http.status_code=500, http.method=POST, random.key=d23419b9-223e-4cad-b4e9-603d59893273, span.kind=server, http.target=/session}, capacity=128, totalAddedValues=5}, totalAttributeCount=5, events=[ImmutableEventData{name=HTTP request execution complete, attributes={http.flavor=1, http.handler_class="org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue", http.host="127.0.0.1:4444", http.method="POST", http.request_content_length="84", http.scheme="HTTP", http.status_code=500, http.target="/session", http.user_agent="selenium/4.0.0a1 (python linux)"}, epochNanos=1719585971353143043, totalAttributeCount=9}], totalRecordedEvents=1, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=ERROR, description=Kind: INTERNAL Description:}, hasEnded=true}
14:46:11.356 WARN [SeleniumSpanExporter$1.lambda$export$3] - {"traceId": "3936a1296e9b4d320009deaffa66fdbb","eventTime": 1719585971353143043,"eventName": "HTTP request execution complete","attributes": {"http.flavor": 1,"http.handler_class": "org.openqa.selenium.grid.sessionqueue.local.LocalNewSessionQueue","http.host": "127.0.0.1:4444","http.method": "POST","http.request_content_length": "84","http.scheme": "HTTP","http.status_code": 500,"http.target": "\u002fsession","http.user_agent": "selenium\u002f4.0.0a1 (python linux)"}}
This issue is looking for contributors.
Please comment below or reach out to us through our IRC/Slack/Matrix channels if you are interested.
What happened?
When server is started with:
"--enable-managed-downloads true"
, you cannot start a firefox session.It works when the grid sees:
So it works so long as
moz:firefoxOptions
is not empty. I've seen this issue before and thought I fixed it. As I recall, the grid is creating a new capabilities object when downloads are enabled, but when firefoxOptions is empty it isn't using it, and then improperly sends the unrecognized capability to geckodriver which then fails (though it should error that it doesn't recognize that capability, so I'm not sure what is going on there).How can we reproduce the issue?
Relevant log output
Operating System
Mac
Selenium version
4.16.1
What are the browser(s) and version(s) where you see this issue?
Firefox 120
What are the browser driver(s) and version(s) where you see this issue?
geckodriver 0.33
Are you using Selenium Grid?
4.16.1