From 8bfb8468b49a2cc615ac7d483bd90c02ffb82422 Mon Sep 17 00:00:00 2001 From: Crespin Alexandre <114501859+kunail0804@users.noreply.github.com> Date: Tue, 7 Jul 2026 19:17:00 +0200 Subject: [PATCH] feat(compiler): add centralized structured logging (#6) (#50) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Implement structured, machine-readable logging per MASTER_SPEC §22, §25.7 in compiler/common/log.py. - DebugLevel IntEnum with the four levels (None/Basic/Verbose/Developer), ordered; DebugLevel.from_config maps a debug config section to a threshold (disabled -> None). - LogRecord: immutable structured record (level, event, fields) with a machine-readable to_json; no timestamps, so logging stays deterministic. - StructuredLogger: filters by threshold, emits to an injectable sink, and offers basic/verbose/developer helpers plus from_config. No global state. - json_lines_sink writes one JSON object per line to a stream (never print). - Tighten configuration.schema.json debug.level to enum none/basic/verbose/developer. Tests: level filtering across all four levels, structured/immutable records, config integration, and a guard asserting no print() exists in the compiler package. Co-authored-by: kunail0804 Co-authored-by: Claude Opus 4.8 --- compiler/common/log.py | 125 +++++++++++++++++++++++ schemas/json/configuration.schema.json | 2 +- tests/test_logging.py | 133 +++++++++++++++++++++++++ 3 files changed, 259 insertions(+), 1 deletion(-) create mode 100644 compiler/common/log.py create mode 100644 tests/test_logging.py diff --git a/compiler/common/log.py b/compiler/common/log.py new file mode 100644 index 0000000..e49d47c --- /dev/null +++ b/compiler/common/log.py @@ -0,0 +1,125 @@ +"""Centralized structured logging for the compiler (MASTER_SPEC §22, §25.7). + +Logs are structured :class:`LogRecord` objects — never free-form strings — so +they can be consumed programmatically without parsing. Emission is filtered by a +:class:`DebugLevel` threshold driven by configuration (``config.debug``), and the +compiler never calls ``print``. + +Records carry no timestamp so that logging stays deterministic and testable. The +output destination is an injectable ``sink`` callable; the ComfyUI nodes (or a +test) supply one. :func:`json_lines_sink` provides a ready-made sink that writes +one JSON object per line to a stream. +""" + +from __future__ import annotations + +import json +import sys +from collections.abc import Callable, Mapping +from dataclasses import dataclass, field +from enum import IntEnum +from types import MappingProxyType +from typing import IO, Any + +_EMPTY_FIELDS: Mapping[str, Any] = MappingProxyType({}) + + +class DebugLevel(IntEnum): + """Debug verbosity levels (§22.1), ordered from least to most verbose.""" + + NONE = 0 + BASIC = 1 + VERBOSE = 2 + DEVELOPER = 3 + + @classmethod + def from_config(cls, *, enabled: bool, level: str) -> DebugLevel: + """Resolve the active level from a ``debug`` config section. + + When debugging is disabled the level is always :attr:`NONE`, regardless + of the configured ``level``. + + Raises: + ValueError: If ``level`` is not a known level name. + """ + if not enabled: + return cls.NONE + try: + return cls[level.upper()] + except KeyError: + raise ValueError(f"Unknown debug level '{level}'.") from None + + +@dataclass(frozen=True) +class LogRecord: + """A single structured log record.""" + + level: DebugLevel + event: str + fields: Mapping[str, Any] = field(default_factory=lambda: _EMPTY_FIELDS) + + def __post_init__(self) -> None: + if not isinstance(self.fields, MappingProxyType): + frozen = MappingProxyType(dict(self.fields)) if self.fields else _EMPTY_FIELDS + object.__setattr__(self, "fields", frozen) + + def to_json(self) -> dict[str, Any]: + return { + "level": self.level.name.lower(), + "event": self.event, + "fields": dict(self.fields), + } + + +class StructuredLogger: + """Emits structured log records filtered by a configured :class:`DebugLevel`. + + A record is emitted only when its level is not :attr:`DebugLevel.NONE` and is + at or below the logger's threshold. Emission goes to the injected ``sink``; + without a sink the logger is silent but still returns the (unemitted) record. + """ + + def __init__( + self, + level: DebugLevel = DebugLevel.NONE, + sink: Callable[[LogRecord], None] | None = None, + ) -> None: + self.level = level + self._sink = sink + + @classmethod + def from_config(cls, config: Any, sink: Callable[[LogRecord], None] | None = None): + """Build a logger from a Config's ``debug`` section.""" + level = DebugLevel.from_config(enabled=config.debug.enabled, level=config.debug.level) + return cls(level=level, sink=sink) + + def log(self, level: DebugLevel, event: str, **fields: Any) -> LogRecord | None: + """Emit a record at ``level``; return it, or None if filtered out.""" + if level == DebugLevel.NONE or level > self.level: + return None + record = LogRecord(level=level, event=event, fields=fields) + if self._sink is not None: + self._sink(record) + return record + + def basic(self, event: str, **fields: Any) -> LogRecord | None: + return self.log(DebugLevel.BASIC, event, **fields) + + def verbose(self, event: str, **fields: Any) -> LogRecord | None: + return self.log(DebugLevel.VERBOSE, event, **fields) + + def developer(self, event: str, **fields: Any) -> LogRecord | None: + return self.log(DebugLevel.DEVELOPER, event, **fields) + + +def json_lines_sink(stream: IO[str] | None = None) -> Callable[[LogRecord], None]: + """Return a sink that writes each record as one JSON line to ``stream``. + + Defaults to ``sys.stderr``. Uses ``json.dumps`` (never ``print``). + """ + target = stream if stream is not None else sys.stderr + + def _sink(record: LogRecord) -> None: + target.write(json.dumps(record.to_json(), sort_keys=True) + "\n") + + return _sink diff --git a/schemas/json/configuration.schema.json b/schemas/json/configuration.schema.json index b080aa7..24d4a8e 100644 --- a/schemas/json/configuration.schema.json +++ b/schemas/json/configuration.schema.json @@ -52,7 +52,7 @@ "additionalProperties": false, "properties": { "enabled": { "type": "boolean" }, - "level": { "type": "string" } + "level": { "type": "string", "enum": ["none", "basic", "verbose", "developer"] } } } } diff --git a/tests/test_logging.py b/tests/test_logging.py new file mode 100644 index 0000000..5d4bf13 --- /dev/null +++ b/tests/test_logging.py @@ -0,0 +1,133 @@ +"""Tests for the structured logger (issue #6, MASTER_SPEC §22, §25.7).""" + +from __future__ import annotations + +import dataclasses +from pathlib import Path + +import pytest + +from compiler.common.config import Config +from compiler.common.log import DebugLevel, LogRecord, StructuredLogger + +# --- DebugLevel ------------------------------------------------------------ + + +def test_four_debug_levels_ordered() -> None: + assert DebugLevel.NONE < DebugLevel.BASIC < DebugLevel.VERBOSE < DebugLevel.DEVELOPER + + +def test_debug_level_from_config_disabled_is_none() -> None: + assert DebugLevel.from_config(enabled=False, level="basic") is DebugLevel.NONE + + +@pytest.mark.parametrize( + ("level", "expected"), + [ + ("basic", DebugLevel.BASIC), + ("verbose", DebugLevel.VERBOSE), + ("developer", DebugLevel.DEVELOPER), + ("none", DebugLevel.NONE), + ], +) +def test_debug_level_from_config_enabled(level: str, expected: DebugLevel) -> None: + assert DebugLevel.from_config(enabled=True, level=level) is expected + + +def test_unknown_level_raises() -> None: + with pytest.raises(ValueError): + DebugLevel.from_config(enabled=True, level="bogus") + + +# --- filtering ------------------------------------------------------------- + + +def make_logger(level: DebugLevel) -> tuple[StructuredLogger, list[LogRecord]]: + sink: list[LogRecord] = [] + return StructuredLogger(level=level, sink=sink.append), sink + + +def test_basic_logger_emits_basic_only() -> None: + logger, sink = make_logger(DebugLevel.BASIC) + assert logger.basic("stage_started", stage="resolver") is not None + assert logger.verbose("detail") is None + assert logger.developer("trace") is None + assert [r.event for r in sink] == ["stage_started"] + + +def test_developer_logger_emits_all() -> None: + logger, sink = make_logger(DebugLevel.DEVELOPER) + logger.basic("a") + logger.verbose("b") + logger.developer("c") + assert [r.event for r in sink] == ["a", "b", "c"] + + +def test_none_logger_emits_nothing() -> None: + logger, sink = make_logger(DebugLevel.NONE) + logger.basic("a") + logger.verbose("b") + logger.developer("c") + assert sink == [] + + +def test_verbose_logger_emits_basic_and_verbose() -> None: + logger, sink = make_logger(DebugLevel.VERBOSE) + logger.basic("a") + logger.verbose("b") + logger.developer("c") + assert [r.event for r in sink] == ["a", "b"] + + +# --- structured records ---------------------------------------------------- + + +def test_record_is_structured_not_a_string() -> None: + logger, sink = make_logger(DebugLevel.BASIC) + logger.basic("stage_started", stage="resolver", count=3) + record = sink[0] + assert record.event == "stage_started" + assert record.fields == {"stage": "resolver", "count": 3} + assert record.level is DebugLevel.BASIC + + +def test_record_to_json_machine_readable() -> None: + record = LogRecord(level=DebugLevel.VERBOSE, event="e", fields={"k": "v"}) + assert record.to_json() == {"level": "verbose", "event": "e", "fields": {"k": "v"}} + + +def test_record_is_immutable() -> None: + record = LogRecord(level=DebugLevel.BASIC, event="e", fields={}) + with pytest.raises(dataclasses.FrozenInstanceError): + record.event = "x" # type: ignore[misc] + + +# --- config integration ---------------------------------------------------- + + +def test_from_config_uses_debug_section() -> None: + config = Config.from_json({"debug": {"enabled": True, "level": "verbose"}}) + logger, sink = make_logger(DebugLevel.NONE) + logger = StructuredLogger.from_config(config, sink=sink.append) + assert logger.level is DebugLevel.VERBOSE + logger.verbose("ok") + assert [r.event for r in sink] == ["ok"] + + +def test_default_logger_is_silent_and_needs_no_sink() -> None: + # A logger without a sink must not raise when emitting. + logger = StructuredLogger(level=DebugLevel.DEVELOPER) + assert logger.basic("a") is not None # returns record, emits nowhere + + +# --- no print() in the compiler -------------------------------------------- + + +def test_no_print_in_compiler_package() -> None: + compiler_dir = Path(__file__).resolve().parent.parent / "compiler" + offenders = [ + py.relative_to(compiler_dir).as_posix() + for py in compiler_dir.rglob("*.py") + if "print(" in py.read_text(encoding="utf-8") + ] + assert offenders == [], f"print() found in compiler package: {offenders}"