[🐛 Bug]: [py] Service logging to console not working correctly

[cgoldberg]

Description

(sorry for the vague title. I'll rename it once I figure out what is happening)

Something weird is going on when I enable logging to the console in the Service class.

The following code should work properly. It is creating a driver instance with logging to sys.stdout enabled in the Service class. After instantiating the driver, it quits, and then creates another driver instance. This 2nd driver instance is totally unrelated to the first one, except for the fact that they both log to sys.stdout. This should work because driver.quit() closes the sys.stdout file descriptor, so there should be no issue re-using it in the next instance:

import sys
from selenium import webdriver
from selenium.webdriver.chrome.service import Service

service = Service(log_output=sys.stdout)
driver = webdriver.Chrome(service=service)
driver.quit()
service2 = Service(log_output=sys.stdout)
driver2 = webdriver.Chrome(service=service2)

When I run this, I get:

Starting ChromeDriver 135.0.7049.84 (6c019e56001911b3fd467e03bf68c435924d62f4-refs/branch-heads/7049@{#1778}) on port 52771
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
ChromeDriver was started successfully on port 52771.
Traceback (most recent call last):
  File "/home/cgoldberg617/code/selenium/py/sel.py", line 97, in <module>
    driver2 = webdriver.Chrome(service=service2)
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/chrome/webdriver.py", line 45, in __init__
    super().__init__(
    ~~~~~~~~~~~~~~~~^
        browser_name=DesiredCapabilities.CHROME["browserName"],
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<3 lines>...
        keep_alive=keep_alive,
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/chromium/webdriver.py", line 55, in __init__
    self.service.start()
    ~~~~~~~~~~~~~~~~~~^^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/common/service.py", line 109, in start
    self._start_process(self._path)
    ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/common/service.py", line 220, in _start_process
    self.process = subprocess.Popen(
                   ~~~~~~~~~~~~~~~~^
        cmd,
        ^^^^
    ...<7 lines>...
        **self.popen_kw,
        ^^^^^^^^^^^^^^^^
    )
    ^
  File "/home/cgoldberg617/.pyenv/versions/3.13.2/lib/python3.13/subprocess.py", line 1004, in __init__
    errread, errwrite) = self._get_handles(stdin, stdout, stderr)
                         ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/cgoldberg617/.pyenv/versions/3.13.2/lib/python3.13/subprocess.py", line 1740, in _get_handles
    c2pwrite = stdout.fileno()
ValueError: I/O operation on closed file

It's not a race condition, because I tried adding a long sleep before instantiating the 2nd driver and I still get the same error.

This same error occurs with all other browsers besides Chrome, so it's not browser related.

What is going ON??

Reproducible Code

import sys
from selenium import webdriver
from selenium.webdriver.chrome.service import Service

service = Service(log_output=sys.stdout)
driver = webdriver.Chrome(service=service)
driver.quit()
service2 = Service(log_output=sys.stdout)
driver2 = webdriver.Chrome(service=service2)

Debugging Logs

DEBUG:selenium.webdriver.common.selenium_manager:Selenium Manager binary found at: /home/cgoldberg617/code/selenium/py/selenium/webdriver/common/linux/selenium-manager
DEBUG:selenium.webdriver.common.selenium_manager:Executing process: /home/cgoldberg617/code/selenium/py/selenium/webdriver/common/linux/selenium-manager --browser chrome --debug --language-binding python --output json
DEBUG:selenium.webdriver.common.selenium_manager:chromedriver not found in PATH
DEBUG:selenium.webdriver.common.selenium_manager:chrome not found in PATH
DEBUG:selenium.webdriver.common.selenium_manager:chrome not found in the system
DEBUG:selenium.webdriver.common.selenium_manager:Required browser: chrome 135.0.7049.84
DEBUG:selenium.webdriver.common.selenium_manager:chrome 135.0.7049.84 already exists
DEBUG:selenium.webdriver.common.selenium_manager:chrome 135.0.7049.84 is available at /home/cgoldberg617/.cache/selenium/chrome/linux64/135.0.7049.84/chrome
DEBUG:selenium.webdriver.common.selenium_manager:Required driver: chromedriver 135.0.7049.84
DEBUG:selenium.webdriver.common.selenium_manager:chromedriver 135.0.7049.84 already in the cache
DEBUG:selenium.webdriver.common.selenium_manager:Driver path: /home/cgoldberg617/.cache/selenium/chromedriver/linux64/135.0.7049.84/chromedriver
DEBUG:selenium.webdriver.common.selenium_manager:Browser path: /home/cgoldberg617/.cache/selenium/chrome/linux64/135.0.7049.84/chrome
DEBUG:selenium.webdriver.common.service:Started executable: `/home/cgoldberg617/.cache/selenium/chromedriver/linux64/135.0.7049.84/chromedriver` in a child process with pid: 32003 using 0 to output <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
Starting ChromeDriver 135.0.7049.84 (6c019e56001911b3fd467e03bf68c435924d62f4-refs/branch-heads/7049@{#1778}) on port 53461
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
ChromeDriver was started successfully on port 53461.
DEBUG:selenium.webdriver.remote.remote_connection:POST http://localhost:53461/session {'capabilities': {'firstMatch': [{}], 'alwaysMatch': {'browserName': 'chrome', 'pageLoadStrategy': <PageLoadStrategy.normal: 'normal'>, 'browserVersion': None, 'goog:chromeOptions': {'extensions': [], 'binary': '/home/cgoldberg617/.cache/selenium/chrome/linux64/135.0.7049.84/chrome', 'args': []}}}}
DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): localhost:53461
DEBUG:urllib3.connectionpool:http://localhost:53461 "POST /session HTTP/1.1" 200 0
DEBUG:selenium.webdriver.remote.remote_connection:Remote response: status=200 | data={"value":{"capabilities":{"acceptInsecureCerts":false,"browserName":"chrome","browserVersion":"135.0.7049.84","chrome":{"chromedriverVersion":"135.0.7049.84 (6c019e56001911b3fd467e03bf68c435924d62f4-refs/branch-heads/7049@{#1778})","userDataDir":"/tmp/.org.chromium.Chromium.reJVS7"},"fedcm:accounts":true,"goog:chromeOptions":{"debuggerAddress":"localhost:35293"},"networkConnectionEnabled":false,"pageLoadStrategy":"normal","platformName":"linux","proxy":{},"setWindowRect":true,"strictFileInteractability":false,"timeouts":{"implicit":0,"pageLoad":300000,"script":30000},"unhandledPromptBehavior":"dismiss and notify","webauthn:extension:credBlob":true,"webauthn:extension:largeBlob":true,"webauthn:extension:minPinLength":true,"webauthn:extension:prf":true,"webauthn:virtualAuthenticators":true},"sessionId":"fb374a498572f448b21fc696f5aab487"}} | headers=HTTPHeaderDict({'Content-Length': '848', 'Content-Type': 'application/json; charset=utf-8', 'cache-control': 'no-cache'})
DEBUG:selenium.webdriver.remote.remote_connection:Finished Request
DEBUG:selenium.webdriver.remote.remote_connection:DELETE http://localhost:53461/session/fb374a498572f448b21fc696f5aab487 {}
DEBUG:urllib3.connectionpool:http://localhost:53461 "DELETE /session/fb374a498572f448b21fc696f5aab487 HTTP/1.1" 200 0
DEBUG:selenium.webdriver.remote.remote_connection:Remote response: status=200 | data={"value":null} | headers=HTTPHeaderDict({'Content-Length': '14', 'Content-Type': 'application/json; charset=utf-8', 'cache-control': 'no-cache'})
DEBUG:selenium.webdriver.remote.remote_connection:Finished Request
DEBUG:selenium.webdriver.common.selenium_manager:Selenium Manager binary found at: /home/cgoldberg617/code/selenium/py/selenium/webdriver/common/linux/selenium-manager
DEBUG:selenium.webdriver.common.selenium_manager:Executing process: /home/cgoldberg617/code/selenium/py/selenium/webdriver/common/linux/selenium-manager --browser chrome --debug --language-binding python --output json
DEBUG:selenium.webdriver.common.selenium_manager:chromedriver not found in PATH
DEBUG:selenium.webdriver.common.selenium_manager:chrome not found in PATH
DEBUG:selenium.webdriver.common.selenium_manager:chrome not found in the system
DEBUG:selenium.webdriver.common.selenium_manager:Required browser: chrome 135.0.7049.84
DEBUG:selenium.webdriver.common.selenium_manager:chrome 135.0.7049.84 already exists
DEBUG:selenium.webdriver.common.selenium_manager:chrome 135.0.7049.84 is available at /home/cgoldberg617/.cache/selenium/chrome/linux64/135.0.7049.84/chrome
DEBUG:selenium.webdriver.common.selenium_manager:Required driver: chromedriver 135.0.7049.84
DEBUG:selenium.webdriver.common.selenium_manager:chromedriver 135.0.7049.84 already in the cache
DEBUG:selenium.webdriver.common.selenium_manager:Driver path: /home/cgoldberg617/.cache/selenium/chromedriver/linux64/135.0.7049.84/chromedriver
DEBUG:selenium.webdriver.common.selenium_manager:Browser path: /home/cgoldberg617/.cache/selenium/chrome/linux64/135.0.7049.84/chrome
Traceback (most recent call last):
  File "/home/cgoldberg617/code/selenium/py/sel.py", line 97, in <module>
    driver2 = webdriver.Chrome(service=service2)
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/chrome/webdriver.py", line 45, in __init__
    super().__init__(
    ~~~~~~~~~~~~~~~~^
        browser_name=DesiredCapabilities.CHROME["browserName"],
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ...<3 lines>...
        keep_alive=keep_alive,
        ^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/chromium/webdriver.py", line 55, in __init__
    self.service.start()
    ~~~~~~~~~~~~~~~~~~^^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/common/service.py", line 109, in start
    self._start_process(self._path)
    ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
  File "/home/cgoldberg617/code/selenium/py/selenium/webdriver/common/service.py", line 220, in _start_process
    self.process = subprocess.Popen(
                   ~~~~~~~~~~~~~~~~^
        cmd,
        ^^^^
    ...<7 lines>...
        **self.popen_kw,
        ^^^^^^^^^^^^^^^^
    )
    ^
  File "/home/cgoldberg617/.pyenv/versions/3.13.2/lib/python3.13/subprocess.py", line 1004, in __init__
    errread, errwrite) = self._get_handles(stdin, stdout, stderr)
                         ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/cgoldberg617/.pyenv/versions/3.13.2/lib/python3.13/subprocess.py", line 1740, in _get_handles
    c2pwrite = stdout.fileno()
ValueError: I/O operation on closed file

[selenium-ci]

@cgoldberg, thank you for creating this issue. We will troubleshoot it as soon as we can.

Selenium Triage Team: remember to follow the Triage Guide

[titusfortner]

I think the code assumes: subprocess.STDOUT

[titusfortner]

If that's true, then we need to update the code to support both.

[cgoldberg]

You're right, it works with subprocess.STDOUT. It would make sense to allow sys.stdout also. I'll take a look at the code and try to fix it.

I'll also add something to the documentation, because there is no example of how to get it to log to the console instead of a file.

[titusfortner]

It should log to console by default?

[selenium-ci]

This issue is looking for contributors.

Please comment below or reach out to us through our IRC/Slack/Matrix channels if you are interested.

[cgoldberg]

It doesn't log anywhere by default... to get driver logs you have create the Service class with a log_output parameter and specify where it's going.

That doesn't seem right .. it should follow the same logging configuration as everything else. But right now if I enable logging for everything else, I won't get driver logs unless I explicitly enable them.

I don't think it always worked like this.

[titusfortner]

I added driver logging functionality to all the languages that didn't have them a couple years ago.
Ruby turns on driver logging when the log level is set to debug. Can we do the same in Python and just toggle it based on logging.getLogger('selenium').getEffectiveLevel() == 10?