Make log level configurable in the settings

reinout commented 7 months ago

What's the problem this feature will solve?

At our company we have quite some non-programmer programmers. I am tidying up their projects. Tox helps a lot to bring order into chaos as it makes it easy to configure the proper test setup, linters, etcetera. But... the default output can be "scary". Especially all the packaging-related lines like .pkg-cpython311: install_requires_for_build_editable> python -I -m pip install wheel. It makes it harder to see the actual linter and test output:

Using -q helps a lot. But I don't really want to add -q everywhere in my documentation. The goal of tox for me is to hide all the options (to coverage/pytest/etc) in tox.ini :-)

Describe the solution you'd like

I'd like to configure the verbosity in the tox.ini config file so that I can pre-configure a nice out-of-the-box experience.

I've managed to configure pytest/ruff/pre-commit/coverage in various config files, tox' verbosity setting is the only one I need that I can't configure. (Or I have overlooked something).

Alternative Solutions

I did some print() debugging to figure out which log levels were used and whether I had some weird setting or env variable somewhere: no.

What I did discover was that the "offending" log messages are logged at the "info" level. I wonder especially whether those logs for the .pkg environment really should be logged at the "info" level? The info-level logging of the command is fine with me: py312: commands[0]> pytest, I don't need -q for that. But .pkg: get_requires_for_build_editable> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ bugs me a bit.

So an alternative would be to lower the log level of the .pkg logging. I couldn't figure out though where those log messages were being generated. None of the pyproject_api/*.py files has an import logging as far as I was able to find.

Additional context

Tox version 4.12.1, nicely isolated with pipx, btw.

Here's the full log of my tox run (without -q) with a "lint" and "py312" action:

$ tox
lint: commands[0]> pre-commit run -a
trim trailing whitespace.................................................Passed
fix end of files.........................................................Passed
check yaml...............................................................Passed
check toml...............................................................Passed
check for added large files..............................................Passed
ruff.....................................................................Passed
ruff-format..............................................................Passed
lint: OK ✔ in 0.51 seconds
.pkg: _optional_hooks> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
.pkg: get_requires_for_build_editable> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
.pkg: build_editable> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
py312: install_package> python -I -m pip install --force-reinstall --no-deps /Users/reinout/nens/nens-meta/.tox/.tmp/package/158/nens_meta-0.1.dev0-0.editable-py3-none-any.whl
py312: commands[0]> pytest
================================ test session starts ================================
platform darwin -- Python 3.12.1, pytest-8.0.0, pluggy-1.4.0
cachedir: .tox/py312/.pytest_cache
rootdir: /Users/reinout/nens/nens-meta
configfile: pyproject.toml
testpaths: nens_meta
plugins: mock-3.12.0
collected 30 items

nens_meta/tests/test_nens_toml.py ...................                         [ 63%]
nens_meta/tests/test_update_project.py ......                                 [ 83%]
nens_meta/tests/test_utils.py .....                                           [100%]

================================ 30 passed in 0.10s =================================
.pkg: _exit> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__
  lint: OK (0.51=setup[0.00]+cmd[0.50] seconds)
  py312: OK (0.66=setup[0.42]+cmd[0.24] seconds)
  congratulations :) (1.21 seconds)

And the relevant part of my tox.ini:

[tox]
# We need 4.4.0 for constrain_package_deps.
min_version = 4.4.0
# envlist is what gets run by default if you just type "tox".
envlist =
    lint
    # py311
    py312

[testenv]
description = run the tests
use_develop = true
skip_install = false
constrain_package_deps = true
# "extras = test" means "install the [test] dependencies from pyproject.toml
extras =
    test
commands =
    pytest

[testenv:lint]
description = run linters that will help improve the code style
skip_install = true
deps =
    pre-commit
commands =
    pre-commit run -a

gaborbernat commented 7 months ago

What I did discover was that the "offending" log messages are logged at the "info" level. I wonder especially whether those logs for the .pkg environment really should be logged at the "info" level?

They most definitely should be.

The info-level logging of the command is fine with me: py312: commands[0]> pytest, I don't need -q for that. But .pkg: get_requires_for_build_editable> python /Users/reinout/.local/pipx/venvs/tox/lib/python3.12/site-packages/pyproject_api/_backend.py True setuptools.build_meta __legacy__ bugs me a bit.

The amount of bug reports we had because of failures in their build backend/frontend was high enough that IMHO, users should understand what is happening under the hood, and IMHO logging the build backend executions achieves this.

In my head, the packaging lines are just as important as the other commands, so what you see as a bug/cleanup I consider it a feature.

reinout commented 7 months ago

I get your point.

OTOH, the details of python packaging ("aha, pyproject_api/_backend.py gets called with True, setuptools.build_meta and __legacy__") escape 90% of my colleagues and I also would have to look up what the first True actually does even though I've done my share of python packaging work (maintaining zc.buildout for a few years). :-)

Some of my colleagues will have a hard time filtering out the actual "productive" output. Visually it looks like lots of things are going wrong, even though it is fine. Sadly. ("Lots of lines that I don't understand, let's ignore it all").

Which is no real problem, as the output with -q is just fine! I only want to make that the default via the settings. If something goes wrong, I'll have to fix it and I can do -vv.

gaborbernat commented 7 months ago

I disagree. I'd rather encourage people to learn about build backends than hide this away from them. If something is printed, and you don't understand, you should probably learn about it. I'm open to making those calls easier to understand, perhaps by formatting their output better, but I'm not for hiding/removing them 😊 (by default).

reinout commented 7 months ago

Yes, I now agree that they should not be hidden by default.

Regarding the colleagues for which I'm doing the tox work: I'm doing that to make it easier for them to actually write tests. That's already a major step forwards. They don't write tests at the moment because it needs a bit of setup which they don't have the experience for. And they haven't ever done it. So I'm doing it for them. "Making it easy for them" isn't the same as "giving a 4 hour course to get them to understand the details of python packaging when they don't even write tests".

If you say "they should probably learn about python build backends": that is just not possible/practical/billable. They're too busy learning about how to make your city's sewer system work or how to keep the nearby river out of your back yard :-) With python of course.

Anyway, I'm not asking anymore for hiding those ".pkg" messages by default, so that's not a real problem.

The remaining question is whether the starting log level (or quiet=true) could be made configurable. I've noticed that --colored also is only a commandline option. And both are used quite early when starting up tox, to set up the logging. So I fear it might be a bit tricky, actually. It seems to happen before the config file gets read?

Perhaps it would be better if I just coded something custom in a plugin? (Which allows me to try out "pluggy": I've only used setuptools entrypoints up till now.)

gaborbernat commented 7 months ago

If you say "they should probably learn about python build backends": that is just not possible/practical/billable. They're too busy learning about how to make your city's sewer system work or how to keep the nearby river out of your back yard :-) With python of course.

The problem is, would what you ask be a reality these people are also the ones that would open up an issue tomorrow complaining that tox does not work, when the bug is really in their backend code...

reinout commented 7 months ago

Keeping the number of unnecessary issues down is a valid concern for a project like tox :-)

The alternative (suppressing the .pkg logging) is already out.
Am I correct in assuming that my original question will also be a bad idea? Because making it (too) easy to lower the log level means lots of people will do just that, resulting in unnecessary issues?

gaborbernat commented 7 months ago

Am I correct in assuming that my original question will also be a bad idea? Because making it (too) easy to lower the log level means lots of people will do just that, resulting in unnecessary issues?

Yeah 🤔

tox-dev / tox