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
Closed
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 49 additions & 0 deletions tests/middleware/test_trace_logging.py
Original file line number Diff line number Diff line change
@@ -1,12 +1,15 @@
import contextlib
import platform
import sys
import threading
import time
import logging

import pytest
import requests

from uvicorn import Config, Server
from uvicorn.config import LOGGING_CONFIG

test_logging_config = {
"version": 1,
Expand Down Expand Up @@ -103,3 +106,49 @@ def test_access_logging(capsys, http_protocol):
captured = capsys.readouterr()
assert '"GET / HTTP/1.1" 204' in captured.out
assert "uvicorn.access" in captured.out


@contextlib.contextmanager
def caplog_for_accesslog(caplog):
# pytest's `caplog` doesn't capture `propagate=False` loggers by default.
# See: https://github.com/pytest-dev/pytest/issues/3697
logger = logging.getLogger("uvicorn.access")
assert logger.propagate is False
logger.addHandler(caplog.handler)
try:
yield
finally:
logger.removeHandler(caplog.handler)


@pytest.mark.parametrize("http_protocol", ["h11", "httptools"])
def test_default_logging(caplog, http_protocol):
caplog.set_level(logging.INFO)

config = Config(
app=app,
loop="asyncio",
http=http_protocol,
limit_max_requests=1,
log_config=LOGGING_CONFIG,
)

with caplog_for_accesslog(caplog):
server = Server(config=config)
thread = threading.Thread(target=server.run)
thread.start()
while not server.started:
time.sleep(0.01)
response = requests.get("http://127.0.0.1:8000")
assert response.status_code == 204
thread.join()

messages = [record.message for record in caplog.records]
assert "Started server process" in messages.pop(0)
assert "Waiting for application startup" in messages.pop(0)
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

assert "Shutting down" in messages.pop(0)
assert "Finished server process" in messages.pop(0)