declarative logging

This commit is contained in:
John Lancaster
2026-07-08 22:39:46 -05:00
parent 963805c551
commit 70dd0f45d9
4 changed files with 229 additions and 454 deletions
@@ -1,28 +1,64 @@
# Network Logging Minimal Example
Use this reference when an application needs to send Python logs across a network to a receiver process. The example is intentionally small, but it keeps the important production-shaped boundaries: application modules use normal named loggers, startup code configures routing once, network I/O happens away from the caller path, and the receiver owns final formatting and destinations.
Use this reference when an application should send logs over TCP to a local receiver and you want a complete, working baseline.
This page shows how the pieces fit together end to end:
- application code logs with named loggers
- startup applies one declarative `LOGGING` config
- `SocketHandler` sends records to a receiver
- receiver uses `socketserver` and local logging config for final routing
Source docs to keep nearby:
- [Sending and receiving logging events across a network](https://docs.python.org/3/howto/logging-cookbook.html#sending-and-receiving-logging-events-across-a-network) for the standard socket-listener recipe.
- [Dealing with handlers that block](https://docs.python.org/3/howto/logging-cookbook.html#dealing-with-handlers-that-block) for why `QueueHandler` and `QueueListener` belong in front of slow handlers.
- [`SocketHandler`](https://docs.python.org/3/library/logging.handlers.html#sockethandler) for the built-in network handler and its pickle-based default wire format.
- [`QueueHandler`](https://docs.python.org/3/library/logging.handlers.html#queuehandler) and [`QueueListener`](https://docs.python.org/3/library/logging.handlers.html#queuelistener) for queue-backed logging mechanics.
- [`logging.makeLogRecord`](https://docs.python.org/3/library/logging.html#logging.makeLogRecord) for recreating a `LogRecord` from serialized fields.
- [`socketserver`](https://docs.python.org/3/library/socketserver.html) for a tiny TCP receiver.
- [logging configuration security considerations](https://docs.python.org/3/library/logging.config.html#security-considerations) for treating remote logging configuration and importable config objects as trusted inputs only.
- [Sending and receiving logging events across a network](https://docs.python.org/3/howto/logging-cookbook.html#sending-and-receiving-logging-events-across-a-network)
- [`SocketHandler`](https://docs.python.org/3/library/logging.handlers.html#sockethandler)
- [`socketserver`](https://docs.python.org/3/library/socketserver.html)
- [`logging.makeLogRecord`](https://docs.python.org/3/library/logging.html#logging.makeLogRecord)
## Minimal Topology
Run one receiver process near the final logging destination. Application processes send serialized records to it, and the receiver decides how those records are formatted, filtered, written, rotated, or forwarded.
```text
application code -> named logger -> QueueHandler -> QueueListener -> JSON TCP handler -> receiver -> final handlers
app module -> logger -> SocketHandler -> TCP receiver -> local handlers
```
This shape is useful because network handlers can block. Even a socket handler can pause on DNS, connection setup, back pressure, or a slow collector. The queue keeps normal request, worker, or CLI code from doing that work directly.
## 1) Client Logging Config (Declarative)
It also keeps application code boring in the best way:
```python title="logging_config.py"
import logging.config
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"console": {
"format": "%(asctime)s %(levelname)s %(name)s %(message)s",
"datefmt": "%Y-%m-%d %H:%M:%S",
}
},
"handlers": {
"network": {
"class": "logging.handlers.SocketHandler",
"host": "127.0.0.1",
"port": 9020,
},
"console": {
"class": "logging.StreamHandler",
"formatter": "console",
"level": "INFO",
"stream": "ext://sys.stdout",
},
},
"root": {
"level": "INFO",
"handlers": ["network", "console"],
},
}
def configure_logging() -> None:
logging.config.dictConfig(LOGGING)
```
```python title="feature.py"
import logging
@@ -34,17 +70,24 @@ def process_order(order_id: str) -> None:
logger.info("Processing order %s", order_id)
```
The feature module does not know whether logs go to a terminal, a file, a socket, or a collector. That decision belongs to application startup.
```python title="main.py"
from feature import process_order
from logging_config import configure_logging
## Receiver
The receiver accepts newline-delimited JSON records, recreates `LogRecord` objects, and routes them through local logging configuration.
def main() -> None:
configure_logging()
process_order("A-42")
```python title="log_receiver.py"
import json
import logging
if __name__ == "__main__":
main()
```
## 2) Receiver Logging Config (Declarative)
```python title="receiver_logging_config.py"
import logging.config
import socketserver
LOGGING = {
"version": 1,
@@ -66,29 +109,63 @@ LOGGING = {
}
class LogRecordHandler(socketserver.StreamRequestHandler):
def configure_receiver_logging() -> None:
logging.config.dictConfig(LOGGING)
```
## 3) Cookbook Receiver (`socketserver`) Implementation
This receiver follows the same structure as the Python logging cookbook example.
`SocketHandler` sends:
- a 4-byte big-endian length prefix
- a pickle payload containing a `LogRecord` dictionary
```python title="log_receiver.py"
import logging
import pickle
import socketserver
import struct
from receiver_logging_config import configure_receiver_logging
class LogRecordStreamHandler(socketserver.StreamRequestHandler):
def handle(self) -> None:
for line in self.rfile:
while True:
chunk = self.connection.recv(4)
if len(chunk) < 4:
break
payload_len = struct.unpack(">L", chunk)[0]
payload = self.connection.recv(payload_len)
while len(payload) < payload_len:
payload = payload + self.connection.recv(payload_len - len(payload))
try:
payload = json.loads(line.decode("utf-8"))
record = logging.makeLogRecord(payload)
record_dict = pickle.loads(payload)
record = logging.makeLogRecord(record_dict)
except Exception:
logging.getLogger(__name__).exception("Dropped malformed log record")
continue
logger = logging.getLogger(record.name)
if logger.isEnabledFor(record.levelno):
logger.handle(record)
self.handle_log_record(record)
def handle_log_record(self, record: logging.LogRecord) -> None:
logger = logging.getLogger(record.name)
if logger.isEnabledFor(record.levelno):
logger.handle(record)
class LogRecordServer(socketserver.ThreadingTCPServer):
class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):
allow_reuse_address = True
def main() -> None:
logging.config.dictConfig(LOGGING)
with LogRecordServer(("127.0.0.1", 9020), LogRecordHandler) as server:
logging.getLogger(__name__).info("Listening for log records")
configure_receiver_logging()
with LogRecordSocketReceiver(("127.0.0.1", 9020), LogRecordStreamHandler) as server:
logging.getLogger(__name__).info("Receiver listening on 127.0.0.1:9020")
server.serve_forever()
@@ -96,182 +173,27 @@ if __name__ == "__main__":
main()
```
### Receiver Mechanics
## 4) How It Fits Together In Practice
- `dictConfig` is local to the receiver. Client processes do not decide the final formatter, file handler, rotation policy, or downstream sink.
- `makeLogRecord` rebuilds a logging record from plain fields. This is the same reconstruction step used by the cookbook socket receiver, but this example uses JSON instead of unpickling bytes from the network.
- The receiver looks up `logging.getLogger(record.name)` so package-level logger names still route through the normal logging hierarchy.
- The `isEnabledFor` check lets receiver-side logger levels suppress records before handlers run. Client-side filtering is still preferred when possible because it avoids wasted network traffic.
- Binding to `127.0.0.1` makes the demo local-only. Binding to `0.0.0.0` changes the trust boundary and should be paired with network controls, authentication, or a real collector protocol.
1. Start `log_receiver.py`.
2. Start `main.py` from the client app.
3. Client logs go to console and TCP.
4. Receiver reconstructs records and emits them through its own handlers.
## Client Configuration
This split keeps app emission and receiver routing independent while still being fully runnable.
Configure logging once at application startup. The root logger writes to a queue, and a listener thread sends records over TCP.
## Important Security Note
```python title="logging_config.py"
import copy
import json
import logging
import logging.handlers
import queue
import socket
`SocketHandler` uses pickle serialization. Treat this as trusted-network-only transport.
- Bind receiver to localhost or a trusted private network.
- Do not expose this receiver to untrusted clients.
- For hostile boundaries, use JSON/TLS with authenticated ingestion instead of raw pickle.
class PreservingQueueHandler(logging.handlers.QueueHandler):
def prepare(self, record: logging.LogRecord) -> logging.LogRecord:
copied = copy.copy(record)
copied.message = copied.getMessage()
copied.msg = copied.message
copied.args = None
## Review Checklist
if copied.exc_info is not None and copied.exc_text is None:
copied.exc_text = logging.Formatter().formatException(copied.exc_info)
copied.exc_info = None
return copied
class JsonTcpHandler(logging.Handler):
def __init__(self, host: str, port: int, timeout: float = 2.0) -> None:
super().__init__()
self.host = host
self.port = port
self.timeout = timeout
self._socket: socket.socket | None = None
def emit(self, record: logging.LogRecord) -> None:
try:
payload = self._payload_from_record(record)
message = json.dumps(payload, separators=(",", ":")).encode("utf-8")
self._send(message + b"\n")
except Exception:
self._close_socket()
self.handleError(record)
def close(self) -> None:
self._close_socket()
super().close()
def _close_socket(self) -> None:
if self._socket is not None:
self._socket.close()
self._socket = None
def _send(self, message: bytes) -> None:
if self._socket is None:
self._socket = socket.create_connection((self.host, self.port), self.timeout)
self._socket.sendall(message)
def _payload_from_record(self, record: logging.LogRecord) -> dict[str, object]:
payload: dict[str, object] = {
"name": record.name,
"levelno": record.levelno,
"levelname": record.levelname,
"pathname": record.pathname,
"lineno": record.lineno,
"funcName": record.funcName,
"created": record.created,
"process": record.process,
"processName": record.processName,
"threadName": record.threadName,
"msg": record.getMessage(),
"args": None,
}
if record.exc_text is not None:
payload["exc_text"] = record.exc_text
return payload
def configure_logging(host: str = "127.0.0.1", port: int = 9020) -> logging.handlers.QueueListener:
log_queue: queue.Queue[logging.LogRecord] = queue.Queue(maxsize=1000)
queue_handler = PreservingQueueHandler(log_queue)
network_handler = JsonTcpHandler(host, port)
listener = logging.handlers.QueueListener(log_queue, network_handler, respect_handler_level=True)
root = logging.getLogger()
root.setLevel(logging.INFO)
root.handlers[:] = [queue_handler]
listener.start()
return listener
```
```python title="app.py"
import logging
from logging_config import configure_logging
logger = logging.getLogger(__name__)
def main() -> None:
listener = configure_logging()
try:
logger.info("Service started")
logger.warning("Example warning from the client")
finally:
listener.stop()
if __name__ == "__main__":
main()
```
Start `log_receiver.py` first, then run `app.py`. The receiver should print the records using its own formatter.
### Client Mechanics
- `PreservingQueueHandler` copies the record before mutating it for queue transfer. The standard `QueueHandler.prepare()` intentionally formats and strips unpickleable fields; overriding it is the documented escape hatch when the listener side needs custom serialization or exception text.
- `queue.Queue(maxsize=1000)` makes back pressure visible. An unbounded queue is simpler, but a bounded queue forces a production decision about whether to drop, block, buffer elsewhere, or fail when the collector cannot keep up.
- `QueueListener` owns the slow handler thread. It should be stopped during application shutdown so queued records are processed before exit.
- `JsonTcpHandler` keeps a TCP connection open after the first event. That avoids a connection handshake per log record while keeping the example small enough to inspect.
- `handleError()` preserves standard logging error behavior. In production, set an explicit policy for dropped records and collector outages rather than assuming logs always arrive.
## Rationale Behind The Pattern
### Use JSON Instead Of The Default Pickle Payload
The built-in `SocketHandler` sends a pickled record dictionary. That is convenient on a trusted local path, but unpickling network input is a poor default at a trust boundary. JSON is not a complete security boundary by itself, but it is inspectable, language-neutral, and avoids executing pickle payloads.
If you use `SocketHandler` anyway, override `makePickle()` with a safer encoding, sign payloads with a scheme such as HMAC, or keep the listener strictly inside a trusted local network.
### Put The Network Handler Behind A Queue
The cookbook explicitly calls out network handlers as potentially blocking. A queue is the smallest standard-library pattern that separates business code from slow handler work. This matters for web requests, async event loops, worker hot paths, and CLIs where the user should not wait on a collector timeout.
### Centralize Final Destinations In The Receiver
Multiple processes writing one file directly is a common source of garbled output, failed rotation, and confusing retention behavior. A receiver process serializes that responsibility: clients emit events, and one process writes or forwards them according to one logging configuration.
### Keep Logger Names Stable
Use module loggers such as `logging.getLogger(__name__)`. Do not create a logger per request, user, socket, tenant, or connection. Put those values in structured fields or formatted messages instead. Logger objects are singletons and are not freed during normal execution, so unbounded logger names become an avoidable memory and routing problem.
### Filter Early When Volume Matters
The receiver can filter records, but records already crossed the network by then. Set client-side logger or handler levels so routine `DEBUG` records are not serialized and transmitted unless the deployment is intentionally collecting them.
## Production Checklist
Before using this beyond a local demo:
1. Protect the receiver with a trusted network boundary, TLS, a VPN, mutual authentication, or a real log collector. Do not expose an unauthenticated logging port to untrusted clients.
2. Decide the outage policy: drop records, block briefly, buffer locally, retry with backoff, or fail startup when the receiver is unavailable.
3. Size the queue and choose the overflow behavior deliberately. The default `QueueHandler.enqueue()` uses `put_nowait()`, so a full bounded queue goes through `handleError()`.
4. Include service, environment, instance, request, trace, or tenant identifiers when operators need cross-service correlation.
5. Redact or avoid secrets before records leave the process.
6. Escape or normalize untrusted newline-containing values if the final destination is line-oriented and vulnerable to log injection confusion.
7. Load-test the receiver and validate shutdown behavior before relying on the logs during incidents.
8. Prefer a managed collector, OpenTelemetry pipeline, syslog, container stdout collection, or platform-native logging when the deployment environment already provides one.
## Review Questions
Use these questions when reviewing network logging code:
- Does normal application code only call named loggers, without attaching handlers in feature modules?
- Is network or file I/O behind a queue for web, async, worker, or high-throughput paths?
- Is the wire format safe for the trust boundary, or does it rely on unpickling unauthenticated input?
- Are logger and handler levels set so noisy records are filtered before crossing the network?
- Is collector failure behavior explicit and tested?
- Does shutdown stop the listener and flush the queue?
- Are secrets, user-controlled newlines, and high-cardinality context handled deliberately?
1. Is there one `LOGGING` dict per process role (client and receiver)?
2. Is `dictConfig` called once at each process startup?
3. Does the receiver decode length-prefixed payloads correctly?
4. Do modules only use `logging.getLogger(__name__)`?
5. Is the receiver endpoint protected by trust boundaries?