logging skill updates

This commit is contained in:
John Lancaster
2026-07-08 21:03:38 -05:00
parent a3ca1a65c2
commit 963805c551
2 changed files with 326 additions and 38 deletions
+150 -38
View File
@@ -17,9 +17,18 @@ x-personal-mcp:
Use this skill to produce idiomatic Python logging guidance or a small logging setup for an application, library, CLI, worker, or web service.
Load references only when needed:
- Python logging overview, library guidance, handlers, and dictConfig schema: [Python logging references](./references/python-logging-docs.md)
- Minimal network logging example with a receiver and queue-backed client: [Network logging minimal example](./references/network-logging-minimal-example.md)
- HTTP JSON logging example with `httpx` and a queue-backed client: [HTTPX logging handler example](./references/httpx-logging-handler-example.md)
[Python logging references](./references/python-logging-docs.md)
: Python logging overview, library guidance, handlers, and dictConfig schema
[JSON file logging pattern](./references/json-file-logging.md)
: Queue-backed rotating JSON file pattern for local machine-readable logs
[Network logging minimal example](./references/network-logging-minimal-example.md)
: Minimal network logging example with a receiver and queue-backed client
[HTTPX logging handler example](./references/httpx-logging-handler-example.md)
: HTTP JSON logging example with `httpx` and a queue-backed client
## When to Use
@@ -50,7 +59,7 @@ If missing, assume:
2. In modules, create loggers with `logger = logging.getLogger(__name__)` so logger names follow the package hierarchy.
3. Use level semantics consistently: `DEBUG` for diagnosis, `INFO` for normal milestones, `WARNING` for notable recoverable conditions, `ERROR` for failed operations, and `CRITICAL` for process-threatening failures.
4. Prefer parameterized logging calls such as `logger.info("Processed %s items", count)` so message formatting is deferred until the record is emitted.
5. Configure handlers and formatters once during application startup. For small scripts, `basicConfig` can be enough; for applications, prefer a centralized configuration function.
5. Configure handlers and formatters once during application startup.
6. Keep third-party logger overrides explicit and narrow. Tune noisy loggers by name instead of muting broad logger hierarchies.
7. Smoke-check output at expected levels and destinations, including one suppressed `DEBUG` message and one exception path if errors are logged.
@@ -64,6 +73,111 @@ If missing, assume:
- For async or high-throughput code, avoid slow network or file handlers on the hot path; consider `QueueHandler` and a listener.
- Avoid custom levels unless there is a strong interoperability reason.
## Examples
### `logging.basicConfig`
```python title="Bare minimum"
import logging
logging.basicConfig(level=logging.INFO, format="%(message)s")
logging.info("Hello, world!")
```
```python title="With a little formatting"
import logging
logging.basicConfig(
level=logging.DEBUG,
format="%(asctime)s.%(msecs)03d %(levelname)-8s %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
)
logging.info("Hello, world!")
```
### `logging.config.dictConfig`
```python title="Minimal dictConfig example"
import logging
import logging.config
logging.config.dictConfig(
{
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"console": {
"format": "%(asctime)s.%(msecs)03d %(levelname)-8s %(message)s",
"datefmt": "%Y-%m-%dT%H:%M:%S",
}
},
"handlers": {
"console": {
"class": "logging.StreamHandler",
"formatter": "console",
}
},
"root": {"level": "INFO", "handlers": ["console"]},
}
)
logging.info("Hello world")
```
### Config Composition
Example function suitable for merging dicts for `dictConfig`
```python title="composed config"
from collections.abc import Iterable
from collections.abc import Mapping
from collections.abc import Sequence
from copy import copy
from functools import reduce
BASE = ...
CONSOLE = ...
JSON_FILE = ...
RICH = ...
def merge(a: Mapping, b: Mapping) -> Mapping:
"""Recursively merge config dicts"""
a = dict(a)
for k, v in b.items():
match a.get(k), v:
case Mapping() as inner, Mapping():
a[k] = merge(inner, v)
case Sequence() as inner, Iterable():
new = list(copy(inner))
a[k] = new + [sub_v for sub_v in v if sub_v not in new]
case _:
a[k] = v
return a
def configure_logging(
base_config: dict | None = None,
*,
enable_console: bool = True,
enable_file: bool = True,
enable_rich: bool = True,
) -> dict:
"""Configure logging using the merged configuration."""
configs = [base_config or BASE]
if enable_console:
configs.append(CONSOLE)
if enable_file:
configs.append(JSON_FILE)
if enable_rich:
configs.append(RICH)
final_config = dict(reduce(merge, configs))
logging.config.dictConfig(final_config)
return final_config
```
## Using dictConfig
Use `logging.config.dictConfig` when configuration should be centralized, data-driven, or richer than `basicConfig`.
@@ -74,45 +188,35 @@ Use `logging.config.dictConfig` when configuration should be centralized, data-d
4. Call `logging.config.dictConfig(LOGGING)` once during application startup.
5. Keep application logging calls unchanged when adding new destinations or formats.
### Minimal dictConfig Baseline
## Application Usage
```python title="logging_config.py"
import logging.config
Concrete examples of how logging should be configured and used.
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"console": {
"format": "%(asctime)s.%(msecs)03d %(levelname)s %(name)s %(message)s",
"datefmt": "%Y-%m-%d %H:%M:%S",
}
},
"handlers": {
"console": {
"class": "logging.StreamHandler",
"formatter": "console",
"stream": "ext://sys.stdout",
}
},
"root": {
"level": "INFO",
"handlers": ["console"],
},
}
!!! warning "It's important to avoid the obvious name of `logging.py` to avoid weird clashes with IDEs and python internals."
=== "dictConfig"
def configure_logging() -> None:
logging.config.dictConfig(LOGGING)
```
```python title="logging_config.py"
import logging.config
LOGGING = ...
def configure_logging() -> None:
logging.config.dictConfig(LOGGING)
```
=== "basicConfig"
```python title="logging_config.py"
import logging.config
LOGGING = ...
def configure_logging() -> None:
logging.basicConfig(**LOGGING)
```
```python title="app.py"
from .logging_config import configure_logging
configure_logging()
```
```python title="feature.py"
import logging
logger = logging.getLogger(__name__)
@@ -122,12 +226,20 @@ def run(count: int) -> None:
logger.info("Processing %s items", count)
```
```python title="main.py"
from app import run
from logging_config import configure_logging
configure_logging()
run(5)
```
## Branching Guidance
- If the code is a tiny script: use `basicConfig` once near the entry point and module loggers elsewhere.
- If the code is a library: remove handlers and configuration calls; document logger names and optionally add `NullHandler` at the package root.
- If structured logs are required: keep the same logger and handler topology, but switch formatter output to JSON or a structured formatter.
- If console and file output are needed: add one file or rotating-file handler and attach it centrally.
- If console and file output are needed: add one file or rotating-file handler and attach it centrally. For a queue-backed JSON file setup, use the [JSON file logging pattern](./references/json-file-logging.md).
- If multiple processes write to one file: use a queue/listener or process-safe collection path rather than opening the same file independently in each process.
- If logs must cross a network: send records to a receiver or collector from a queue-backed handler, keep the receiver responsible for final destinations, and avoid exposing unauthenticated logging ports.
- If a framework logger is noisy: add a named logger override with a level and leave unrelated logger propagation alone.
@@ -0,0 +1,176 @@
# JSON File Logging Pattern (Queue + Rotation)
Use this reference when you need machine-readable JSON logs written to rotating files without blocking caller threads.
This page captures the pattern used in the logging notebook example: configure a queue-backed root logger, route queued records to a rotating JSON file handler, and explicitly start and stop the `QueueListener` around workload execution.
## Pattern Overview
Use this topology:
```text
application code -> named logger/root logger -> QueueHandler -> QueueListener -> RotatingFileHandler(JSON)
```
Why this shape:
- `QueueHandler` keeps file I/O off the main execution path. See [Dealing with handlers that block](https://docs.python.org/3/howto/logging-cookbook.html#dealing-with-handlers-that-block).
- `RotatingFileHandler` bounds disk usage and preserves recent history in backups. See [RotatingFileHandler](https://docs.python.org/3/library/logging.handlers.html#rotatingfilehandler).
- A JSON formatter makes logs easy to parse for automation and analytics. See [python-json-logger](https://nhairs.github.io/python-json-logger/latest/).
## Configuration Example
```python title="logging_config.py"
import logging
import logging.config
LOGGING = {
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"console": {
"format": "%(asctime)s.%(msecs)03d %(levelname)-8s %(message)s",
"datefmt": "%Y-%m-%d %H:%M:%S",
},
"json": {
"()": "pythonjsonlogger.json.JsonFormatter",
"format": "pathname,lineno,taskName,created,name,levelname,message,args",
"style": ",",
"rename_fields": {"levelname": "level"},
},
},
"handlers": {
"console": {
"class": "logging.StreamHandler",
"formatter": "console",
"level": "INFO",
},
"queue": {
"class": "logging.handlers.QueueHandler",
"handlers": ["file"],
},
"file": {
"class": "logging.handlers.RotatingFileHandler",
"filename": "app.log",
"maxBytes": 1024**2 * 5,
"backupCount": 5,
"formatter": "json",
},
},
"root": {"level": "DEBUG", "handlers": ["queue", "console"]},
}
logging.config.dictConfig(LOGGING)
```
Notes:
- Queue/listener configuration through `dictConfig` is documented in [Configuring QueueHandler and QueueListener](https://docs.python.org/3/library/logging.config.html#configuring-queuehandler-and-queuelistener).
- `disable_existing_loggers: False` is usually safer unless you intentionally want to disable existing non-root loggers.
## Listener Lifecycle Pattern
When using queue-backed logging, treat listener startup and shutdown as explicit lifecycle responsibilities.
```python title="listener_lifecycle.py"
import logging
import warnings
from collections.abc import Callable
from contextlib import contextmanager
from functools import cache
from logging.handlers import QueueHandler, QueueListener
@cache
def get_listener(queue_handler_name: str) -> QueueListener | None:
match logging.getHandlerByName(queue_handler_name):
case QueueHandler(listener=QueueListener() as listener):
return listener
def _listener_action(queue_handler_name: str, action: Callable[[QueueListener], None]):
match get_listener(queue_handler_name):
case QueueListener() as listener:
action(listener)
return listener
def start_listener(queue_handler_name: str) -> None:
listener = _listener_action(queue_handler_name, lambda listener: listener.start())
if listener is None:
warnings.warn(f"{queue_handler_name} is not set up correctly", stacklevel=2)
return
def stop_listener(queue_handler_name: str) -> None:
_listener_action(queue_handler_name, lambda listener: listener.stop())
@contextmanager
def listener_lifespan(queue_handler_name: str):
start_listener(queue_handler_name)
try:
yield
finally:
stop_listener(queue_handler_name)
with listener_lifespan("queue"):
logging.info("Started")
for _ in range(10**6):
logging.debug("Hello world")
logging.info("Done")
logging.info("Console only")
```
This demonstrates deterministic listener startup/shutdown around the active workload
Docs for APIs used above:
- [`logging.getHandlerByName`](https://docs.python.org/3/library/logging.html#logging.getHandlerByName)
- [`QueueHandler`](https://docs.python.org/3/library/logging.handlers.html#queuehandler)
- [`QueueListener`](https://docs.python.org/3/library/logging.handlers.html#queuelistener)
- [`contextlib.contextmanager`](https://docs.python.org/3/library/contextlib.html#contextlib.contextmanager)
- [`functools.cache`](https://docs.python.org/3/library/functools.html#functools.cache)
## Reading JSON Logs Back
For quick validation, read recent lines and deserialize JSON:
```python title="inspect_logs.py"
import json
from collections import deque
from pathlib import Path
def read_last_n_lines(file: str | Path, *, n: int):
with Path(file).open("r") as f:
return deque(f, maxlen=n)
lines = read_last_n_lines("app.log", n=5)
records = list(map(json.loads, lines))
```
For rotated logs, enumerate files by basename and sort by modification time before reading.
## Practical Checks
Before calling this done:
1. Confirm listener startup and shutdown run for the workload lifecycle.
2. Confirm `app.log` receives JSON lines, not plain text.
3. Confirm rotation occurs at the expected size and backup count.
4. Confirm console output still appears at the desired level.
5. Confirm exceptions and key context fields are preserved in JSON output.
## Source Links
- [Logging Cookbook](https://docs.python.org/3/howto/logging-cookbook.html)
- [logging.config reference](https://docs.python.org/3/library/logging.config.html)
- [Configuring QueueHandler and QueueListener](https://docs.python.org/3/library/logging.config.html#configuring-queuehandler-and-queuelistener)
- [logging handlers reference](https://docs.python.org/3/library/logging.handlers.html)
- [LogRecord attributes](https://docs.python.org/3/library/logging.html#logrecord-attributes)
- [python-json-logger docs](https://nhairs.github.io/python-json-logger/latest/)