Fix catalog diagnostics losing structured data, and make the enabled signal path 2.2x cheaper - #1
Merged
Merged
Conversation
Some CatalogWarning subclasses produce a message with an already-rendered message nested inside their own template, and where a hint exists it is appended twice. Found while analysing the untruncated warning output of a full MolSysMT run: UnknownAtomNameWarning claims the atom is named "Atom name 'Ar' is not recognized; ..." rather than "Ar". Affects UnknownAtomNameWarning and GpuNotAvailableWarning in that sample; MemoryPressureWarning and SelectionWarning are clean, so it is not universal. The report carries a hypothesis rather than a diagnosis, from reading the code: CatalogWarning.__init__ and DiagnosticBundle.resolve both perform "resolve, then append the hint", so a message built by one and passed into the other would be rendered twice. The duplicated *hint* is what points there, since a template applied twice would not by itself explain it. It also names the first thing to check -- what extra["atom_name"] holds at the MolSysMT call site -- because if it already holds a sentence, the bug is upstream of SMonitor. Worth noting that pytest's own warning summary truncates, so this stayed invisible until something printed the full text. Filed from the pytest-receptor pilot; the full evidence, including all sixty warning groups, is in that repository's devguide.
`DiagnosticBundle.warn(instance)` re-emitted through the catalog with
`extra["message"]` set to `str(instance)` — text the instance had already
rendered, hint included. A template keyed on `{message}` therefore
interpolated its own output a second time and the handler appended the
hint again, producing messages roughly twice as long as intended.
The same discard also dropped the instance's structured fields, so
templates could only reference `{message}` and `report()`,
`events_by_fingerprint` and `most_noisy_resources` saw rendered prose
where they should have seen typed data.
Both were one defect:
- `CatalogWarning` and `CatalogException` now retain `code`, `extra`,
`raw_message` and `message`, so catch sites can branch on structured
state instead of parsing English.
- `warn()` merges the instance's `extra` and falls back to its *raw*
message rather than its rendered text.
Additive only: explicit `extra=` still takes precedence, and `{message}`
is unchanged for string callers.
Closes the pending bug and proposal, which are removed together.
eb95bad added both classes and described them as exported, but they were only imported — never listed in `__all__`, so `from smonitor.integrations import *` missed them and ruff flagged them as unused. `_catalog_entry` (added in 689b120) stays out of `__all__` deliberately: the leading underscore marks it as outside the public contract frozen for 1.0. It keeps a redundant alias so the re-export is explicit.
The draft was written against premises the codebase does not have. It asked to remove "magic environment autodetection" that does not exist — PROFILE resolves strictly through configure() > env > _smonitor.py — and to introduce a production/development/disabled profile triad that would collide with the five existing profiles, a breaking change during the pre-1.0 freeze. Neither was decidable as written. Its self-contained part, the disabled-signal fast path, is implemented; re-measured here at 168.7 ns wrapper overhead, matching the draft. Re-measuring shifts the target. The disabled path costs 3.1x a bare call; the *enabled* path costs 54x even when it emits nothing. Over half of that is Frame.time, a UTC timestamp formatted on every decorated call and discarded unless an event actually fires. A prototyped lazy timestamp makes Frame construction 4.5x cheaper (3188 -> 708 ns) with no change to event semantics. Rewritten around that finding, with the original ecosystem measurements preserved as provenance.
The disabled fast path was already optimized; the enabled path — where scientific users actually run — cost 53.5x a bare call while emitting nothing at all. Three changes, measured on the same host: - Frame stored its push time as a formatted ISO-8601 string, computed on every decorated call and read only when an event is emitted. On a quiet hot path it was formatted and thrown away, and it was more than half the wrapper cost. It is now an epoch float rendered by `as_dict()`. - push_frame/pop_frame copied the whole stack list on every call to keep contexts isolated, costing O(depth) twice per call. The stack is now an immutable linked list: O(1) at any depth, still safe to inherit across tasks and threads, and with an immutable ContextVar default instead of a shared mutable list. - Whether a callable can resolve its module from a bound instance is a static property of its qualname, so it is decided at decoration time and free functions skip the lookup entirely. Enabled call: 53.5x -> 24.3x a bare call. Nested, which is how sibling libraries use it (as many as 16 wrappers per operation): 4675 -> 1799 ns per wrapper, 74.9 -> 28.9 us per operation. Disabled path unchanged. Added benchmarks/signal_enabled.py to cover this path. Dropping the `frame.__dict__` aliasing also makes an emitted event a snapshot. `context.frames[*].duration_ms` used to appear in the dict returned by emit() after handlers had already received, printed and buffered that same event with None there; it is now consistently None, and durations are reported through report()["timings"] as before. tests/test_context_stack.py pins ordering, trace_depth slicing, and isolation across asyncio tasks, threads and copied contexts. conftest now clears the breadcrumb stack between tests, which it never did. Closes the rewritten overhead proposal, removed here.
|
You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Closes three of the four items in
devguide/pending_bugsanddevguide/pending_proposals. The catalog bug and the structured-extra proposalturned out to be one defect in
DiagnosticBundle.warn(), so they are fixed andremoved together. The overhead proposal was rewritten against the real code —
two of its premises did not match the codebase — and then implemented, cutting
the cost of an enabled
@signalcall by 2.2x.The remaining item,
pytest_diagnostics_bridge_and_molsyssuite_policy.md, isuntouched: by its own text it is post-1.0 and needs digestion first.
Change Type
@signalhot pathWhat changed
Catalog signals kept their structured data.
warn(instance)re-emitted withextra["message"] = str(instance)— text the instance had already rendered,hint included — so a
{message}-keyed template interpolated its own output asecond time and the handler appended the hint again:
The same discard dropped the instance's typed fields, so templates could only
reference
{message}andreport()saw prose where it should see data.CatalogWarning/CatalogExceptionnow retaincode,extra,raw_messageand
message;warn()merges the instance'sextra. Additive — explicitextra=still wins and{message}is unchanged for string callers.Enabled
@signalpath, measured on one host, bare call as the unit:Framestored its push time as a formatted ISO-8601 string, computed everycall and read only on emission. Now an epoch float, rendered by
as_dict().This was over half the wrapper cost.
instead of copying the stack twice per call. Also replaces a shared mutable
ContextVardefault.decoration time; free functions skip the lookup.
Contract Impact
code,signal, payload fields)context.frames[*].timekeeps its shape (tests/test_core.py::test_frame_time_is_iso_utc_in_emitted_context).One observable behaviour does change, and it is a fix.
get_context()returnedthe live
frame.__dict__, so an emitted event kept mutating after handlers hadrun:
duration_msappeared in the dict returned byemit()while the handlerand the buffer had already seen
Nonethere. Events are now snapshots, so thatfield is consistently
None; durations are reported viareport()["timings"]as before. A test that asserted the aliasing was rewritten to assert the
consistency instead.
FormatErrorandInconsistencyErrorare now inintegrations.__all__—eb95bad described them as exported but only imported them.
Validation Notes
Benchmarks were run before/after in the same session via
git stash, with thebare-call baseline within 6% across runs.
Also smoke-tested end to end outside pytest: breadcrumb chain, fingerprints,
report()["timings"], bundle export and CLI.Note on the diff
This branch is based on local
main, which is one commit ahead oforigin/main, so the PR also carries 293609a (the bug report). Its file isdeleted again here, so the net diff is clean.
Ready for Review