From 9a0f220fd5a616cd1f655eceb4d3b0cbf971e61c Mon Sep 17 00:00:00 2001 From: goodboy Date: Fri, 16 Oct 2026 20:31:49 -0400 Subject: [PATCH] Fix built-in level names in `at_least_level()` The `CUSTOM_LEVELS`-only lookup raised `KeyError` for built-in log levels such as 'INFO'. Resolve other registered names through `logging.getLevelNamesMapping()` only when the custom lookup misses, without eagerly evaluating the fallback on custom hits. Deats, - keep custom precedence, case-insensitive names and `NOTSET=0`; - preserve integer inputs and unknown-name `KeyError` behavior; - keep logger-local and global `isEnabledFor()` disable controls; - advertise integer inputs on the adapter's `at_least_level()`; - add 62 raw/adapted regressions with explicit threshold examples and fixture docs distinguishing instance and global log state. The logging suite passed all 70 cases; the original Piker consumer probe passed 8/8 with its string-level feed guard retained. Prompt-IO: ai/prompt-io/20261011T053737Z_a966928d_prompt_io.md (this patch was generated in some part by `opencode` using `gpt-6.1-sol` (`openai`)) --- .../20261011T053737Z_a966928d_prompt_io.md | 142 +++++++++++++ ...20261011T053737Z_a966928d_prompt_io.raw.md | 34 +++ ai/prompt-io/README.md | 24 +++ tests/test_log_sys.py | 200 ++++++++++++++++++ tractor/log.py | 15 +- 5 files changed, 412 insertions(+), 3 deletions(-) create mode 100644 ai/prompt-io/20261011T053737Z_a966928d_prompt_io.md create mode 100644 ai/prompt-io/20261011T053737Z_a966928d_prompt_io.raw.md create mode 100644 ai/prompt-io/README.md diff --git a/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.md b/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.md new file mode 100644 index 00000000..c854b9d0 --- /dev/null +++ b/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.md @@ -0,0 +1,142 @@ +--- +created_at: 2026-10-11T05:37:37Z +generated_by: + harness: opencode + provider: openai + model: openai/gpt-6.1-sol +git_ref: wkt/address_logging_levels +scope: code +substantive: true +raw_file: 20261011T053737Z_a966928d_prompt_io.raw.md +--- + +## Prompt + +The user supplied this original request: + +> maybe we can add a commit to tractor on top of addr_unpacking, +> also scan for any other downstream from main logging history and +> cherry it there and then add your fix, and finally move piker_pin +> to that? rather not hackaround bug alreadypinningnonmain + +The current instruction narrowed execution to a managed Tractor +worktree, `wkt/address_logging_levels`, starting at the verified +`addr_unpacking` OID a966928dead4cbf369ad244834ce9dbe988ac8ca. +Scan local logging history, preserve relevant originals where +possible, implement the standard-name fix with meaningful tests, +and verify Piker's original cache-hit regression through an import +overlay. Leave changes uncommitted for human review and leave +`piker_pin`, Piker's workaround, environments, and lockfiles intact. + +## Response summary + +Created the managed worktree and recorded approved local discovery +in Git administrative storage. No equivalent name-resolution fix +or additional prerequisite was found. Patch-ID comparisons of +`tractor/log.py` and `tests/test_log_sys.py` identified these +already-landed equivalents: + +- d653cd2c -> a2c8af55: fast caller lookup. +- 4f811a87 -> d1d3fc58: lazy optional imports. +- 361f6fcc and other copies -> bb0b2ffa: custom-level factory. +- 11b9a870 and other copies -> b6bf865f: nested logger names. +- 74784780 and other copies -> 8bb9df9e: logging-spec API. + +The base also includes 88cc68ed (custom-level re-registration), +67280c28 (disable-aware guards), and 089e158d (dynamic caller +fallback). The non-equivalent 53e10861 thread-header change is +unrelated and was excluded. No cherry-pick was needed. + +The source fix uses public stdlib name resolution after Tractor's +custom-level lookup. It keeps the existing `KeyError` contract +instead of introducing a `ValueError` compatibility change. + +## Files changed + +- `tractor/log.py`: standard/application name resolution and + integer-capable adapter annotation. +- `tests/test_log_sys.py`: 62 raw/adapted regression cases with + detailed failure-mechanism documentation and isolated log state. +- `ai/prompt-io/README.md`: shared provenance policy. +- This structured record and its immutable raw partner. + +## Verification + +Run from the new Tractor worktree: + +```xsh +env PYTHONPATH=/home/goodboy/repos/tractor/wkts/address_logging_levels /home/goodboy/repos/tractor/py313/bin/python -m pytest tests/test_log_sys.py -k at_least_level +``` + +Before the source fix: 30 failed, 32 passed, 8 deselected. Failures +were name-lookup `KeyError`s, including INFO and NOTSET. + +```xsh +env PYTHONPATH=/home/goodboy/repos/tractor/wkts/address_logging_levels /home/goodboy/repos/tractor/py313/bin/python -m pytest tests/test_log_sys.py +/nix/store/qmrz7inmmlfmx1nghix8ymghh5yd9gnv-ruff-0.15.22/bin/ruff check tractor/log.py tests/test_log_sys.py +git diff --check +``` + +After the fix: 70 passed; Ruff and whitespace checks passed. +Tractor tests used CPython 3.13.11 and pytest 9.1.0. Source imports +were asserted beneath the new worktree. The inherited VIRTUAL_ENV +named Modden, but the explicit Tractor interpreter was used; +TRACTOR_SPAWN_METHOD and TRACTOR_LOGLEVEL were unset. + +The existing `modern_consumer_probe.py` was run through an isolated +wrapper with the new Tractor source and Piker's existing +`land_flake_update/py313` interpreter (CPython 3.13.14). Original +Piker Git-tree modules and tests were overlaid only in memory; +the `--standard-level-fix` option was absent. All 8 cases passed, +including both cache-miss and cache-hit variants from b691422b. +The installed Tractor distribution metadata still identifies the +base OID; import assertions independently verified that executable +Tractor and its logging module came from the new source worktree. + +Direct Piker imports first failed for missing native libraries +(libstdc++, then libzstd). A process-local LD_LIBRARY_PATH containing +already-present library outputs resolved from Piker's locked Nix +input fixed those imports. No shell hook, dependency installation, +environment synchronization, live broker, or actor suite was run. + +## Human edits + +The human directed the upstream Tractor fix instead of a Piker +workaround, selected the exact stack base and local discovery scope, +required compatibility and consumer verification, and reserved +commits and ref publication for review. These are human-directed +agent changes; no subsequent manual edits or acceptance are recorded. + +Subsequent local Tuicr review supplied 17 human-selected comments in +`address_logging_levels@wkt-address_logging_levels/staged/a966928`. +The reviewer directed explicit INFO(20) fixture documentation, +boolean selector meanings, the `is_info_level_enabled` callable +name, threshold comments at numeric values, and precise API and +failure descriptions instead of vague terms or Piker-specific +context. The agent applied those directions and replaced the custom +level membership/subscript pair with `CUSTOM_LEVELS.get(name)` plus +a lazy stdlib fallback on `None`, preserving zero and `KeyError`. +The registered-level regression now uses 35, between WARNING(30) +and ERROR(40), and tests it at INFO(20) then ERROR(40). + +After these review adjustments, all 70 logging tests passed with +the same source-verified Tractor CPython 3.13.11 environment. +Targeted Ruff and `git diff --check` also passed. The staged index +was preserved; review adjustments remain unstaged for human review. +The original `.raw.md` watermark and response capture are unchanged. + +A second review selected three follow-up comments about the logger +registration hook, fixture parameter meaning, and the INFO-specific +query name after changing the logger's threshold to ERROR. The +fixture now distinguishes instance-local level/disabled settings +from temporary registration and the process-global disable cutoff, +and includes a short consumer example. Each fixture case allocates +a fresh raw logger; only the query form varies between the module +function and an adapter method wrapping that logger. The test which +changes the threshold now names its query `is_level_enabled`. + +All 70 logging tests passed again with source imports verified in +this worktree under Tractor's CPython 3.13.11 interpreter. Targeted +Ruff and whitespace checks passed. These follow-up adjustments are +unstaged; the current human-staged baseline and original raw prompt +record are preserved. diff --git a/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.raw.md b/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.raw.md new file mode 100644 index 00000000..e65c4934 --- /dev/null +++ b/ai/prompt-io/20261011T053737Z_a966928d_prompt_io.raw.md @@ -0,0 +1,34 @@ +--- +created_at: 2026-10-11T05:37:37Z +generated_by: + harness: opencode + provider: openai + model: openai/gpt-6.1-sol +git_ref: wkt/address_logging_levels +diff_cmd: git diff a966928dead4cbf369ad244834ce9dbe988ac8ca wkt/address_logging_levels +--- + +> `git diff a966928dead4cbf369ad244834ce9dbe988ac8ca wkt/address_logging_levels -- tractor/log.py` + +Extend `at_least_level()` to resolve uppercase names first through +`CUSTOM_LEVELS`, then through `logging.getLevelNamesMapping()`. +Preserve integer inputs, zero-valued NOTSET, `KeyError` for unknown +names, and `Logger.isEnabledFor()` disable semantics. Update the +adapter's annotation to advertise its existing integer support. + +> `git diff a966928dead4cbf369ad244834ce9dbe988ac8ca wkt/address_logging_levels -- tests/test_log_sys.py` + +Add an isolated raw/adapted logger fixture and regressions for +standard names and aliases, lowercase names, custom CANCEL, +integer and NOTSET inputs, application-registered names, unknown +names, and logger-local/global disable controls. + +Tractor's logging suite passes: **70 tests**. Before the source fix, +the new regressions produced **30 failures**, including `INFO`, +`NOTSET`, and application-registered names. Ruff and whitespace +checks also pass. + +The original Piker consumer probe now passes **8/8**, including the +cache-hit case with `log.at_least_level('info')` retained. Import +assertions confirm it used the new Tractor worktree. The probe needed +a process-local overlay of existing Nix libraries to import Piker. diff --git a/ai/prompt-io/README.md b/ai/prompt-io/README.md new file mode 100644 index 00000000..2c2e9ef7 --- /dev/null +++ b/ai/prompt-io/README.md @@ -0,0 +1,24 @@ +# AI Prompt I/O Log + +This directory tracks prompt inputs and model outputs for +AI-assisted development across harnesses. + +## Policy + +Prompt logging follows the [NLNet generative AI policy][nlnet-ai]. +All substantive AI contributions are logged with: + +- Original harness, and provider/model when known +- Timestamps +- The prompts that produced the output +- Unedited model output (`.raw.md` files) + +[nlnet-ai]: https://nlnet.nl/foundation/policies/generativeAI/ + +## Usage + +Entries are created by the `/prompt-io` skill or automatically via +`/commit-msg` integration. + +Human contributors remain accountable for all code decisions. +AI-generated content is never presented as human-authored work. diff --git a/tests/test_log_sys.py b/tests/test_log_sys.py index f4fcee70..404a6f66 100644 --- a/tests/test_log_sys.py +++ b/tests/test_log_sys.py @@ -2,7 +2,9 @@ `tractor.log`-wrapping unit tests. ''' +from collections.abc import Callable, Iterator import importlib +from functools import partial import logging from pathlib import Path import shutil @@ -274,6 +276,204 @@ def test_add_log_level_pluggable(): delattr(log.StackLevelAdapter, name.lower()) +@pytest.fixture(params=[False, True], ids=['raw', 'adapter']) +def level_guard( + request: pytest.FixtureRequest, + monkeypatch: pytest.MonkeyPatch, +) -> Iterator[tuple[logging.Logger, Callable[[int|str], bool]]]: + ''' + Return an INFO(20) logger and a log-level enablement query. + + `is_info_level_enabled(level)` returns True when the requested + log level meets the logger's current threshold and logging is + not disabled. It queries that decision; it does not emit a msg. + The initial INFO threshold permits INFO(20), CANCEL(22) and + WARNING(30), but blocks DEBUG(10) and NOTSET(0). Tests may change + the logger's threshold or disable flag to query those settings. + + Each case allocates a fresh raw `logging.Logger` as `std_log`; + consuming tests do not supply a logger. `request.param` selects + only the returned query: + - False (`raw`): bind `tractor.log.at_least_level` to `std_log`. + - True (`adapter`): wrap that same logger in `StackLevelAdapter` + and return its `at_least_level` method. The raw logger never + supplies an `at_least_level` method. + + Register only `std_log` under its name in + `Logger.manager.loggerDict` so `Logger.setLevel()` and + `logging.disable()` can invalidate its enabled-level cache. + `std_log.setLevel(...)` and changes to `std_log.disabled` affect + that logger, not other loggers. The registration is temporary; + `logging.disable()` changes the process-global cutoff. Restore + that cutoff and the registration after each case. + + A consumer can use either query form in the same way:: + + def test_info_query(level_guard): + std_log, is_info_level_enabled = level_guard + assert std_log.level == logging.INFO + assert is_info_level_enabled('INFO') + assert not is_info_level_enabled('DEBUG') + + ''' + std_log = logging.Logger('level_guard_test', logging.INFO) + monkeypatch.setitem( + logging.Logger.manager.loggerDict, + std_log.name, + std_log, + ) + orig_disable: int = logging.root.manager.disable + # Clear inherited global suppression so INFO queries can pass. + # NOTSET(0) removes logging.disable()'s positive-level cutoff. + logging.disable(logging.NOTSET) + try: + is_info_level_enabled: Callable[[int|str], bool] + if request.param: + guarded_log = log.StackLevelAdapter(std_log, {}) + is_info_level_enabled = guarded_log.at_least_level + else: + is_info_level_enabled = partial( + log.at_least_level, std_log, + ) + + yield std_log, is_info_level_enabled + finally: + logging.disable(orig_disable) + + +@pytest.mark.parametrize( + 'level, enabled', + [ + # String log levels are compared with the INFO(20) threshold. + ('INFO', True), + ('info', True), + ('WARNING', True), + ('warning', True), + ('DEBUG', False), + ('debug', False), + ('ERROR', True), + ('CRITICAL', True), + ('WARN', True), # WARNING(30) alias, above INFO(20). + ('FATAL', True), # CRITICAL(50) alias, above INFO(20). + ('CANCEL', True), # Custom CANCEL(22), above INFO(20). + ('cancel', True), + ('TRANSPORT', False), # TRANSPORT(5), below INFO(20). + (logging.INFO, True), # 20 equals the INFO(20) threshold. + (logging.DEBUG, False), # 10 is below INFO(20). + (22, True), # CANCEL(22) is above INFO(20). + (0, False), # NOTSET(0) is below INFO(20). + ('NOTSET', False), + ('notset', False), + ], +) +def test_at_least_level_names_and_integers( + level_guard, + level: int|str, + enabled: bool, +): + ''' + String names of built-in log levels must not raise `KeyError`. + + `tractor.log.at_least_level()` indexed `CUSTOM_LEVELS` for every + string query, so built-in logging levels such as 'INFO' raised + `KeyError` before testing whether logging was enabled. Query the + documented log levels and aliases, lowercase spellings, custom + levels and integer equivalents. Each result must match its + expected INFO(20) threshold comparison without changing that + threshold; NOTSET must resolve even though its value is zero. + + See Python's `logging` docs for built-in level values: + https://docs.python.org/3/library/logging.html#logging-levels + + ''' + std_log, is_info_level_enabled = level_guard + assert is_info_level_enabled(level) is enabled + # A query must not reconfigure the INFO(20) logger. + assert std_log.level == logging.INFO + + +def test_at_least_level_registered_name( + level_guard, + monkeypatch: pytest.MonkeyPatch, +): + ''' + Query a custom log level registered with `logging.addLevelName()`. + + `tractor.log.at_least_level()` raised `KeyError` when a string + log level was absent from `CUSTOM_LEVELS`, even when registered + by `logging.addLevelName()`. Register APP_LEVEL_GUARD(35), between + WARNING(30) and ERROR(40). Its lowercase query must pass at + INFO(20), and its uppercase query must fail at ERROR(40). Restore + the logging registrations afterward so later tests do not inherit + this custom level. + + ''' + monkeypatch.setattr( + logging, '_nameToLevel', logging._nameToLevel.copy(), + ) + monkeypatch.setattr( + logging, '_levelToName', logging._levelToName.copy(), + ) + # Custom 35 is above INFO(20), but below ERROR(40). + logging.addLevelName(35, 'APP_LEVEL_GUARD') + std_log, is_level_enabled = level_guard + assert is_level_enabled('app_level_guard') is True + std_log.setLevel(logging.ERROR) + assert is_level_enabled('APP_LEVEL_GUARD') is False + + +@pytest.mark.parametrize('level', ['unknown_level_guard', '20', '']) +def test_at_least_level_unknown_name( + level_guard, + level: str, +): + ''' + Reject unknown log-level names with an explicit `KeyError`. + + The old `CUSTOM_LEVELS` lookup raised `KeyError` with the + uppercase query as its key. Log-level name lookup must not + silently enable misspelled levels or treat numeric strings as + integer inputs. Each invalid name must still raise `KeyError` + carrying its uppercase spelling, including an empty name. + + ''' + std_log, is_info_level_enabled = level_guard + with pytest.raises(KeyError) as excinfo: + is_info_level_enabled(level) + assert excinfo.value.args == (level.upper(),) + assert std_log.level == logging.INFO + + +@pytest.mark.parametrize('level', ['info', 'cancel', logging.INFO, 22]) +@pytest.mark.parametrize('suppression', ['logger', 'global']) +def test_at_least_level_disable_controls( + level_guard, + level: int|str, + suppression: str, +): + ''' + Log-level name resolution must honor logging disable controls. + + Earlier guards checked only `Logger.getEffectiveLevel()` and + rendered payloads despite disable controls. Prime a positive + enabled-level result, then disable the logger or all logging. + Built-in INFO and custom CANCEL string names, plus their integer + equivalents, must return False even though the logger's effective + INFO(20) threshold remains unchanged. Query once before disabling + to ensure a cached True result cannot bypass suppression. + + ''' + std_log, is_info_level_enabled = level_guard + assert is_info_level_enabled(level) is True + if suppression == 'logger': + std_log.disabled = True + else: + logging.disable(logging.CRITICAL) + + assert is_info_level_enabled(level) is False + assert std_log.getEffectiveLevel() == logging.INFO + + @pytest.mark.parametrize( 'suppression', [ diff --git a/tractor/log.py b/tractor/log.py index 7cab2b99..50dabaf7 100644 --- a/tractor/log.py +++ b/tractor/log.py @@ -106,11 +106,20 @@ def at_least_level( level: int|str, ) -> bool: ''' - Predicate to test if a given level is active. + Return whether `log.isEnabledFor()` permits `level`. + + Accept integer log levels or their case-insensitive string names. + `CUSTOM_LEVELS` takes precedence over names registered with + `logging.addLevelName()`, including the built-in logging levels. + Unknown names raise `KeyError` with the uppercased name. ''' if isinstance(level, str): - level: int = CUSTOM_LEVELS[level.upper()] + name: str = level.upper() + level = CUSTOM_LEVELS.get(name) + # Resolve stdlib registrations only on a CUSTOM_LEVELS miss. + if level is None: + level = logging.getLevelNamesMapping()[name] return log.isEnabledFor(level) @@ -138,7 +147,7 @@ class StackLevelAdapter(LoggerAdapter): def at_least_level( self, - level: str, + level: int|str, ) -> bool: return at_least_level( log=self,