Šarūnas Nejus
c1dc7332b6
Fix logging in tests ( #6853 )
...
## Summary
- Add a CLI logging handler that resolves `sys.stderr` when each log
record is emitted.
- Keep CLI logs attached to the current stderr stream when callers
temporarily replace it for capture or redirection.
- Avoid retaining pytest's closed per-test capture stream across
repeated CLI invocations.
## Problem
The issue is that the first CLI command run under pytest can install a
`StreamHandler` bound to pytest's temporary stderr capture stream.
Pytest later closes that stream, but the global beets logger keeps the
handler around for the next CLI invocation.
This was introduced by #6755 , which removed logging setup as an import
side effect and moved CLI logging bootstrap into command startup.
Before #6755 , the handler was created when `beets.ui` was imported. In
tests, that usually happened before pytest swapped in its per-test
stderr capture stream. After #6755 , the handler is created when
`_raw_main()` runs, which means it can be created while pytest capture
is active.
The important bit is that `logging.StreamHandler()` stores the stream it
sees at creation time. So it ends up holding on to pytest's temporary
stderr stream from the first command. Once pytest closes that stream,
later debug/info logs try to write to a closed file and Python's logging
module prints the huge `--- Logging error ---` blocks.
This keeps the useful part of #6755 - no logging setup as an import side
effect - but avoids retaining whichever stderr stream happened to be
active during the first CLI run.
#### Before
I include the output I'm seeing where I have two failing tests in
`test_convert.py`. See the amount of noise this generates - this also
hides the actual test failures under repeated logging-internal
tracebacks and captured debug logs.
<details>
<summary>very verbose output</summary>
```text
Poe => uv run pytest -p no:cov test/plugins/test_convert.py --lf --maxfail=2
=============================================================================== test session starts ================================================================================
platform linux -- Python 3.10.18, pytest-9.0.3, pluggy-1.6.0
cachedir: /tmp/pytest_cache
rootdir: /home/sarunas/repo/beets
configfile: setup.cfg
plugins: factoryboy-2.8.1, requests-mock-1.12.1, Faker-40.15.0, flask-1.3.0, anyio-4.13.0, xdist-3.8.0
collected 36 items / 15 deselected / 21 selected
run-last-failure: rerun previous 21 failures
test/plugins/test_convert.py FF
===================================================================================== FAILURES =====================================================================================
___________________________________________________________________________ TestConvertCli.test_convert ____________________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7efd27567df0>
def test_convert(self):
self.io.addinput("y")
self.run_convert()
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:127:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7efd27567df0>, path = PosixPath('/tmp/tmpxyo_pvcw/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmpxyo_pvcw/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
Convert? (Y/n)
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
data directory: /tmp/tmpxyo_pvcw
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
data directory: /tmp/tmpxyo_pvcw
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:953 data directory: /tmp/tmpxyo_pvcw
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmpxyo_pvcw/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
________________________________________________________________ TestConvertCli.test_convert_with_auto_confirmation ________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7efd27565f30>
def test_convert_with_auto_confirmation(self):
self.run_convert("--yes")
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:131:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7efd27565f30>, path = PosixPath('/tmp/tmpvslyu88g/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmpvslyu88g/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
------------------------------------------------------------------------------ Captured stderr setup -------------------------------------------------------------------------------
--- Logging error ---
Traceback (most recent call last):
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1103, in emit
stream.write(msg + self.terminator)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/capture.py", line 218, in write
super().write(s)
ValueError: I/O operation on closed file.
Call stack:
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/bin/pytest", line 10, in <module>
sys.exit(console_main())
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/config/__init__.py", line 223, in console_main
...
Another 1200 lines of this stuff
...
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/fixtures.py", line 1202, in pytest_fixture_setup
result = call_fixture_func(fixturefunc, request, kwargs)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/fixtures.py", line 908, in call_fixture_func
fixture_result = next(generator)
File "/home/sarunas/repo/beets/beets/test/helper.py", line 209, in setup
self.setup_beets()
File "/home/sarunas/repo/beets/test/plugins/test_convert.py", line 107, in setup_beets
self.album = self.add_album_fixture(ext="ogg")
File "/home/sarunas/repo/beets/beets/test/helper.py", line 376, in add_album_fixture
return self.lib.add_album(items)
File "/home/sarunas/repo/beets/beets/library/library.py", line 132, in add_album
item.store()
File "/home/sarunas/repo/beets/beets/library/models.py", line 93, in store
plugins.send("database_change", lib=self.db, model=self)
File "/home/sarunas/repo/beets/beets/plugins.py", line 622, in send
log.debug("Sending event: {}", event)
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1465, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/home/sarunas/repo/beets/beets/logging.py", line 163, in _log
return super()._log(
Message: <beets.logging.StrFormatLogger._LogMessage object at 0x7efd271f4310>
Arguments: ()
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
--- Logging error ---
Traceback (most recent call last):
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1103, in emit
stream.write(msg + self.terminator)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/capture.py", line 218, in write
super().write(s)
ValueError: I/O operation on closed file.
Call stack:
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/bin/pytest", line 10, in <module>
sys.exit(console_main())
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/config/__init__.py", line 223, in console_main
code = main()
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/config/__init__.py", line 199, in main
ret: ExitCode | int = config.hook.pytest_cmdline_main(config=config)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/main.py", line 365, in pytest_cmdline_main
...
Another 1000 lines of this stuff
...
return self.ctx.run(func, *args, **kwargs)
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 224, in coro
func(*args, task)
File "/home/sarunas/repo/beets/beetsplug/convert.py", line 515, in convert_item
item.try_write(path=converted, id3v23=id3v23)
File "/home/sarunas/repo/beets/beets/library/models.py", line 988, in try_write
self.write(path=path, tags=tags, id3v23=id3v23)
File "/home/sarunas/repo/beets/beets/library/models.py", line 956, in write
plugins.send("write", item=self, path=path, tags=item_tags)
File "/home/sarunas/repo/beets/beets/plugins.py", line 622, in send
log.debug("Sending event: {}", event)
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1465, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/home/sarunas/repo/beets/beets/logging.py", line 163, in _log
return super()._log(
Message: <beets.logging.StrFormatLogger._LogMessage object at 0x7efd2987b940>
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1103, in emit
stream.write(msg + self.terminator)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/capture.py", line 218, in write
super().write(s)
ValueError: I/O operation on closed file.
Call stack:
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/threading.py", line 973, in _bootstrap
self._bootstrap_inner()
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
self.run()
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 420, in run
self._run_in_context(self.coro.send, msg)
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 263, in _run_in_context
return self.ctx.run(func, *args, **kwargs)
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 224, in coro
func(*args, task)
File "/home/sarunas/repo/beets/beetsplug/convert.py", line 515, in convert_item
item.try_write(path=converted, id3v23=id3v23)
File "/home/sarunas/repo/beets/beets/library/models.py", line 988, in try_write
self.write(path=path, tags=tags, id3v23=id3v23)
File "/home/sarunas/repo/beets/beets/library/models.py", line 974, in write
plugins.send("after_write", item=self, path=path)
File "/home/sarunas/repo/beets/beets/plugins.py", line 622, in send
log.debug("Sending event: {}", event)
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1465, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/home/sarunas/repo/beets/beets/logging.py", line 163, in _log
return super()._log(
Message: <beets.logging.StrFormatLogger._LogMessage object at 0x7efd2987afb0>
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1103, in emit
stream.write(msg + self.terminator)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/capture.py", line 218, in write
super().write(s)
ValueError: I/O operation on closed file.
Call stack:
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/threading.py", line 973, in _bootstrap
self._bootstrap_inner()
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
self.run()
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 420, in run
self._run_in_context(self.coro.send, msg)
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 263, in _run_in_context
return self.ctx.run(func, *args, **kwargs)
File "/home/sarunas/repo/beets/beets/util/pipeline.py", line 224, in coro
func(*args, task)
File "/home/sarunas/repo/beets/beetsplug/convert.py", line 543, in convert_item
plugins.send(
File "/home/sarunas/repo/beets/beets/plugins.py", line 622, in send
log.debug("Sending event: {}", event)
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1465, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/home/sarunas/repo/beets/beets/logging.py", line 163, in _log
return super()._log(
Message: <beets.logging.StrFormatLogger._LogMessage object at 0x7efd2987b8e0>
Arguments: ()
--- Logging error ---
Traceback (most recent call last):
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1103, in emit
stream.write(msg + self.terminator)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/capture.py", line 218, in write
super().write(s)
ValueError: I/O operation on closed file.
Call stack:
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/bin/pytest", line 10, in <module>
sys.exit(console_main())
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/config/__init__.py", line 223, in console_main
code = main()
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/config/__init__.py", line 199, in main
ret: ExitCode | int = config.hook.pytest_cmdline_main(config=config)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/main.py", line 365, in pytest_cmdline_main
return wrap_session(config, _main)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/main.py", line 318, in wrap_session
session.exitstatus = doit(config, session) or 0
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/main.py", line 372, in _main
config.hook.pytest_runtestloop(session=session)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/main.py", line 396, in pytest_runtestloop
item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 118, in pytest_runtest_protocol
runtestprotocol(item, nextitem=nextitem)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 137, in runtestprotocol
reports.append(call_and_report(item, "call", log))
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 244, in call_and_report
call = CallInfo.from_call(
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 353, in from_call
result: TResult | None = func()
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 245, in <lambda>
lambda: runtest_hook(item=item, **kwds),
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/runner.py", line 179, in pytest_runtest_call
item.runtest()
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/python.py", line 1720, in runtest
self.ihook.pytest_pyfunc_call(pyfuncitem=self)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_hooks.py", line 512, in __call__
return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_manager.py", line 120, in _hookexec
return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/pluggy/_callers.py", line 121, in _multicall
res = hook_impl.function(*args)
File "/media/poetry/virtualenvs/beets-yAypcYUQ-py3.10/lib/python3.10/site-packages/_pytest/python.py", line 166, in pytest_pyfunc_call
result = testfunction(**testargs)
File "/home/sarunas/repo/beets/test/plugins/test_convert.py", line 130, in test_convert_with_auto_confirmation
self.run_convert("--yes")
File "/home/sarunas/repo/beets/test/plugins/test_convert.py", line 101, in run_convert
return self.run_convert_path(self.item, *args)
File "/home/sarunas/repo/beets/test/plugins/test_convert.py", line 97, in run_convert_path
return self.run_command("convert", *args, f"path:{item.filepath}")
File "/home/sarunas/repo/beets/beets/test/helper.py", line 152, in run_command
beets.ui._raw_main(list(args))
File "/home/sarunas/repo/beets/beets/ui/__init__.py", line 903, in _raw_main
plugins.send("cli_exit", lib=lib)
File "/home/sarunas/repo/beets/beets/plugins.py", line 622, in send
log.debug("Sending event: {}", event)
File "/home/sarunas/.local/share/uv/python/cpython-3.10.18-linux-x86_64-gnu/lib/python3.10/logging/__init__.py", line 1465, in debug
self._log(DEBUG, msg, args, **kwargs)
File "/home/sarunas/repo/beets/beets/logging.py", line 163, in _log
return super()._log(
Message: <beets.logging.StrFormatLogger._LogMessage object at 0x7efd289904c0>
Arguments: ()
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:953 data directory: /tmp/tmpvslyu88g
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmpvslyu88g/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmpvslyu88g/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
--------------------------------------------------------- generated xml file: /home/sarunas/repo/beets/.reports/pytest.xml ---------------------------------------------------------
============================================================================= short test summary info ==============================================================================
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert - AssertionError: assert False
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert_with_auto_confirmation - AssertionError: assert False
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 2 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
========================================================================= 2 failed, 15 deselected in 1.60s =========================================================================
```
</details>
#### After introducing `_CurrentStderrHandler`
<details>
<summary>the logging noise is gone</summary>
```text
Poe => uv run pytest -p no:cov test/plugins/test_convert.py --lf --maxfail=2
=============================================================================== test session starts ================================================================================
platform linux -- Python 3.10.18, pytest-9.0.3, pluggy-1.6.0
cachedir: /tmp/pytest_cache
rootdir: /home/sarunas/repo/beets
configfile: setup.cfg
plugins: factoryboy-2.8.1, requests-mock-1.12.1, Faker-40.15.0, flask-1.3.0, anyio-4.13.0, xdist-3.8.0
collected 36 items / 15 deselected / 21 selected
run-last-failure: rerun previous 21 failures
test/plugins/test_convert.py FF
===================================================================================== FAILURES =====================================================================================
___________________________________________________________________________ TestConvertCli.test_convert ____________________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7f6dff756c80>
def test_convert(self):
self.io.addinput("y")
self.run_convert()
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:127:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7f6dff756c80>, path = PosixPath('/tmp/tmppey_4nbm/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmppey_4nbm/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
Convert? (Y/n)
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
configuration sources (highest → lowest priority):
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
ConfigSource None
ConfigSource None
YamlSource /tmp/tmppey_4nbm/config.yaml
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
data directory: /tmp/tmppey_4nbm
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
configuration sources (highest → lowest priority):
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
ConfigSource None
ConfigSource None
YamlSource /tmp/tmppey_4nbm/config.yaml
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
data directory: /tmp/tmppey_4nbm
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:43 configuration sources (highest → lowest priority):
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 YamlSource /tmp/tmppey_4nbm/config.yaml
DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
DEBUG beets:__init__.py:974 data directory: /tmp/tmppey_4nbm
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmppey_4nbm/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
________________________________________________________________ TestConvertCli.test_convert_with_auto_confirmation ________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7f6dff756500>
def test_convert_with_auto_confirmation(self):
self.run_convert("--yes")
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:131:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7f6dff756500>, path = PosixPath('/tmp/tmpb2tryk4g/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmpb2tryk4g/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
------------------------------------------------------------------------------ Captured stderr setup -------------------------------------------------------------------------------
plugin paths: []
Loading plugins: convert
Sending event: pluginload
Sending event: database_change
Parsed query: AndQuery([NoneQuery('album_id', True)])
Parsed sort: NullSort()
Sending event: item_copied
Sending event: database_change
Sending event: database_change
Sending event: database_change
Sending event: database_change
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
configuration sources (highest → lowest priority):
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
ConfigSource None
ConfigSource None
YamlSource /tmp/tmpb2tryk4g/config.yaml
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
data directory: /tmp/tmpb2tryk4g
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
configuration sources (highest → lowest priority):
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
ConfigSource None
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
ConfigSource None
ConfigSource None
YamlSource /tmp/tmpb2tryk4g/config.yaml
YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
data directory: /tmp/tmpb2tryk4g
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:43 configuration sources (highest → lowest priority):
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 ConfigSource None
DEBUG beets:__init__.py:46 YamlSource /tmp/tmpb2tryk4g/config.yaml
DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
DEBUG beets:__init__.py:974 data directory: /tmp/tmpb2tryk4g
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmpb2tryk4g/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
--------------------------------------------------------- generated xml file: /home/sarunas/repo/beets/.reports/pytest.xml ---------------------------------------------------------
============================================================================= short test summary info ==============================================================================
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert - AssertionError: assert False
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert_with_auto_confirmation - AssertionError: assert False
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 2 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
========================================================================= 2 failed, 15 deselected in 1.52s =========================================================================
```
</details>
#### After mocking `IncludeLazyConfig.log_sources` in tests
<details>
<summary>even less noise</summary>
```text
Poe => uv run pytest -p no:cov test/plugins/test_convert.py --lf --maxfail=2
=============================================================================== test session starts ================================================================================
platform linux -- Python 3.10.18, pytest-9.0.3, pluggy-1.6.0
cachedir: /tmp/pytest_cache
rootdir: /home/sarunas/repo/beets
configfile: setup.cfg
plugins: factoryboy-2.8.1, requests-mock-1.12.1, Faker-40.15.0, flask-1.3.0, anyio-4.13.0, xdist-3.8.0
collected 36 items / 15 deselected / 21 selected
run-last-failure: rerun previous 21 failures
test/plugins/test_convert.py FF
===================================================================================== FAILURES =====================================================================================
___________________________________________________________________________ TestConvertCli.test_convert ____________________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7f5333c5e770>
def test_convert(self):
self.io.addinput("y")
self.run_convert()
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:127:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7f5333c5e770>, path = PosixPath('/tmp/tmplqi7o6lz/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmplqi7o6lz/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
Convert? (Y/n)
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
data directory: /tmp/tmplqi7o6lz
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
data directory: /tmp/tmplqi7o6lz
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:973 data directory: /tmp/tmplqi7o6lz
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmplqi7o6lz/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
________________________________________________________________ TestConvertCli.test_convert_with_auto_confirmation ________________________________________________________________
self = <test.plugins.test_convert.TestConvertCli object at 0x7f5333c5ebf0>
def test_convert_with_auto_confirmation(self):
self.run_convert("--yes")
> assert self.file_endswith(self.converted_mp3, "mp3")
test/plugins/test_convert.py:131:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
self = <test.plugins.test_convert.TestConvertCli object at 0x7f5333c5ebf0>, path = PosixPath('/tmp/tmpza4w_qqk/convert_dest/converted.mp3'), tag = 'mp3'
def file_endswith(self, path: Path, tag: str):
"""Check the path is a file and if its content ends with `tag`."""
> assert path.exists()
E AssertionError: assert False
E + where False = exists()
E + where exists = PosixPath('/tmp/tmpza4w_qqk/convert_dest/converted.mp3').exists
test/plugins/test_convert.py:48: AssertionError
------------------------------------------------------------------------------ Captured stderr setup -------------------------------------------------------------------------------
plugin paths: []
Loading plugins: convert
Sending event: pluginload
Sending event: database_change
Parsed query: AndQuery([NoneQuery('album_id', True)])
Parsed sort: NullSort()
Sending event: item_copied
Sending event: database_change
Sending event: database_change
Sending event: database_change
Sending event: database_change
-------------------------------------------------------------------------------- Captured log setup --------------------------------------------------------------------------------
DEBUG beets:plugins.py:376 plugin paths: []
DEBUG beets:plugins.py:458 Loading plugins: convert
DEBUG beets:plugins.py:622 Sending event: pluginload
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:queries.py:50 Parsed query: AndQuery([NoneQuery('album_id', True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
DEBUG beets:plugins.py:622 Sending event: item_copied
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
DEBUG beets:plugins.py:622 Sending event: database_change
------------------------------------------------------------------------------- Captured stdout call -------------------------------------------------------------------------------
the artist - älbum - tïtle 0
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
data directory: /tmp/tmpza4w_qqk
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
data directory: /tmp/tmpza4w_qqk
Sending event: library_opened
Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
Parsed sort: NullSort()
convert: Encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
convert: Finished encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
Sending event: write
Sending event: after_write
Sending event: after_convert
Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
DEBUG beets:__init__.py:973 data directory: /tmp/tmpza4w_qqk
DEBUG beets:plugins.py:622 Sending event: library_opened
DEBUG beets:queries.py:50 Parsed query: AndQuery([PathQuery('path', b'Non-Album/the artist/t\xc3\xaftle 0.ogg', fast=True, case_sensitive=True)])
DEBUG beets:queries.py:51 Parsed sort: NullSort()
INFO beets.convert:convert.py:318 Encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
INFO beets.convert:convert.py:354 Finished encoding /tmp/tmpza4w_qqk/libdir/Non-Album/the artist/tïtle 0.ogg
DEBUG beets:plugins.py:622 Sending event: write
DEBUG beets:plugins.py:622 Sending event: after_write
DEBUG beets:plugins.py:622 Sending event: after_convert
DEBUG beets:plugins.py:622 Sending event: cli_exit
--------------------------------------------------------- generated xml file: /home/sarunas/repo/beets/.reports/pytest.xml ---------------------------------------------------------
============================================================================= short test summary info ==============================================================================
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert - AssertionError: assert False
FAILED test/plugins/test_convert.py::TestConvertCli::test_convert_with_auto_confirmation - AssertionError: assert False
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! stopping after 2 failures !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
========================================================================= 2 failed, 15 deselected in 1.54s =========================================================================
```
</details>
<details>
<summary>last commit diff</summary>
```diff
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
-configuration sources (highest → lowest priority):
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-ConfigSource None
-ConfigSource None
-YamlSource /tmp/tmppey_4nbm/config.yaml
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
Sending event: write
@@ -75,18 +61,3 @@ Sending event: after_convert
Sending event: cli_exit
-configuration sources (highest → lowest priority):
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-ConfigSource None
-ConfigSource None
-YamlSource /tmp/tmppey_4nbm/config.yaml
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
@@ -101,18 +72,3 @@ Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
-DEBUG beets:__init__.py:43 configuration sources (highest → lowest priority):
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 YamlSource /tmp/tmppey_4nbm/config.yaml
-DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
------------------------------------------------------------------------------- Captured stderr call -------------------------------------------------------------------------------
-configuration sources (highest → lowest priority):
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-ConfigSource None
-ConfigSource None
-YamlSource /tmp/tmpb2tryk4g/config.yaml
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
@@ -199,18 +140,3 @@ Sending event: after_convert
Sending event: cli_exit
-configuration sources (highest → lowest priority):
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-ConfigSource None
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-ConfigSource None
-ConfigSource None
-YamlSource /tmp/tmpb2tryk4g/config.yaml
-YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
@@ -225,18 +151,3 @@ Sending event: cli_exit
-------------------------------------------------------------------------------- Captured log call ---------------------------------------------------------------------------------
-DEBUG beets:__init__.py:43 configuration sources (highest → lowest priority):
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 ConfigSource None
-DEBUG beets:__init__.py:46 YamlSource /tmp/tmpb2tryk4g/config.yaml
-DEBUG beets:__init__.py:46 YamlSource /home/sarunas/repo/beets/beets/config_default.yaml
```
</details>
2026-07-21 11:15:03 +01:00
Šarūnas Nejus
2cf20aa60c
discogs: refactor _coalesce_tracks around more specific track types ( #6818 )
...
- `beetsplug/discogs/types.py` now models Discogs tracklist entries as
distinct shapes: `AudioTrack`, `IndexTrack`, and `HeadingTrack`. This
shifts the plugin from "guessing by `position`" to handling each entry
by its declared `type_`.
- `beetsplug/discogs/__init__.py` refactors `_coalesce_tracks()` into
smaller helpers for flat subtracks and index tracks. The normalization
flow is now type-driven, which makes the rules for "one physical track"
vs "many physical tracks" more explicit.
- `beetsplug/discogs/states.py` now advances track state only for real
audio entries (`type_ == "track"`), so structural entries no longer
affect track counting through indirect `position` checks.
- Tests now use dedicated Discogs track factories and add coverage for
logical index tracks. This gives the refactor a clearer test model and
protects the new coalescing behavior.
- High-level impact: Discogs imports should now treat headings, index
containers, and subtracks more consistently, especially for releases
where one displayed work contains multiple logical parts but maps to a
single playable track.
### This change is based on the following research (thanks, Codex!):
# Discogs track coalescing
`DiscogsPlugin._coalesce_tracks()` handles three distinct notions all
called
"subtracks." This is the main source of its complexity.
Discogs distinguishes:
- `track`: an audio entry.
- `index`: a titled container whose `sub_tracks` are parts or movements.
- `heading`: descriptive text applying to following tracks.
That distinction is documented in the current
[Discogs tracklisting
guidelines](https://support.discogs.com/hc/en-us/articles/360005055373-Database-Guidelines-12-Tracklisting ).
Positions such as `3.1`, `3.2` or `3a`, `3b` separately indicate
multiple
musical pieces inside one physical track.
## Observed input shapes
| Case | API shape | Current result | Example |
|---|---|---|---|
| Normal track | `type_="track"`, nonempty position | Passed through |
Most releases |
| Flat virtual subtracks | Multiple top-level `track` entries with
`1.1`, `1.2` or `22a`, `22b` | Merged into a copy of the first track |
[This Is Not](https://www.discogs.com/release/7117597 ), [Eclectic Beatz
8](https://www.discogs.com/release/2885582 ) |
| Nested logical subtracks | `index` with nested children sharing one
physical position | Parent index becomes the physical track; children
discarded | [Defqon.1 Weekend
Festival](https://www.discogs.com/release/7168134 ) |
| Nested physical subtracks | `index` with children numbered as
independent tracks | Index discarded; children promoted | [Classical
Hollywood III](https://www.discogs.com/release/3647530 ) |
| Heading | `heading`, empty position, no `sub_tracks` | Passed through
as structural metadata | Defqon.1 CD headings |
| Ambiguous/nonstandard index | `index` with positions the regex cannot
classify | Usually promoted incorrectly as separate tracks | [King
Crimson - Lizard](https://www.discogs.com/release/1156598 ) |
### Flat virtual subtracks
`This Is Not` returns nine top-level entries:
```python
{"type_": "track", "position": "1.1", "title": "Intro", "duration": "1:49"}
{"type_": "track", "position": "1.2", "title": "Untitled", "duration": "6:31"}
# ...
{"type_": "track", "position": "1.9", "title": "2 Bad ...", "duration": "10:18"}
```
There is no index container. `_coalesce_tracks()` detects the suffixes
and
`_add_merged_subtracks()` produces:
```python
{
"type_": "track",
"position": "1.1",
"title": "Intro / Untitled / ... / 2 Bad ...",
"duration": "1:49",
"artists": ["Unknown Artist"],
}
```
It copies all metadata from the first entry and only combines titles.
This
explains the incorrect duration and artist.
`Eclectic Beatz 8` has the same flat shape:
```python
{"type_": "track", "position": "22a", "title": "Amplifier", "artists": ["Fedde Le Grand"]}
{"type_": "track", "position": "22b", "title": "Autograph ...", "artists": ["Hatiras", "MC Flipside"]}
```
Those become one track, retaining only the first artist.
### Nested logical subtracks
Defqon.1 contains:
```python
{
"type_": "index",
"position": "",
"title": "Eat This / God! What The Hell!",
"duration": "3:06",
"sub_tracks": [
{"type_": "track", "position": "2-20A", "title": "Eat This"},
{"type_": "track", "position": "2-20B", "title": "God! What The Hell!"},
],
}
```
Because `2-20A` has a parsed subindex, the helper changes the parent to:
```python
{
"type_": "index",
"position": "2-20",
"title": "Eat This / God! What The Hell!",
"duration": "3:06",
}
```
The children disappear. Downstream code treats this as audio solely
because
its position is now nonempty. It never checks that `type_` remains
`"index"`.
### Nested physical subtracks
`Classical Hollywood III` contains index containers such as:
```python
{
"type_": "index",
"position": "",
"title": "Auld Lang Syne Variations For Piano Quartet",
"sub_tracks": [
{"type_": "track", "position": "1", "title": "Eine Kleine Nichtmusik ..."},
{"type_": "track", "position": "2", "title": "L.V.B. - Adagio"},
{"type_": "track", "position": "3", "title": "Chaconne ..."},
{"type_": "track", "position": "4", "title": "Homage ..."},
],
}
```
Because position `1` has no subindex:
- the index container is removed;
- its children become top-level physical tracks;
- parent artists are copied to children missing artists;
- when `index_tracks` is enabled, the parent title prefixes every child
title.
This behavior was added for
[issue #2318 ](https://github.com/beetbox/beets/issues/2318 ) by
[PR #2355 ](https://github.com/beetbox/beets/pull/2355 ).
### Headings
Defqon.1 also contains:
```python
{
"type_": "heading",
"position": "",
"title": "CD2 ⚡ Mixed By Partyraiser",
"duration": "",
}
```
This is not coalesced. It passes through, but `TracklistState`
subsequently
treats every positionless object as structural metadata without checking
`type_`.
The code therefore cannot distinguish:
```python
position == "" and type_ == "heading"
position == "" and type_ == "index"
```
Worse, `_add_merged_subtracks()` identifies a parent using only:
```python
tracklist and not tracklist[-1]["position"]
```
A heading can therefore theoretically be mistaken for an index parent.
## History
- [Issue #1543 ](https://github.com/beetbox/beets/issues/1543 ) reported
flat
positions such as `22a` and `22b` representing one CD track.
- [PR #2222 ](https://github.com/beetbox/beets/pull/2222 ) added both flat
and
nested subtrack support. Its author explicitly noted that `type_` might
identify index tracks robustly, but avoided the larger refactor.
- [Issue #2318 ](https://github.com/beetbox/beets/issues/2318 )
demonstrated that
nested `sub_tracks` can instead be independent physical tracks.
- PR #2355 added the current heuristic:
- parsed child subindex means logical fragments of one physical track;
- no parsed child subindex means independent physical tracks.
- That PR documented the heuristic as imperfect. `Lizard`, with `Ba`,
`Bb`,
`Bc`, and related positions, was already a known failure.
## Test data does not match the API shapes
The current test helper always creates:
```python
"type_": "track"
```
Consequently, test inputs such as:
```python
_track("TRACK GROUP TITLE", sub_tracks=[...])
```
are not realistic. Real API data uses:
```python
"type_": "index"
```
Likewise, test medium titles are manufactured as positionless `track`
objects
rather than `heading` or `index` objects.
## Recommended direction
Before refactoring production code, introduce accurate input types and
factories:
```python
TrackEntry = AudioTrack | IndexTrack | HeadingTrack
```
With approximate shapes:
```python
class AudioTrack(TypedDict):
type_: Literal["track"]
position: str
title: str
duration: str
artists: NotRequired[list[Artist]]
class IndexTrack(TypedDict):
type_: Literal["index"]
position: Literal[""]
title: str
duration: str
sub_tracks: list[AudioTrack]
artists: NotRequired[list[Artist]]
class HeadingTrack(TypedDict):
type_: Literal["heading"]
position: Literal[""]
title: str
duration: str
```
Then test using `_track()`, `_index()`, and `_heading()` factories.
The eventual normalization can dispatch structurally:
1. `track` without subindex: pass through.
2. Flat subindexed `track` group: apply the flat-fragment policy.
3. `index`: normalize its children as logical or physical.
4. `heading`: preserve as structural metadata.
5. Never infer an index merely from `position == ""`.
This removes the most dangerous ambiguity while preserving the
positional
heuristic where Discogs genuinely requires it.
2026-07-16 12:02:00 +01:00
