Test discovery fails with ValueError: I/O operation on closed file.

[fleimgruber]

OS: Windows
VS Code: 1.76.0
Python: venv created using Poetry and pyenv-win

Running the relevant test discovery command from CLI (PowerShell 7.2.1):

.\.venv\Scripts\python.exe C:\Users\LeimgruberF\.vscode\extensions\ms-python.python-2023.4.0\pythonFiles\testing_tools\run_adapter.py discover pytest -- --rootdir . -s --cache-clear tests

shows this error:

cwd: .
[ERROR 2023-2-9 17:9:52.58]: Error discovering pytest tests:
 [n [Error]: --- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 332, in _exit_function
    info('process shutting down')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 54, in info
    _logger.log(INFO, msg, *args)
Message: 'process shutting down'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 333, in _exit_function
    debug('running all "atexit" finalizers with priority >= 0')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 50, in debug
    _logger.log(DEBUG, msg, *args)
Message: 'running all "atexit" finalizers with priority >= 0'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 359, in _exit_function
    debug('running the remaining "atexit" finalizers')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 50, in debug
    _logger.log(DEBUG, msg, *args)
Message: 'running the remaining "atexit" finalizers'
Arguments: ()

	at ChildProcess.<anonymous> (c:\Users\LeimgruberF\.vscode\extensions\ms-python.python-2023.4.0\out\client\extension.js:2:244860)
	at Object.onceWrapper (node:events:646:26)
	at ChildProcess.emit (node:events:526:28)
	at maybeClose (node:internal/child_process:1092:16)
	at ChildProcess._handle.onexit (node:internal/child_process:302:5)]

[eleanorjboyd]

Hello! Could you try running pytest discovery in the terminal and see the result?

[fleimgruber]

Hi @eleanorjboyd, thanks for the support.

Could you try running pytest discovery in the terminal and see the result?

I ran the command in the terminal (updated the description to be explicit I ran it in PowerShell), the output is reproducible and the same as above.

Edit: I did not look closely, now I see this output (I inserted the "... (more tests) ..." portion manually):

[{"rootid": ".", "root": "C:\\Users\\LeimgruberF\\dev\\the_project", "parents": [{"id": "./tests", "kind": "folder", "name": "tests", "parentid": ".", "relpath": ".\\tests"}, {"id": "./tests/test_device.py", "kind": "file", "name": "test_device.py", "parentid": "./tests", "relpath": ".\\tests\\test_device.py"}, {"id": "./tests/test_evaluate.py", "kind": "file", "name": "test_evaluate.py", "parentid": "./tests", "relpath": ".\\tests\\test_evaluate.py"}, ... (more tests) ... {"id": "./tests/test_storage_sqlite.py::test_sqlite_file_load", "name": "test_sqlite_file_load", "source": ".\\tests\\test_storage_sqlite.py:53", "markers": [], "parentid": "./tests/test_storage_sqlite.py"}]}]
--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 332, in _exit_function
    info('process shutting down')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 54, in info
    _logger.log(INFO, msg, *args)
Message: 'process shutting down'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 333, in _exit_function
    debug('running all "atexit" finalizers with priority >= 0')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 50, in debug
    _logger.log(DEBUG, msg, *args)
Message: 'running all "atexit" finalizers with priority >= 0'
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\logging\__init__.py", line 1086, in emit
    stream.write(msg + self.terminator)
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\tempfile.py", line 478, in func_wrapper
    return func(*args, **kwargs)
ValueError: I/O operation on closed file.
Call stack:
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 359, in _exit_function
    debug('running the remaining "atexit" finalizers')
  File "C:\Users\LeimgruberF\scoop\apps\pyenv\current\pyenv-win\versions\3.9.12\lib\multiprocessing\util.py", line 50, in debug
    _logger.log(DEBUG, msg, *args)
Message: 'running the remaining "atexit" finalizers'
Arguments: ()

[fleimgruber]

@eleanorjboyd or did you mean to run it in the VS Code terminal? Happy to support in any other way.

[eleanorjboyd]

yes- that would be great. Sorry for the delay!

[fleimgruber]

Getting the same error as in #20826 (comment) from the VS Code terminal (which is a PowerShell).

[eleanorjboyd]

Hi @fleimgruber, if pytest is unable to discover the tests correctly than we cannot parse that output and display it in our UI therefore you should look into getting the pytest error fixed and our discovery will be fix as well. Thanks!

[eleanorjboyd]

closing as this is a pytest error not vscode- please reopen if you think that is not the case.

[fleimgruber]

For reference, this is the related upstream pytest issue: pytest-dev/pytest#5502.

What was causing the error for me was test code that imported from a module that imported a lot of dagster - which apparently does some offending (according to pytest authors) stdio handling at import time. I did not dig further into it, just removed the related tests.