Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Test output of default logging configuration #887

Closed
wants to merge 4 commits into from

Conversation

florimondmanca
Copy link
Member

Alternative to #885

Adds a test that verifies the expected output from our default logging configuration on a basic startup-request-shutdown sequence.

@florimondmanca
Copy link
Member Author

Hmm. Looks like there's a weird interaction between the existing test cases and this new one. Only the access log line is captured when running all the tests in a row, rather than -k test_default_logging. 😕

@euri10
Copy link
Member

euri10 commented Dec 12, 2020

iirc I had to resort on using capsys instead of caplog when I sent the trace logging test but cant remember if I found the reason, and yes there might be an interaction from previious tests

assert "ASGI 'lifespan' protocol appears unsupported" in messages.pop(0)
assert "Application startup complete" in messages.pop(0)
assert "Uvicorn running on http://127.0.0.1:8000" in messages.pop(0)
assert '"GET / HTTP/1.1" 204' in messages.pop(0)
Copy link
Member

@euri10 euri10 Dec 12, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm just surprised here that it outputs 204 and not 204 No Content

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, same…

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it's because caplog uses its own formatter, and we use AccessFormatter for access logs,
I cant find a clean way to get it through caplog without messing up with pytest

@florimondmanca
Copy link
Member Author

Even if using capsys, the captured output only contains the access log line. Weird…

Comment on lines 45 to 46
"uvicorn": {"handlers": ["default"], "level": "INFO"},
"uvicorn.error": {"level": "INFO"},
Copy link
Member Author

@florimondmanca florimondmanca Dec 12, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@euri10 There were two problems here:

  • The test config overrides the root logger. Doesn't actually make the test fail if left as-is, but we had a PR to fix it in the default logging config: Don't override the root logger #674.
  • It sets propagate: False on uvicorn.error, which is why when the new test runs after the others, uvicorn.error won't be captured. It could be captured without changing the test config — I'd have to do the same trick than for uvicorn.access — but that sounds a bit absurd.

I think given that the test trace config aims at focusing on uvicorn.asgi in particular, keeping the rest in line with LOGGING_CONFIG sounds about right.

@florimondmanca florimondmanca force-pushed the fm/test-default-logging branch from e8e6905 to 9bd30c0 Compare December 12, 2020 13:02
@euri10
Copy link
Member

euri10 commented Dec 12, 2020

arg sorry @florimondmanca I didn't mean to push this here but to a new branch, hope this is not causing troubles, worst case we can revert my commit on this.
in any case I just renamed the filename to test_logging and leveraged your context manager a little bit more.

@euri10 euri10 self-requested a review December 22, 2020 13:45
@euri10
Copy link
Member

euri10 commented Dec 30, 2020

@florimondmanca what do you think of this:

https://raw.githubusercontent.com/euri10/uvicorn/test_logging/tests/middleware/test_logging.py

i fu the last two commits on your PR, thought I was doing it on another branch, the above link is just the same as the present PR, just adapted for the new test suite,
it leverages you idea of the caplog context manager and test 3 things, trace, access and normal logger
feel free to take it, I dont want to "steal" PRs !!!

@euri10 euri10 mentioned this pull request Feb 24, 2021
@euri10
Copy link
Member

euri10 commented May 29, 2021

closed in favor of #964

@euri10 euri10 closed this May 29, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants