4 Commits
Author SHA1 Message Date
dsql 33d61633af fix: bump __version__ to 0.2.0 to match pyproject/tag
__init__.py still reported __version__ = 0.1.1 while pyproject, README, and the tag are 0.2.0 — the one version-metadata drift across the libs. bumped to 0.2.0 so __version__/pyproject/tag agree.

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-06-29 01:10:25 -04:00
dsql 871471dd58 fix: prune log_dir on every roll so daily/size retention is enforced
TimedRotatingFileHandler/RotatingFileHandler retention (getFilesToDelete) only scans the live file's directory, never the log_dir we redirect rolled files into, so daily (the default) and size modes never pruned and .gz files grew unbounded. the rotator now calls the existing prune(log_dir, stem, backup_count) helper (the one on_start already uses) after each roll. verified by execution: daily and size both retain exactly backup_count; a no-prune control retains all.

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-06-28 18:45:25 -04:00
dsql 54151b9835 feat: structured JSON output mode (output="json")
add a selectable output format to setup_logging: text (default, human,
local time) stays unchanged; output="json" emits one-JSON-object-per-line
(JSON Lines) for the Grafana/Loki path. json fields are time (UTC ISO-8601
with Z), level, module, message, plus any extra={...} keys surfaced as
top-level fields and a rendered exc_info traceback on error records. both
file and console use the chosen format; the live-file name is unchanged so
the Promtail glob and tail command don't break across text/json. an unknown
output falls back to text and warns, never crashes. stdlib json only, zero
new deps. minor bump to v0.2.0.

Signed-off-by: disqualifier <dev@disqualifier.me>
2026-06-28 17:16:25 -04:00
dsql 84e1744d6f fix: never crash on a bad level= string (v0.1.1)
_level_value used logging.getLevelName(name), which returns the string 'Level XXX'
for an unknown name; that string then reached setLevel() and raised ValueError,
violating the 'never crashes the app over logging' contract. validate the result is
an int and fall back to INFO otherwise.

verified: level='BOGUS' -> INFO (no crash); 'DEBUG' and int levels still honored.
Signed-off-by: disqualifier <dev@disqualifier.me>
2026-06-27 21:49:20 -04:00
6 changed files with 140 additions and 25 deletions
+38 -5
View File
@@ -13,7 +13,7 @@ and emit; their records flow into the handlers `log_setup` wired.
## Install ## Install
``` ```
log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v0.1.0 log_setup @ git+ssh://git@git.rethinkstudios.io/rethink-public/log_setup.git@v0.2.0
``` ```
No dependencies — stdlib only. No dependencies — stdlib only.
@@ -52,6 +52,37 @@ emits; the records land in the configured root.
- **console=True** (off by default) also logs to stdout in the same format — opt in when - **console=True** (off by default) also logs to stdout in the same format — opt in when
you want live terminal output alongside the file. you want live terminal output alongside the file.
## Output format (`output=`)
Two formats, two needs. Default is `"text"`; the live-file name is the same either way
(`run.log`, never auto-renamed), so a service can switch text↔json without breaking the
Promtail glob, bind-mount path, or your `tail` command.
- **`output="text"`** (default) — human-readable
`2026-06-27 19:55:05 | module.name | INFO | message`, **local time**. The
single-machine `tail -f` path. `fmt`/`datefmt` override it. Unchanged from v0.1.x.
- **`output="json"`** — structured **one JSON object per line** (JSON Lines) for the
Grafana/Loki pipeline (Promtail → Loki → Grafana); Loki parses JSON fields into labels
natively, no regex.
```python
setup_logging(name="run", output="json")
logging.getLogger("bot.core").info("ready", extra={"monitor": "heartbeat"})
# -> {"time": "2026-06-28T14:03:11Z", "level": "INFO", "module": "bot.core",
# "message": "ready", "monitor": "heartbeat"}
```
- **Fields:** `time`, `level`, `module`, `message` always; any `extra={...}` keys land
as **top-level** fields (stamp `monitor`/`service`/request-id for Loki labels — the lib
stays domain-agnostic); error records carry the traceback in `exc_info` (never dropped).
- **Time is UTC ISO-8601 with a `Z`** (`2026-06-28T14:03:11Z`), not local. json is the
aggregation path — logs from many servers/containers sort unambiguously only in UTC;
Grafana converts to local for display. (Text mode stays local — that's a human on one
box.)
- Both file and console use the chosen format. `fmt`/`datefmt` apply to text only (json
builds fields, not a format string). An unknown `output` falls back to text + warns,
never crashes. **Zero new deps** — stdlib `json` only.
## Signature ## Signature
```python ```python
@@ -65,8 +96,9 @@ setup_logging(
compress=True, # gzip rolled files compress=True, # gzip rolled files
console=False, # also log to stdout (off by default; opt in) console=False, # also log to stdout (off by default; opt in)
queue=False, # route through a background QueueListener (async-friendly) queue=False, # route through a background QueueListener (async-friendly)
fmt=None, # override the format string output="text", # "text" (human, local time) | "json" (structured, UTC)
datefmt=None, # override the date format fmt=None, # override the text format string (text mode only)
datefmt=None, # override the text date format (text mode only)
) -> logging.Logger # returns the configured root logger ) -> logging.Logger # returns the configured root logger
``` ```
@@ -97,8 +129,9 @@ handlers. Getting files to a backend is a separate concern (e.g. Promtail tails
backend can change without touching any app, and the consistent format here is what backend can change without touching any app, and the consistent format here is what
makes downstream parsing and alerting easy. makes downstream parsing and alerting easy.
Also out of v0.1.0 (possible later additions): structured/JSON logging, color Structured/JSON output is **in** as of v0.2.0 (`output="json"`) — text and json only.
formatting, per-logger filters, remote handlers. Still deliberately out: logfmt or other formats, a format DSL, per-handler formats,
color formatting, per-logger filters, remote handlers.
## Versioning ## Versioning
+1 -1
View File
@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
[project] [project]
name = "log_setup" name = "log_setup"
version = "0.1.0" version = "0.2.0"
description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format" description = "stdlib app-entry-point logging setup: live run.log, rotation, gzip, retention, consistent format"
requires-python = ">=3.10" requires-python = ">=3.10"
dependencies = [] dependencies = []
+1 -1
View File
@@ -19,4 +19,4 @@ from .setup import setup_logging
__all__ = ["setup_logging"] __all__ = ["setup_logging"]
__version__ = "0.1.0" __version__ = "0.2.0"
+57 -5
View File
@@ -1,15 +1,67 @@
"""default log format + datefmt for the app-wide setup. """log formats for the app-wide setup: human-readable text + structured JSON lines.
one format for v0.1.0, used on both console and file. `%(name)s` is the getLogger two output formats, two proven needs. `text` (default) is the human `tail -f` format
name the emitting module used, so each library/module shows in the line. (`time | module | level | message`, local time). `json` is the Grafana/Loki path —
one JSON object per line (JSON Lines), fields parsed into labels natively, UTC
timestamps so logs aggregated from many machines/containers sort unambiguously.
`%(name)s` is the getLogger name the emitting module used, so each module shows.
""" """
import datetime
import json
import logging import logging
DEFAULT_FORMAT = "%(asctime)s | %(name)s | %(levelname)s | %(message)s" DEFAULT_FORMAT = "%(asctime)s | %(name)s | %(levelname)s | %(message)s"
DEFAULT_DATEFMT = "%Y-%m-%d %H:%M:%S" DEFAULT_DATEFMT = "%Y-%m-%d %H:%M:%S"
_RESERVED = frozenset(vars(logging.makeLogRecord({})).keys()) | {"message", "asctime"}
def build_formatter(fmt=None, datefmt=None) -> logging.Formatter:
"""build a logging.Formatter from overrides, falling back to the defaults""" class JsonLinesFormatter(logging.Formatter):
"""format each record as a single-line JSON object (JSON Lines / .jsonl)
emits at minimum time/level/module/message. time is UTC ISO-8601 with a `Z`
suffix (e.g. 2026-06-28T14:03:11Z) so logs aggregated across machines and
containers sort unambiguously — Grafana converts to local for display. any
field passed via logging `extra={...}` lands as a top-level JSON field, which
is how a caller stamps monitor/service/request-id for Loki labels without the
lib knowing those domain concepts. a traceback (exc_info) is rendered into an
`exc_info` string field rather than dropped.
"""
def format(self, record: logging.LogRecord) -> str:
when = datetime.datetime.fromtimestamp(record.created, datetime.timezone.utc)
payload = {
"time": when.strftime("%Y-%m-%dT%H:%M:%SZ"),
"level": record.levelname,
"module": record.name,
"message": record.getMessage(),
}
for key, value in record.__dict__.items():
if key not in _RESERVED and not key.startswith("_"):
payload[key] = value
if record.exc_info:
payload["exc_info"] = self.formatException(record.exc_info)
elif record.exc_text:
payload["exc_info"] = record.exc_text
if record.stack_info:
payload["stack_info"] = self.formatStack(record.stack_info)
return json.dumps(payload, default=str)
def build_formatter(output: str = "text", fmt=None, datefmt=None) -> logging.Formatter:
"""build the formatter for the chosen output format
`output="text"` (default) returns the human-readable text formatter, honoring
the raw `fmt`/`datefmt` format-string overrides. `output="json"` returns the
structured `JsonLinesFormatter` (which ignores `fmt`/`datefmt` — it builds
fields, not a format string). an unrecognized `output` falls back to text and
warns, never raising — a bad format arg must not take the app down.
"""
if output == "json":
return JsonLinesFormatter()
if output != "text":
logging.getLogger(__name__).warning(
"log_setup: unknown output %r; falling back to 'text'", output
)
return logging.Formatter(fmt or DEFAULT_FORMAT, datefmt or DEFAULT_DATEFMT) return logging.Formatter(fmt or DEFAULT_FORMAT, datefmt or DEFAULT_DATEFMT)
+25 -6
View File
@@ -10,7 +10,7 @@ import gzip
import os import os
import shutil import shutil
import time import time
from typing import Callable, Tuple from typing import Callable, Optional, Tuple
def make_namer(log_dir: str, compress: bool) -> Callable[[str], str]: def make_namer(log_dir: str, compress: bool) -> Callable[[str], str]:
@@ -26,8 +26,18 @@ def make_namer(log_dir: str, compress: bool) -> Callable[[str], str]:
return namer return namer
def make_rotator(compress: bool) -> Callable[[str, str], None]: def make_rotator(
"""rotator: move (or gzip) the source live file to the destination rolled path""" compress: bool, log_dir: Optional[str] = None,
prune_stem: Optional[str] = None, backup_count: int = 0,
) -> Callable[[str, str], None]:
"""rotator: move (or gzip) the source live file to the destination rolled path
prunes `log_dir` to `backup_count` newest rolled files after each roll when
`log_dir`/`prune_stem` are given. the stdlib handler's own retention
(`getFilesToDelete`) only scans the live file's directory, so it never sees the
rolled files we redirect into `log_dir` — pruning here is what actually bounds
retention for the daily and size rolling modes.
"""
def rotator(source: str, dest: str) -> None: def rotator(source: str, dest: str) -> None:
if not os.path.exists(source): if not os.path.exists(source):
return return
@@ -37,6 +47,8 @@ def make_rotator(compress: bool) -> Callable[[str, str], None]:
os.remove(source) os.remove(source)
else: else:
os.replace(source, dest) os.replace(source, dest)
if log_dir is not None and prune_stem is not None:
prune(log_dir, prune_stem, backup_count)
return rotator return rotator
@@ -93,10 +105,17 @@ def _safe_mtime(path: str) -> float:
return 0.0 return 0.0
def attach_rolling(handler, log_dir: str, compress: bool) -> Tuple[Callable, Callable]: def attach_rolling(
"""wire the custom namer + rotator onto a rotating handler; return them""" handler, log_dir: str, compress: bool,
prune_stem: Optional[str] = None, backup_count: int = 0,
) -> Tuple[Callable, Callable]:
"""wire the custom namer + rotator onto a rotating handler; return them
pass `prune_stem`/`backup_count` so the rotator prunes `log_dir` after each roll
(the handler's own retention can't see the redirected rolled files).
"""
namer = make_namer(log_dir, compress) namer = make_namer(log_dir, compress)
rotator = make_rotator(compress) rotator = make_rotator(compress, log_dir, prune_stem, backup_count)
handler.namer = namer handler.namer = namer
handler.rotator = rotator handler.rotator = rotator
return namer, rotator return namer, rotator
+18 -7
View File
@@ -28,7 +28,12 @@ def _level_value(level: Union[int, str]) -> int:
"""coerce a level name or int to a logging level int (defaults to INFO)""" """coerce a level name or int to a logging level int (defaults to INFO)"""
if isinstance(level, int): if isinstance(level, int):
return level return level
return logging.getLevelName(str(level).upper()) if isinstance(level, str) else logging.INFO if not isinstance(level, str):
return logging.INFO
resolved = logging.getLevelName(level.upper())
# getLevelName returns the string "Level XXX" for an unknown name, which
# setLevel then rejects — never crash the app over a bad level, fall back to INFO
return resolved if isinstance(resolved, int) else logging.INFO
def _clear_owned(root: logging.Logger) -> None: def _clear_owned(root: logging.Logger) -> None:
@@ -61,12 +66,12 @@ def _file_handler(
handler = logging.handlers.RotatingFileHandler( handler = logging.handlers.RotatingFileHandler(
live_path, maxBytes=max_bytes, backupCount=backup_count, encoding="utf-8", live_path, maxBytes=max_bytes, backupCount=backup_count, encoding="utf-8",
) )
attach_rolling(handler, log_dir, compress) attach_rolling(handler, log_dir, compress, prune_stem=name, backup_count=backup_count)
elif rotate == "daily": elif rotate == "daily":
handler = logging.handlers.TimedRotatingFileHandler( handler = logging.handlers.TimedRotatingFileHandler(
live_path, when="midnight", backupCount=backup_count, encoding="utf-8", live_path, when="midnight", backupCount=backup_count, encoding="utf-8",
) )
attach_rolling(handler, log_dir, compress) attach_rolling(handler, log_dir, compress, prune_stem=name, backup_count=backup_count)
else: else:
if rotate == "on_start": if rotate == "on_start":
rotate_on_start(live_path, log_dir, compress) rotate_on_start(live_path, log_dir, compress)
@@ -85,6 +90,7 @@ def setup_logging(
compress: bool = True, compress: bool = True,
console: bool = False, console: bool = False,
queue: bool = False, queue: bool = False,
output: str = "text",
fmt: Optional[str] = None, fmt: Optional[str] = None,
datefmt: Optional[str] = None, datefmt: Optional[str] = None,
) -> logging.Logger: ) -> logging.Logger:
@@ -94,9 +100,14 @@ def setup_logging(
`rotate` is "daily" (default), "size", "on_start", or None. `console=True` adds a `rotate` is "daily" (default), "size", "on_start", or None. `console=True` adds a
stdout handler (off by default — the file is the output). `queue=True` routes records stdout handler (off by default — the file is the output). `queue=True` routes records
through a background QueueListener so file I/O never blocks the caller (the listener through a background QueueListener so file I/O never blocks the caller (the listener
is stopped at exit). idempotent: a repeat call clears only the handlers this function is stopped at exit). `output` is "text" (default, human `time | module | level |
added. never raises over logging — an unwritable `log_dir` falls back to console-only message`, local time) or "json" (structured one-JSON-object-per-line for the
with a warning even when `console` is off, so output is never silently lost. Grafana/Loki path, UTC timestamps, `extra=` fields surfaced as top-level keys); both
file and console use the chosen format and the live-file name is the same regardless.
the raw `fmt`/`datefmt` overrides apply to text output only. idempotent: a repeat call
clears only the handlers this function added. never raises over logging — an
unwritable `log_dir` falls back to console-only with a warning even when `console` is
off, so output is never silently lost; an unknown `output` falls back to text.
""" """
global _listener global _listener
@@ -104,7 +115,7 @@ def setup_logging(
root.setLevel(_level_value(level)) root.setLevel(_level_value(level))
_clear_owned(root) _clear_owned(root)
formatter = build_formatter(fmt, datefmt) formatter = build_formatter(output, fmt, datefmt)
live_path = f"{name}.log" live_path = f"{name}.log"
handlers = [] handlers = []