click icon indicating copy to clipboard operation
click copied to clipboard

No stdout/stderr is captured with `invoke` during tests in combination with structlog

Open ivasic opened this issue 1 year ago • 2 comments

There seems to be an issue with capturing stdout/stderr when using structlog with stdlib Logger in tests. I've raised an issue with structlog but they are not convinced the problem originates there since the logs are simply passed to the stdlib Logger.

I've traced this down to the click's isolation context manager which seems to replace sys.stdout/sys.stderr with mocks during testing and my guess would be that this could have something to do with the problem but I'm hoping you may know better.

I've tried numerous things like explicitly setting a StreamHandler(sys.stderr) to the stdlib basicConfig, experimented with mix_stderr etc. nothing helped. Any ideas how to fix or work around this issue would be most welcome, thank you.

An example

# app.py
import structlog
import click

logger = structlog.get_logger()
structlog.configure(logger_factory=structlog.stdlib.LoggerFactory())


@click.command()
def hello() -> None:
    logger.info("Hello!")

if __name__ == '__main__':
    hello()

A test case:

# test_app.py
from click.testing import CliRunner
from app import hello

def test_log() -> None:
    runner = CliRunner()
    result = runner.invoke(hello)
    print(result.stdout)
    assert "Hello" in result.stdout

Expected Hello! (to be printed) assertion to pass

Actual nothing printed (result.stdout is empty) assertion failure:

>       assert "Hello" in result.stdout
E       AssertionError: assert 'Hello' in ''
E        +  where '' = <Result okay>.stdout

test_app.py:8: AssertionError```

Environment: macOS

- Python version: 3.12.7
- Click version: 8.1.7

ivasic avatar Dec 20 '24 10:12 ivasic

I had lots of issues with Click <= 8.1.x when writing unittests for my logging helpers in Click Extra (see: https://kdeldycke.github.io/click-extra/logging.html ).

Tl;Dr: I had to extensively patch the CliRunner to make it works. It ended up with a PR at https://github.com/pallets/click/pull/2523 . This PR is now part of the upcoming 8.2.0 version. Can you try it? Maybe that will solve your issue.

kdeldycke avatar Jan 23 '25 05:01 kdeldycke

@kdeldycke thank you, appreciate your help!

I just tried it from the release but the same test case I originally posted still fails :/ I'll give it one more test after the release is officially out.

➜  click-structlog uv add git+https://github.com/pallets/[email protected]           
Resolved 15 packages in 93ms
 Updated https://github.com/pallets/click.git (e4c24ca)
   Built click @ git+https://github.com/pallets/click.git@e4c24ca309ebe77ab029dac9b6d27d49fff5964f
Prepared 1 package in 2.27s
Uninstalled 1 package in 11ms
Installed 1 package in 2ms
 - click==8.1.7
 + click==8.2.0 (from git+https://github.com/pallets/click.git@e4c24ca309ebe77ab029dac9b6d27d49fff5964f)
➜  click-structlog uv run pytest                                                
==================================================================== test session starts =====================================================================
platform darwin -- Python 3.12.7, pytest-8.3.4, pluggy-1.5.0
rootdir: click-structlog
configfile: pyproject.toml
collected 1 item                                                                                                                                             

test_app.py F                                                                                                                                          [100%]

========================================================================== FAILURES ==========================================================================
__________________________________________________________________________ test_log __________________________________________________________________________

    def test_log() -> None:
        runner = CliRunner()
        result = runner.invoke(hello)
        print(result.stdout)
>       assert "Hello" in result.stdout
E       AssertionError: assert 'Hello' in ''
E        +  where '' = <Result okay>.stdout

test_app.py:8: AssertionError
-------------------------------------------------------------------- Captured stdout call --------------------------------------------------------------------

================================================================== short test summary info ===================================================================
FAILED test_app.py::test_log - AssertionError: assert 'Hello' in ''
===================================================================== 1 failed in 0.17s ======================================================================

ivasic avatar Jan 31 '25 12:01 ivasic