DRY and simple way to capture logging

[yohanboniface]

Hi,

First of all: congrats for the work on ward!

I'm failing to find a DRY and simple way to configure logging so ward would capture it.

Here is a very basic sample:

import logging

from ward import test

logger = logging.getLogger("foobar")
logger.setLevel(logging.DEBUG)
logger.addHandler(logging.StreamHandler())


@test("I expect capture-output to capture logs")
def _():
    print("PRINT")
    logger.info("INFO")
    logger.debug("DEBUG")

Running ward will output something like this:

─────────────────────────────────────────────────────────────────────────────── Ward 0.62.0b0 | CPython 3.9.6 ────────────────────────────────────────────────────────────────────────────────
Found 1 test and 0 fixtures in 0.00 seconds.

INFO
DEBUG
 PASS  test_ward:10 I expect capture-output to capture logs                                                                                                                               100%


╭──────────── Results ────────────╮
│  1  Test Encountered            │
│  1  Passes            (100.0%)  │
╰─────────────────────────────────╯
────────────────────────────────────────────────────────────────────────────────── SUCCESS in 0.01 seconds ───────────────────────────────────────────────────────────────────────────────────

For what I understand, this is because logging is configured before ward try to capture it. And this seems to be because of the way redirect_stdout/stderr works (see this bug report for a bit of context).

In other word, AFAIK, the logging should be configured after redirect_stderr has been called.

This would be a working sample of this scenario:

import logging

from ward import test, fixture

logger = logging.getLogger("foobar")


@fixture
def configure_logging():
    logger.setLevel(logging.DEBUG)
    logger.addHandler(logging.StreamHandler())


@test("I expect capture-output to capture logs")
def _(configure_logging=configure_logging):
    print("PRINT")
    logger.info("INFO")
    logger.debug("DEBUG")

But that would mean adding the fixture configure_logging to each and every test, which is not ideal for obvious reasons.

Any better suggestion ?

I'm thinking about some per-test hook or some fixture autoloading mode (but I do appreciate the path taken by ward to try to avoid magic; while in this given case, pytest has a (magical?) way to work around this race condition).

As a user, I'm expecting to be able to configure a logging with a DEBUG level and to have this output displayed on the console only in case of a failing test.

Thanks for your lights! :)

PS: talking about hooks, what about automatically adding the value of --path as a plugin module candidate ? That way one may implement hooks inside test/__init__.py without the need to either add a pyproject.toml or pass --hook-module to the command line call.

[darrenburns]

Thanks for the report! I naively assumed that logging would be captured in the same was as printing to stdout.

For this, we may need to look at how pytest or other frameworks handle it as I don't have any ideas from the top of my head.

I quite like the idea of adding --path as a plugin module candidate, but will need to take some time to think about it.