Summary
Used as a Sphinx extension, the analyse/ layer writes routine progress — Source files loaded: N, Source comments extracted: N, Oneline needs extracted: N — to stderr at INFO level, through a logging.StreamHandler the library installs on its own loggers at import time. Because the messages are on stderr, wrappers that colorize stderr (tox, many CI log viewers) render these harmless INFO lines red, where they read as errors — although the build succeeds (exit 0) and they are not warnings.
Environment
- sphinx-codelinks 1.2.0; Sphinx 8.2.3; Python 3.12
- Surfaced via tox 4.48.1, which renders subprocess stderr in red
Repro
Any project using sphinx_codelinks as an extension:
sphinx-build -b html -c docs docs/source /tmp/out 1>/tmp/out.log 2>/tmp/err.log
grep -nE "Source files loaded|comments extracted|Oneline needs extracted" /tmp/err.log
The lines appear only in the stderr capture; 2>/dev/null makes them vanish. Exit code is 0.
Root cause
Each analyse/ module configures logging and adds a handler at import scope:
# analyse/analyse.py:31-36 (same shape in utils.py:35-40, oneline_parser.py:8-13, projects.py:14-19)
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)
console = logging.StreamHandler() # no stream arg -> defaults to sys.stderr
console.setLevel(logging.INFO)
logger.addHandler(console)
Routine progress is then emitted at INFO (analyse.py:113-114, 359).
- Libraries shouldn't install handlers on their loggers. Per the stdlib logging guidance, a library should only
getLogger(__name__) and emit; configuring handlers/levels/streams is the application's job. An import-time StreamHandler removes that choice from consumers and can't be undone without reaching into the library's logger.
- Routine progress goes to stderr.
StreamHandler() defaults to sys.stderr, so informational output lands on the error stream and gets reddened by stderr-aware wrappers.
The Sphinx-extension submodules already do the right thing — sphinx_extension/source_tracing.py and sphinx_extension/directives/src_trace.py use from sphinx.util import logging, routing through Sphinx's logging (verbosity, suppress_warnings, color, stream routing). The analyse/ layer is inconsistent with that.
Suggested fix
- Drop the import-time
StreamHandler() + setLevel() + addHandler() from analyse/analyse.py, analyse/utils.py, analyse/oneline_parser.py, analyse/projects.py; keep only logger = logging.getLogger(__name__).
- As a Sphinx extension, route progress through
sphinx.util.logging (consistent with sphinx_extension/*). For the standalone CLI, send progress to stdout (or gate behind --verbose), reserving stderr for warnings/errors.
Related to #21 (separating CLI vs Sphinx-extension concerns).
Extra note (not a sphinx-codelinks bug)
With the furo theme these lines appear doubled — once bare, once as # <ts> INFO sphinx_codelinks.analyse.analyse analyse.py:113 -- .... The second copy comes from accessible-pygments, which calls logging.basicConfig() on the root logger at import; codelinks records propagate to it. That's a separate upstream issue, but it compounds the noise — and disappears once codelinks stops emitting INFO to stderr (or sets propagate=False).
Summary
Used as a Sphinx extension, the
analyse/layer writes routine progress —Source files loaded: N,Source comments extracted: N,Oneline needs extracted: N— to stderr at INFO level, through alogging.StreamHandlerthe library installs on its own loggers at import time. Because the messages are on stderr, wrappers that colorize stderr (tox, many CI log viewers) render these harmless INFO lines red, where they read as errors — although the build succeeds (exit 0) and they are not warnings.Environment
Repro
Any project using
sphinx_codelinksas an extension:The lines appear only in the stderr capture;
2>/dev/nullmakes them vanish. Exit code is 0.Root cause
Each
analyse/module configures logging and adds a handler at import scope:Routine progress is then emitted at INFO (
analyse.py:113-114, 359).getLogger(__name__)and emit; configuring handlers/levels/streams is the application's job. An import-timeStreamHandlerremoves that choice from consumers and can't be undone without reaching into the library's logger.StreamHandler()defaults tosys.stderr, so informational output lands on the error stream and gets reddened by stderr-aware wrappers.The Sphinx-extension submodules already do the right thing —
sphinx_extension/source_tracing.pyandsphinx_extension/directives/src_trace.pyusefrom sphinx.util import logging, routing through Sphinx's logging (verbosity,suppress_warnings, color, stream routing). Theanalyse/layer is inconsistent with that.Suggested fix
StreamHandler()+setLevel()+addHandler()fromanalyse/analyse.py,analyse/utils.py,analyse/oneline_parser.py,analyse/projects.py; keep onlylogger = logging.getLogger(__name__).sphinx.util.logging(consistent withsphinx_extension/*). For the standalone CLI, send progress to stdout (or gate behind--verbose), reserving stderr for warnings/errors.Related to #21 (separating CLI vs Sphinx-extension concerns).
Extra note (not a sphinx-codelinks bug)
With the furo theme these lines appear doubled — once bare, once as
# <ts> INFO sphinx_codelinks.analyse.analyse analyse.py:113 -- .... The second copy comes fromaccessible-pygments, which callslogging.basicConfig()on the root logger at import; codelinks records propagate to it. That's a separate upstream issue, but it compounds the noise — and disappears once codelinks stops emitting INFO to stderr (or setspropagate=False).