fix(dashboard-auth): rotate dashboard-auth.log at 5MB/3 backups
audit_log() appended with a plain open(path, 'a') and no size cap, so dashboard-auth.log grew unbounded for the life of the install — the one log in the auth path outside hermes_logging's rotation. Add self-contained size-check-and-rename rotation in audit.py matching the agent.log convention (maxBytes=5MB, backupCount=3, stdlib .1/.2/.3 naming). The pending record's UTF-8 bytes count toward the threshold, so a crossing write rotates before appending. Implemented locally (stdlib os.replace only) to keep the module import-light for early-loading middleware; reusing _ManagedRotatingFileHandler would pull in hermes_constants and break that guarantee. Fixes #57749
This commit is contained in:
@@ -8,6 +8,7 @@ import datetime as _dt
|
||||
import enum
|
||||
import json
|
||||
import logging
|
||||
import os
|
||||
import threading
|
||||
from pathlib import Path
|
||||
from typing import Any
|
||||
@@ -17,6 +18,15 @@ _write_lock = threading.Lock()
|
||||
_MAX_FIELD_LENGTH = 256
|
||||
_TRUNCATION_MARKER = "...[truncated]"
|
||||
|
||||
# Size-based rotation matching hermes_logging's agent.log / errors.log convention
|
||||
# (maxBytes=5MB, backupCount=3, stdlib RotatingFileHandler ``.1``/``.2``/``.3`` naming).
|
||||
# Implemented locally (check-and-rename, stdlib only) rather than importing
|
||||
# hermes_logging/_ManagedRotatingFileHandler: that would pull in hermes_constants
|
||||
# (and lazily hermes_cli.config) and break this module's import-light guarantee —
|
||||
# it is imported by middleware that runs very early in startup.
|
||||
_MAX_BYTES = 5 * 1024 * 1024
|
||||
_BACKUP_COUNT = 3
|
||||
|
||||
# Field names that must never appear in the log raw; matching kwargs are dropped.
|
||||
_REDACTED_FIELDS: frozenset = frozenset({
|
||||
"access_token", "refresh_token", "code", "code_verifier",
|
||||
@@ -64,18 +74,41 @@ def _bounded_value(value: Any) -> Any:
|
||||
return value
|
||||
|
||||
|
||||
def _rotate_if_needed(path: Path, pending_bytes: int) -> None:
|
||||
"""Rotate ``path`` to ``.1``/…/``.<_BACKUP_COUNT>`` once appending *pending_bytes* would
|
||||
reach ``_MAX_BYTES``. Mirrors stdlib ``RotatingFileHandler``'s naming; must be called
|
||||
with ``_write_lock`` held. Rotation errors must not break the write path."""
|
||||
try:
|
||||
if path.stat().st_size + pending_bytes < _MAX_BYTES:
|
||||
return
|
||||
except OSError:
|
||||
return # missing/vanished mid-check; the append itself surfaces real errors
|
||||
try:
|
||||
for i in range(_BACKUP_COUNT - 1, 0, -1):
|
||||
src = path.with_name(f"{path.name}.{i}")
|
||||
if src.exists():
|
||||
os.replace(src, path.with_name(f"{path.name}.{i + 1}"))
|
||||
os.replace(path, path.with_name(f"{path.name}.1"))
|
||||
except OSError:
|
||||
pass # a log that cannot be rotated is still a working (if overlong) log
|
||||
|
||||
|
||||
def audit_log(event: AuditEvent, **fields: Any) -> None:
|
||||
"""Append one event; token-like fields dropped, log dir created. Write failures are logged at
|
||||
WARNING but never raise — auth must not fail because the audit logger broke."""
|
||||
"""Append one event; token-like fields dropped, log dir created, size-capped rotation
|
||||
(``_MAX_BYTES`` with ``_BACKUP_COUNT`` backups). Write failures are logged at WARNING
|
||||
but never raise — auth must not fail because the audit logger broke."""
|
||||
try:
|
||||
entry = {
|
||||
"ts": _dt.datetime.now(_dt.timezone.utc).isoformat(),
|
||||
"event": event.value,
|
||||
**{k: _bounded_value(v) for k, v in fields.items() if k not in _REDACTED_FIELDS}}
|
||||
line = json.dumps(entry, separators=(",", ":")) + "\n"
|
||||
line_bytes = line.encode("utf-8")
|
||||
path = _resolve_log_path()
|
||||
path.parent.mkdir(parents=True, exist_ok=True)
|
||||
with _write_lock, open(path, "a", encoding="utf-8") as f:
|
||||
f.write(line)
|
||||
with _write_lock:
|
||||
_rotate_if_needed(path, len(line_bytes))
|
||||
with open(path, "ab") as f:
|
||||
f.write(line_bytes)
|
||||
except Exception as e:
|
||||
_log.warning("dashboard-auth audit log write failed: %s", e)
|
||||
|
||||
@@ -67,6 +67,43 @@ def test_audit_writes_jsonlines(profile_home):
|
||||
assert "ts" in second # ISO-8601 timestamp
|
||||
|
||||
|
||||
def test_audit_rotates_when_over_max_bytes(profile_home, monkeypatch):
|
||||
"""Rotation is bounded: at most ``_BACKUP_COUNT`` ``.N`` files, current log under the cap."""
|
||||
import hermes_cli.dashboard_auth.audit as audit_module
|
||||
|
||||
monkeypatch.setattr(audit_module, "_MAX_BYTES", 2000)
|
||||
monkeypatch.setattr(audit_module, "_BACKUP_COUNT", 3)
|
||||
|
||||
for i in range(500):
|
||||
audit_log(AuditEvent.LOGIN_START, provider="x" * 50, i=i)
|
||||
|
||||
logs = profile_home / "logs"
|
||||
assert (logs / "dashboard-auth.log").exists()
|
||||
for i in (1, 2, 3):
|
||||
assert (logs / f"dashboard-auth.log.{i}").exists()
|
||||
assert not (logs / "dashboard-auth.log.4").exists()
|
||||
assert (logs / "dashboard-auth.log").stat().st_size < 2000
|
||||
|
||||
|
||||
def test_audit_rotates_on_crossing_write(profile_home, monkeypatch):
|
||||
"""A write that pushes the file to/past the cap must rotate BEFORE appending (the pending
|
||||
line's bytes count toward the threshold), not stay over the cap until the next event."""
|
||||
import hermes_cli.dashboard_auth.audit as audit_module
|
||||
|
||||
monkeypatch.setattr(audit_module, "_MAX_BYTES", 200)
|
||||
monkeypatch.setattr(audit_module, "_BACKUP_COUNT", 3)
|
||||
|
||||
logs = profile_home / "logs"
|
||||
logs.mkdir()
|
||||
prior = logs / "dashboard-auth.log"
|
||||
prior.write_bytes(b"x" * 190)
|
||||
|
||||
audit_log(AuditEvent.LOGIN_START, provider="nous")
|
||||
|
||||
assert (logs / "dashboard-auth.log.1").read_bytes() == b"x" * 190
|
||||
assert prior.stat().st_size < 200
|
||||
|
||||
|
||||
def test_audit_redacts_token_like_fields(profile_home):
|
||||
audit_log(
|
||||
AuditEvent.LOGIN_SUCCESS,
|
||||
|
||||
Reference in New Issue
Block a user