mirror of
https://github.com/kennethreitz/responder.git
synced 2026-06-05 23:00:17 +00:00
Compare commits
4 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| 691f6b4d5c | |||
| 90a082a0ac | |||
| 5ee0de6458 | |||
| 1c729c8542 |
@@ -5,6 +5,38 @@ All notable changes to this project will be documented in this file.
|
||||
The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and
|
||||
this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
|
||||
|
||||
## [v3.6.0] - 2026-03-24
|
||||
|
||||
### Added
|
||||
|
||||
- Built-in structured logging with per-request context (`enable_logging=True`)
|
||||
- `api.log` — always-available logger, enriched with request context when logging is enabled
|
||||
- Automatic access logging with timing: `GET /path → 200 (1.2ms)`
|
||||
- Request ID generation/forwarding via `X-Request-ID` header
|
||||
- `contextvars`-based request context (ID, method, path, client IP) on every log record
|
||||
- `responder.ext.logging` module: `get_logger()`, `RequestContext`, `RequestContextFilter`
|
||||
- CLAUDE.md project guide and `/release` command
|
||||
- Version number in docs sidebar
|
||||
|
||||
### Changed
|
||||
|
||||
- Comprehensive documentation improvements across all pages
|
||||
- Deployment: health checks, Docker Compose, Caddy, Procfile, production checklist
|
||||
- API reference: usage examples for every class
|
||||
- Feature tour: Pydantic validation, content negotiation, structured logging sections
|
||||
- Tutorials: modernized SQLAlchemy to `mapped_column()`, fixed deprecated `datetime.utcnow()`,
|
||||
WebSocket `WebSocketDisconnect` handling, role-based auth, auth strategy guide
|
||||
- Testing: rate limiting and WSGI mount examples
|
||||
- Middleware: pure ASGI middleware example
|
||||
- Quickstart: links to all tutorials
|
||||
- Sandbox: full rewrite with project layout
|
||||
- Docker example uses `uv` instead of pip
|
||||
- Backlog updated: removed implemented features, replaced HTTP/2 server push with dependency injection
|
||||
|
||||
### Removed
|
||||
|
||||
- `uv.lock` — this is a library, not an application
|
||||
|
||||
## [v3.5.0] - 2026-03-24
|
||||
|
||||
### Added
|
||||
@@ -459,6 +491,7 @@ this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.htm
|
||||
|
||||
- Conception!
|
||||
|
||||
[v3.6.0]: https://github.com/kennethreitz/responder/compare/v3.5.0..v3.6.0
|
||||
[v3.5.0]: https://github.com/kennethreitz/responder/compare/v3.4.0..v3.5.0
|
||||
[v3.4.0]: https://github.com/kennethreitz/responder/compare/v3.3.0..v3.4.0
|
||||
[v3.3.0]: https://github.com/kennethreitz/responder/compare/v3.2.0..v3.3.0
|
||||
|
||||
@@ -5,4 +5,4 @@
|
||||
- Per-route rate limiting (different limits for different endpoints)
|
||||
- Built-in structured logging with request context
|
||||
- OpenAPI 3.1 support
|
||||
- HTTP/2 server push
|
||||
- Dependency injection for route handlers
|
||||
|
||||
@@ -30,8 +30,9 @@ Here's a minimal Dockerfile::
|
||||
|
||||
FROM python:3.13-slim
|
||||
WORKDIR /app
|
||||
COPY --from=ghcr.io/astral-sh/uv:latest /uv /usr/local/bin/uv
|
||||
COPY . .
|
||||
RUN pip install responder
|
||||
RUN uv pip install --system responder
|
||||
ENV PORT=80
|
||||
EXPOSE 80
|
||||
CMD ["python", "api.py"]
|
||||
@@ -42,9 +43,10 @@ Build and run::
|
||||
$ docker run -p 8000:80 myapi
|
||||
|
||||
The ``python:3.13-slim`` image is about 150MB — small enough for fast
|
||||
deploys but includes everything you need. For even smaller images, you
|
||||
can use ``python:3.13-alpine``, though some packages may need extra
|
||||
build dependencies.
|
||||
deploys but includes everything you need. Using ``uv`` for installs
|
||||
is significantly faster than pip. For even smaller images, you can use
|
||||
``python:3.13-alpine``, though some packages may need extra build
|
||||
dependencies.
|
||||
|
||||
|
||||
Cloud Platforms
|
||||
@@ -182,4 +184,4 @@ Before going live:
|
||||
- **Add a health check** — ``/health`` endpoint for monitoring
|
||||
- **Enable HTTPS** — via your proxy, cloud platform, or uvicorn's ``--ssl-*`` flags
|
||||
- **Set up logging** — uvicorn logs requests by default; pipe them to your log aggregator
|
||||
- **Pin your dependencies** — commit ``uv.lock`` for reproducible deploys
|
||||
- **Pin your dependencies** — use a lock file or pinned requirements for reproducible deploys
|
||||
|
||||
@@ -73,6 +73,7 @@ One ``pip install``, batteries included:
|
||||
- Sync and async views — ``async`` is always optional.
|
||||
- Class-based views with ``on_get``, ``on_post``, ``on_request``.
|
||||
- Built-in rate limiting with ``X-RateLimit`` headers.
|
||||
- Structured logging with per-request context.
|
||||
- Content negotiation: JSON, YAML, and MessagePack.
|
||||
- A pleasant API with a single import statement.
|
||||
- OpenAPI schema generation with Swagger UI.
|
||||
|
||||
@@ -376,3 +376,9 @@ jump into the tutorials:
|
||||
- :doc:`tutorial-rest` — build a full CRUD API with validation
|
||||
- :doc:`tutorial-sqlalchemy` — connect to a database
|
||||
- :doc:`tutorial-auth` — add authentication
|
||||
- :doc:`tutorial-websockets` — real-time communication
|
||||
- :doc:`tutorial-middleware` — hooks and middleware
|
||||
- :doc:`tutorial-flask` — migrating from Flask
|
||||
- :doc:`guide-config` — environment variables and secrets
|
||||
- :doc:`deployment` — Docker, cloud platforms, and production
|
||||
- :doc:`testing` — writing tests with pytest
|
||||
|
||||
+43
-17
@@ -2,35 +2,61 @@
|
||||
# Development Sandbox
|
||||
|
||||
## Setup
|
||||
Set up a development sandbox.
|
||||
|
||||
Acquire sources and create virtualenv.
|
||||
Clone the repo and install all dependencies:
|
||||
```shell
|
||||
git clone https://github.com/kennethreitz/responder.git
|
||||
cd responder
|
||||
uv venv
|
||||
```
|
||||
|
||||
Install project in editable mode, including
|
||||
all development tools.
|
||||
```shell
|
||||
uv venv && source .venv/bin/activate
|
||||
uv pip install --upgrade --editable '.[develop,docs,release,test]'
|
||||
```
|
||||
|
||||
## Operations
|
||||
Run tests.
|
||||
## Running Tests
|
||||
```shell
|
||||
source .venv/bin/activate
|
||||
pytest
|
||||
pytest # full suite with coverage
|
||||
pytest tests/test_responder.py -xvs # single file, stop on first failure
|
||||
pytest -k "test_mount" # run tests matching a pattern
|
||||
```
|
||||
|
||||
Format code.
|
||||
## Code Formatting
|
||||
```shell
|
||||
ruff format .
|
||||
ruff check --fix .
|
||||
ruff format . # auto-format
|
||||
ruff check --fix . # lint and auto-fix
|
||||
```
|
||||
|
||||
Documentation authoring.
|
||||
## Type Checking
|
||||
```shell
|
||||
sphinx-autobuild --open-browser --watch docs/source docs/source docs/build
|
||||
mypy
|
||||
```
|
||||
|
||||
## Documentation
|
||||
|
||||
Live-reloading doc server (opens in browser):
|
||||
```shell
|
||||
cd docs
|
||||
sphinx-autobuild --open-browser --watch source source build
|
||||
```
|
||||
|
||||
Or build once:
|
||||
```shell
|
||||
cd docs
|
||||
make html
|
||||
# open build/html/index.html
|
||||
```
|
||||
|
||||
## Project Layout
|
||||
|
||||
```
|
||||
responder/
|
||||
├── responder/ # main package
|
||||
│ ├── api.py # API class — the entry point
|
||||
│ ├── routes.py # Router, Route, WebSocketRoute
|
||||
│ ├── models.py # Request and Response wrappers
|
||||
│ ├── ext/ # extensions (CLI, GraphQL, OpenAPI, rate limiting)
|
||||
│ ├── background.py # background task queue
|
||||
│ └── formats.py # content negotiation (JSON, YAML, msgpack)
|
||||
├── tests/ # pytest test suite
|
||||
├── examples/ # runnable example apps
|
||||
├── docs/source/ # Sphinx documentation
|
||||
└── pyproject.toml # project metadata and tool config
|
||||
```
|
||||
|
||||
@@ -596,6 +596,60 @@ can pace themselves.
|
||||
The rate limiter is per-client, keyed by IP address.
|
||||
|
||||
|
||||
Structured Logging
|
||||
------------------
|
||||
|
||||
Production applications need structured, searchable logs. Responder
|
||||
includes built-in logging that automatically attaches request context
|
||||
— request ID, HTTP method, path, and client IP — to every log message
|
||||
emitted during request handling::
|
||||
|
||||
api = responder.API(enable_logging=True)
|
||||
|
||||
This gives you:
|
||||
|
||||
- **Access logging** with timing for every request::
|
||||
|
||||
2026-03-24 12:00:00 [INFO] responder.access — GET /users → 200 (1.2ms)
|
||||
|
||||
- **A logger on the API instance** — use ``api.log`` anywhere in
|
||||
your routes. Request context (ID, method, path, client IP) is
|
||||
attached automatically::
|
||||
|
||||
@api.route("/users/{user_id:int}")
|
||||
def get_user(req, resp, *, user_id):
|
||||
api.log.info("fetching user %d", user_id)
|
||||
# => [INFO] responder.app -- fetching user 42 [GET /users/42] [req:a1b2c3] [client:10.0.0.1]
|
||||
resp.media = {"id": user_id}
|
||||
|
||||
- **Request IDs** generated automatically (or forwarded from the
|
||||
``X-Request-ID`` header) and included in responses.
|
||||
|
||||
The logging uses Python's standard ``logging`` module, so it works with
|
||||
any handler — files, syslog, JSON formatters, Datadog, Sentry, whatever
|
||||
you already use.
|
||||
|
||||
For additional loggers (e.g. in helper modules), use ``get_logger``::
|
||||
|
||||
from responder.ext.logging import get_logger
|
||||
logger = get_logger("myapp.db")
|
||||
|
||||
You can also access the current request context directly::
|
||||
|
||||
from responder.ext.logging import RequestContext
|
||||
|
||||
@api.route("/debug")
|
||||
def debug(req, resp):
|
||||
resp.media = {
|
||||
"request_id": RequestContext.get_request_id(),
|
||||
"client_ip": RequestContext.get_client_ip(),
|
||||
}
|
||||
|
||||
When ``enable_logging=True`` is set, it supersedes ``request_id=True``
|
||||
— the logging middleware handles request IDs itself, so you don't get
|
||||
duplicate headers.
|
||||
|
||||
|
||||
Pydantic Validation
|
||||
-------------------
|
||||
|
||||
|
||||
@@ -46,14 +46,14 @@ Install PyJWT::
|
||||
Create a helper to encode and decode tokens::
|
||||
|
||||
import jwt
|
||||
from datetime import datetime, timedelta
|
||||
from datetime import datetime, timedelta, timezone
|
||||
|
||||
SECRET = "your-secret-key"
|
||||
|
||||
def create_token(user_id: int) -> str:
|
||||
payload = {
|
||||
"sub": user_id,
|
||||
"exp": datetime.utcnow() + timedelta(hours=24),
|
||||
"exp": datetime.now(timezone.utc) + timedelta(hours=24),
|
||||
}
|
||||
return jwt.encode(payload, SECRET, algorithm="HS256")
|
||||
|
||||
@@ -189,3 +189,56 @@ Remember to set a proper secret key::
|
||||
The session data is signed (not encrypted) — users can read it but
|
||||
can't tamper with it. Don't store sensitive data like passwords in
|
||||
sessions.
|
||||
|
||||
|
||||
Role-Based Access Control
|
||||
--------------------------
|
||||
|
||||
For APIs where different users have different permissions, embed the
|
||||
role in the token and check it in route-specific guards::
|
||||
|
||||
def create_token(user_id: int, role: str = "user") -> str:
|
||||
payload = {
|
||||
"sub": user_id,
|
||||
"role": role,
|
||||
"exp": datetime.now(timezone.utc) + timedelta(hours=24),
|
||||
}
|
||||
return jwt.encode(payload, SECRET, algorithm="HS256")
|
||||
|
||||
Create a helper that checks for a specific role::
|
||||
|
||||
def require_role(*roles):
|
||||
"""Before-request hook factory that restricts by role."""
|
||||
def check(req, resp):
|
||||
user_role = getattr(req.state, "role", None)
|
||||
if user_role not in roles:
|
||||
resp.status_code = 403
|
||||
resp.media = {"error": "Insufficient permissions"}
|
||||
return check
|
||||
|
||||
Use it on specific routes::
|
||||
|
||||
@api.route("/admin/users", before_request=require_role("admin"))
|
||||
def list_all_users(req, resp):
|
||||
resp.media = {"users": [...]}
|
||||
|
||||
And store the role during token verification::
|
||||
|
||||
# In your auth_guard:
|
||||
req.state.user_id = payload["sub"]
|
||||
req.state.role = payload.get("role", "user")
|
||||
|
||||
|
||||
Choosing an Auth Strategy
|
||||
--------------------------
|
||||
|
||||
- **API keys** — simplest. Good for server-to-server, CLI tools, and
|
||||
internal services. No expiration unless you build it.
|
||||
- **JWT tokens** — standard for SPAs and mobile apps. Stateless, so
|
||||
they scale well. Downside: you can't revoke them without a blocklist.
|
||||
- **Sessions** — best for traditional web apps with HTML forms. The
|
||||
browser manages cookies automatically. Stateful — the server controls
|
||||
the session lifecycle.
|
||||
|
||||
Start with API keys for internal tools, JWT for public APIs, and
|
||||
sessions for web apps with login pages.
|
||||
|
||||
@@ -28,8 +28,8 @@ SQLAlchemy models map Python classes to database tables. Each attribute
|
||||
becomes a column::
|
||||
|
||||
# models.py
|
||||
from sqlalchemy import Column, Integer, String
|
||||
from sqlalchemy.orm import DeclarativeBase
|
||||
from sqlalchemy import String
|
||||
from sqlalchemy.orm import DeclarativeBase, Mapped, mapped_column
|
||||
|
||||
class Base(DeclarativeBase):
|
||||
pass
|
||||
@@ -37,15 +37,16 @@ becomes a column::
|
||||
class Book(Base):
|
||||
__tablename__ = "books"
|
||||
|
||||
id = Column(Integer, primary_key=True, autoincrement=True)
|
||||
title = Column(String, nullable=False)
|
||||
author = Column(String, nullable=False)
|
||||
year = Column(Integer, nullable=False)
|
||||
isbn = Column(String, nullable=True)
|
||||
id: Mapped[int] = mapped_column(primary_key=True, autoincrement=True)
|
||||
title: Mapped[str] = mapped_column(String, nullable=False)
|
||||
author: Mapped[str] = mapped_column(String, nullable=False)
|
||||
year: Mapped[int] = mapped_column(nullable=False)
|
||||
isbn: Mapped[str | None] = mapped_column(String, nullable=True)
|
||||
|
||||
``DeclarativeBase`` is SQLAlchemy's modern base class (SQLAlchemy 2.0+).
|
||||
Each model class corresponds to a table, and each ``Column`` corresponds
|
||||
to a column in that table.
|
||||
This uses SQLAlchemy 2.0's ``Mapped`` type annotations and
|
||||
``mapped_column()``, which give you type checker support and cleaner
|
||||
syntax than the older ``Column()`` style. Each model class corresponds
|
||||
to a table, and each ``mapped_column()`` corresponds to a column.
|
||||
|
||||
|
||||
Database Setup
|
||||
|
||||
@@ -58,6 +58,8 @@ A chat room needs to broadcast messages to all connected clients. We keep
|
||||
a set of active connections and iterate through them when someone sends
|
||||
a message::
|
||||
|
||||
from starlette.websockets import WebSocketDisconnect
|
||||
|
||||
connected = set()
|
||||
|
||||
@api.route("/chat", websocket=True)
|
||||
@@ -70,13 +72,15 @@ a message::
|
||||
# Broadcast to all connected clients
|
||||
for client in connected:
|
||||
await client.send_text(message)
|
||||
except Exception:
|
||||
except WebSocketDisconnect:
|
||||
pass
|
||||
finally:
|
||||
connected.discard(ws)
|
||||
|
||||
The ``try/finally`` block ensures we remove disconnected clients from
|
||||
the set, even if the connection drops unexpectedly.
|
||||
the set, even if the connection drops unexpectedly. Catching
|
||||
``WebSocketDisconnect`` specifically (rather than bare ``Exception``)
|
||||
makes the intent clear and avoids swallowing real bugs.
|
||||
|
||||
|
||||
Data Formats
|
||||
@@ -154,6 +158,40 @@ WebSocket before-request hooks receive the ``ws`` object and must call
|
||||
``await ws.accept()`` if they want the connection to proceed.
|
||||
|
||||
|
||||
Connection Lifecycle
|
||||
--------------------
|
||||
|
||||
WebSocket connections go through several states:
|
||||
|
||||
1. **Connecting** — the client sends an upgrade request
|
||||
2. **Open** — after ``await ws.accept()``, both sides can send messages
|
||||
3. **Closing** — either side initiates a close handshake
|
||||
4. **Closed** — the connection is fully terminated
|
||||
|
||||
When a client disconnects (closes the tab, loses network), the next
|
||||
``await ws.receive_text()`` raises ``WebSocketDisconnect``. Always
|
||||
handle this — otherwise your server accumulates dead connections::
|
||||
|
||||
from starlette.websockets import WebSocketDisconnect
|
||||
|
||||
@api.route("/ws", websocket=True)
|
||||
async def handler(ws):
|
||||
await ws.accept()
|
||||
try:
|
||||
while True:
|
||||
data = await ws.receive_text()
|
||||
await ws.send_text(f"Got: {data}")
|
||||
except WebSocketDisconnect:
|
||||
print("Client disconnected")
|
||||
|
||||
You can also close connections from the server side::
|
||||
|
||||
await ws.close(code=1000) # 1000 = normal closure
|
||||
|
||||
Common close codes: ``1000`` (normal), ``1001`` (going away),
|
||||
``1008`` (policy violation), ``1011`` (server error).
|
||||
|
||||
|
||||
Testing WebSockets
|
||||
------------------
|
||||
|
||||
@@ -169,3 +207,13 @@ Use Starlette's ``TestClient`` for WebSocket tests::
|
||||
|
||||
The ``websocket_connect`` context manager handles the connection
|
||||
lifecycle — it connects on enter and disconnects on exit.
|
||||
|
||||
You can also test that connections are properly rejected::
|
||||
|
||||
from starlette.websockets import WebSocketDisconnect
|
||||
|
||||
def test_websocket_404():
|
||||
client = TestClient(api)
|
||||
with pytest.raises(WebSocketDisconnect):
|
||||
with client.websocket_connect("/nonexistent"):
|
||||
pass
|
||||
|
||||
@@ -1 +1 @@
|
||||
__version__ = "3.5.0"
|
||||
__version__ = "3.6.0"
|
||||
|
||||
+17
-1
@@ -61,6 +61,7 @@ class API:
|
||||
openapi_theme=DEFAULT_OPENAPI_THEME,
|
||||
lifespan=None,
|
||||
request_id=False,
|
||||
enable_logging=False,
|
||||
):
|
||||
"""Create a new Responder API instance.
|
||||
|
||||
@@ -86,6 +87,7 @@ class API:
|
||||
:param openapi_theme: Documentation UI theme: ``"swagger_ui"``, ``"redoc"``, ``"rapidoc"``, or ``"elements"``.
|
||||
:param lifespan: An async context manager for startup/shutdown logic.
|
||||
:param request_id: If ``True``, add ``X-Request-ID`` headers to all responses.
|
||||
:param enable_logging: If ``True``, enable structured logging with per-request context (request ID, method, path, client IP).
|
||||
""" # noqa: E501
|
||||
self.background = BackgroundQueue()
|
||||
|
||||
@@ -158,7 +160,7 @@ class API:
|
||||
|
||||
self.templates = Templates(directory=templates_dir)
|
||||
|
||||
if request_id:
|
||||
if request_id and not enable_logging:
|
||||
import uuid as _uuid
|
||||
|
||||
def _add_request_id(req, resp):
|
||||
@@ -167,6 +169,20 @@ class API:
|
||||
|
||||
self.router.after_request(_add_request_id)
|
||||
|
||||
if enable_logging:
|
||||
import logging as _logging
|
||||
|
||||
from .ext.logging import LoggingMiddleware, get_logger, setup_logging
|
||||
|
||||
log_level = _logging.DEBUG if debug else _logging.INFO
|
||||
setup_logging(level=log_level)
|
||||
self.add_middleware(LoggingMiddleware)
|
||||
self.log = get_logger("responder.app")
|
||||
else:
|
||||
import logging as _logging
|
||||
|
||||
self.log = _logging.getLogger("responder.app")
|
||||
|
||||
@property
|
||||
def requests(self):
|
||||
"""A test client connected to the ASGI app. Lazily initialized."""
|
||||
|
||||
@@ -0,0 +1,181 @@
|
||||
"""Structured logging with per-request context.
|
||||
|
||||
Provides a logging setup that automatically includes request metadata
|
||||
(request ID, method, path, client IP) in every log message emitted
|
||||
during request handling.
|
||||
|
||||
Usage::
|
||||
|
||||
api = responder.API(enable_logging=True)
|
||||
|
||||
# In any route or middleware:
|
||||
from responder.ext.logging import get_logger
|
||||
logger = get_logger(__name__)
|
||||
|
||||
@api.route("/")
|
||||
def index(req, resp):
|
||||
logger.info("handling request")
|
||||
# => 2026-03-24 12:00:00 [INFO] app — handling request [GET /] [req:abc123] [client:127.0.0.1]
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import logging
|
||||
import time
|
||||
import uuid
|
||||
from contextvars import ContextVar
|
||||
|
||||
__all__ = ["get_logger", "RequestContext", "RequestContextFilter", "LoggingMiddleware"]
|
||||
|
||||
# Context variables for per-request metadata.
|
||||
_request_id: ContextVar[str] = ContextVar("request_id", default="-")
|
||||
_request_method: ContextVar[str] = ContextVar("request_method", default="-")
|
||||
_request_path: ContextVar[str] = ContextVar("request_path", default="-")
|
||||
_client_ip: ContextVar[str] = ContextVar("client_ip", default="-")
|
||||
|
||||
|
||||
class RequestContext:
|
||||
"""Read-only access to the current request's logging context."""
|
||||
|
||||
@staticmethod
|
||||
def get_request_id() -> str:
|
||||
return _request_id.get()
|
||||
|
||||
@staticmethod
|
||||
def get_method() -> str:
|
||||
return _request_method.get()
|
||||
|
||||
@staticmethod
|
||||
def get_path() -> str:
|
||||
return _request_path.get()
|
||||
|
||||
@staticmethod
|
||||
def get_client_ip() -> str:
|
||||
return _client_ip.get()
|
||||
|
||||
|
||||
class RequestContextFilter(logging.Filter):
|
||||
"""A logging filter that injects request context into log records.
|
||||
|
||||
Adds ``request_id``, ``request_method``, ``request_path``, and
|
||||
``client_ip`` attributes to every log record, so they can be used
|
||||
in format strings.
|
||||
"""
|
||||
|
||||
def filter(self, record: logging.LogRecord) -> bool:
|
||||
record.request_id = _request_id.get() # type: ignore[attr-defined]
|
||||
record.request_method = _request_method.get() # type: ignore[attr-defined]
|
||||
record.request_path = _request_path.get() # type: ignore[attr-defined]
|
||||
record.client_ip = _client_ip.get() # type: ignore[attr-defined]
|
||||
return True
|
||||
|
||||
|
||||
# Default format that includes request context.
|
||||
DEFAULT_LOG_FORMAT = (
|
||||
"%(asctime)s [%(levelname)s] %(name)s -- %(message)s "
|
||||
"[%(request_method)s %(request_path)s] "
|
||||
"[req:%(request_id)s] [client:%(client_ip)s]"
|
||||
)
|
||||
|
||||
|
||||
def get_logger(name: str | None = None) -> logging.Logger:
|
||||
"""Get a logger with the request context filter attached.
|
||||
|
||||
:param name: Logger name (typically ``__name__``).
|
||||
:returns: A :class:`logging.Logger` with request context available.
|
||||
"""
|
||||
logger = logging.getLogger(name)
|
||||
# Avoid adding duplicate filters.
|
||||
if not any(isinstance(f, RequestContextFilter) for f in logger.filters):
|
||||
logger.addFilter(RequestContextFilter())
|
||||
return logger
|
||||
|
||||
|
||||
def setup_logging(level: int = logging.INFO) -> None:
|
||||
"""Configure the root logger with request-context-aware formatting.
|
||||
|
||||
:param level: The logging level (default ``INFO``).
|
||||
"""
|
||||
root = logging.getLogger()
|
||||
root.setLevel(level)
|
||||
|
||||
# Only add our handler if the root logger has no handlers yet,
|
||||
# or if none of them use our filter.
|
||||
has_context_handler = any(
|
||||
any(isinstance(f, RequestContextFilter) for f in h.filters)
|
||||
for h in root.handlers
|
||||
)
|
||||
if not has_context_handler:
|
||||
handler = logging.StreamHandler()
|
||||
handler.setLevel(level)
|
||||
handler.addFilter(RequestContextFilter())
|
||||
handler.setFormatter(logging.Formatter(DEFAULT_LOG_FORMAT))
|
||||
root.addHandler(handler)
|
||||
|
||||
|
||||
class LoggingMiddleware:
|
||||
"""ASGI middleware that sets per-request context variables.
|
||||
|
||||
For each HTTP request, this middleware:
|
||||
|
||||
1. Extracts or generates a request ID
|
||||
2. Sets context variables for method, path, and client IP
|
||||
3. Logs the request and response with timing information
|
||||
"""
|
||||
|
||||
def __init__(self, app, logger_name: str = "responder.access"):
|
||||
self.app = app
|
||||
self.logger = get_logger(logger_name)
|
||||
|
||||
async def __call__(self, scope, receive, send):
|
||||
if scope["type"] not in ("http", "websocket"):
|
||||
await self.app(scope, receive, send)
|
||||
return
|
||||
|
||||
# Extract request metadata.
|
||||
headers = dict(scope.get("headers", []))
|
||||
request_id = (
|
||||
headers.get(b"x-request-id", b"").decode() or uuid.uuid4().hex[:8]
|
||||
)
|
||||
method = scope.get("method", "WS")
|
||||
path = scope.get("path", "/")
|
||||
client = scope.get("client")
|
||||
client_ip = client[0] if client else "-"
|
||||
|
||||
# Set context variables for the duration of this request.
|
||||
tok_id = _request_id.set(request_id)
|
||||
tok_method = _request_method.set(method)
|
||||
tok_path = _request_path.set(path)
|
||||
tok_ip = _client_ip.set(client_ip)
|
||||
|
||||
# Track response status.
|
||||
status_code = None
|
||||
|
||||
async def send_wrapper(message):
|
||||
nonlocal status_code
|
||||
if message["type"] == "http.response.start":
|
||||
status_code = message.get("status")
|
||||
# Inject request ID into response headers.
|
||||
headers_list = list(message.get("headers", []))
|
||||
headers_list.append((b"x-request-id", request_id.encode()))
|
||||
message = {**message, "headers": headers_list}
|
||||
await send(message)
|
||||
|
||||
start = time.perf_counter()
|
||||
try:
|
||||
await self.app(scope, receive, send_wrapper)
|
||||
finally:
|
||||
duration_ms = (time.perf_counter() - start) * 1000
|
||||
if scope["type"] == "http":
|
||||
self.logger.info(
|
||||
"%s %s → %s (%.1fms)",
|
||||
method,
|
||||
path,
|
||||
status_code or "?",
|
||||
duration_ms,
|
||||
)
|
||||
# Reset context variables.
|
||||
_request_id.reset(tok_id)
|
||||
_request_method.reset(tok_method)
|
||||
_request_path.reset(tok_path)
|
||||
_client_ip.reset(tok_ip)
|
||||
@@ -0,0 +1,158 @@
|
||||
"""Tests for structured logging with request context."""
|
||||
|
||||
import logging
|
||||
|
||||
import responder
|
||||
from responder.ext.logging import (
|
||||
LoggingMiddleware,
|
||||
RequestContext,
|
||||
RequestContextFilter,
|
||||
get_logger,
|
||||
)
|
||||
|
||||
|
||||
def test_logging_middleware_sets_request_id():
|
||||
"""LoggingMiddleware adds X-Request-ID to responses."""
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
|
||||
@api.route("/")
|
||||
def index(req, resp):
|
||||
resp.text = "ok"
|
||||
|
||||
r = api.requests.get("http://localhost/")
|
||||
assert r.status_code == 200
|
||||
assert "x-request-id" in r.headers
|
||||
assert len(r.headers["x-request-id"]) > 0
|
||||
|
||||
|
||||
def test_logging_middleware_forwards_request_id():
|
||||
"""LoggingMiddleware forwards client-provided X-Request-ID."""
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
|
||||
@api.route("/")
|
||||
def index(req, resp):
|
||||
resp.text = "ok"
|
||||
|
||||
r = api.requests.get(
|
||||
"http://localhost/", headers={"X-Request-ID": "custom-id-123"}
|
||||
)
|
||||
assert r.headers["x-request-id"] == "custom-id-123"
|
||||
|
||||
|
||||
def test_logging_context_available_in_route():
|
||||
"""Request context is available inside route handlers."""
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
captured = {}
|
||||
|
||||
@api.route("/ctx")
|
||||
def index(req, resp):
|
||||
captured["request_id"] = RequestContext.get_request_id()
|
||||
captured["method"] = RequestContext.get_method()
|
||||
captured["path"] = RequestContext.get_path()
|
||||
captured["client_ip"] = RequestContext.get_client_ip()
|
||||
resp.text = "ok"
|
||||
|
||||
api.requests.get("http://localhost/ctx")
|
||||
assert captured["method"] == "GET"
|
||||
assert captured["path"] == "/ctx"
|
||||
assert captured["request_id"] != "-"
|
||||
assert captured["client_ip"] != "-"
|
||||
|
||||
|
||||
def test_logging_filter_injects_attributes():
|
||||
"""RequestContextFilter adds context fields to log records."""
|
||||
logger = get_logger("test.filter")
|
||||
records = []
|
||||
|
||||
class CaptureHandler(logging.Handler):
|
||||
def emit(self, record):
|
||||
records.append(record)
|
||||
|
||||
handler = CaptureHandler()
|
||||
logger.addHandler(handler)
|
||||
logger.setLevel(logging.DEBUG)
|
||||
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
|
||||
@api.route("/log")
|
||||
def index(req, resp):
|
||||
logger.info("test message")
|
||||
resp.text = "ok"
|
||||
|
||||
api.requests.get("http://localhost/log")
|
||||
|
||||
logger.removeHandler(handler)
|
||||
|
||||
assert len(records) > 0
|
||||
record = records[0]
|
||||
assert hasattr(record, "request_id")
|
||||
assert hasattr(record, "request_method")
|
||||
assert hasattr(record, "request_path")
|
||||
assert hasattr(record, "client_ip")
|
||||
assert record.request_method == "GET"
|
||||
assert record.request_path == "/log"
|
||||
|
||||
|
||||
def test_get_logger_avoids_duplicate_filters():
|
||||
"""get_logger doesn't add duplicate filters."""
|
||||
logger = get_logger("test.dedup")
|
||||
count_before = sum(1 for f in logger.filters if isinstance(f, RequestContextFilter))
|
||||
get_logger("test.dedup")
|
||||
count_after = sum(1 for f in logger.filters if isinstance(f, RequestContextFilter))
|
||||
assert count_before == count_after == 1
|
||||
|
||||
|
||||
def test_enable_logging_supersedes_request_id():
|
||||
"""enable_logging handles request IDs itself (no duplicate headers)."""
|
||||
api = responder.API(
|
||||
allowed_hosts=["localhost"], request_id=True, enable_logging=True
|
||||
)
|
||||
|
||||
@api.route("/")
|
||||
def index(req, resp):
|
||||
resp.text = "ok"
|
||||
|
||||
r = api.requests.get("http://localhost/")
|
||||
# Should have exactly one X-Request-ID header.
|
||||
assert "x-request-id" in r.headers
|
||||
|
||||
|
||||
def test_api_logger_attribute():
|
||||
"""api.log is available when enable_logging=True."""
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
assert api.log is not None
|
||||
assert api.log.name == "responder.app"
|
||||
|
||||
|
||||
def test_api_log_always_available():
|
||||
"""api.log works even without enable_logging — just no request context."""
|
||||
api = responder.API(allowed_hosts=["localhost"])
|
||||
assert api.log is not None
|
||||
assert api.log.name == "responder.app"
|
||||
api.log.info("works without enable_logging")
|
||||
|
||||
|
||||
def test_api_logger_works_in_routes():
|
||||
"""api.log can be used inside route handlers with context."""
|
||||
api = responder.API(allowed_hosts=["localhost"], enable_logging=True)
|
||||
records = []
|
||||
|
||||
class CaptureHandler(logging.Handler):
|
||||
def emit(self, record):
|
||||
records.append(record)
|
||||
|
||||
handler = CaptureHandler()
|
||||
api.log.addHandler(handler)
|
||||
|
||||
@api.route("/")
|
||||
def index(req, resp):
|
||||
api.log.info("hello from route")
|
||||
resp.text = "ok"
|
||||
|
||||
api.requests.get("http://localhost/")
|
||||
api.log.removeHandler(handler)
|
||||
|
||||
assert any(r.msg == "hello from route" for r in records)
|
||||
record = next(r for r in records if r.msg == "hello from route")
|
||||
assert record.request_method == "GET"
|
||||
assert record.request_path == "/"
|
||||
Reference in New Issue
Block a user