Summary
The dataflow cascade (_operation_result → cleaned → _processed_result → _summary_sd → _merged_sd → _populate_sd_cache) is the hot path for every state_change. When it's slow — and it often is on xorq, polars on large frames, and pandas with expensive autocleaning — diagnosis today means manually adding time.perf_counter() brackets around individual observers and reading them out of ad-hoc print statements.
A few ad-hoc [cache-timing] log lines have crept into dataflow.py (via the buckaroo.dataflow.cache_timing logger). They're useful but inconsistent: some observers are instrumented, some aren't; the format isn't standardised; there's no per-state-change correlation ID so concurrent state changes interleave in the logs; the channel is at INFO level so it floods normal operation.
What would help:
- A consistent observability layer over the cascade — one log line per observer per fire, with elapsed time, the trait change that triggered it, and a stable correlation key (e.g. the state_change request id or a per-cascade monotonic counter).
- Optional in-memory metric capture so a test can assert "this state_change ran
_summary_sd zero times" without parsing log strings.
- A way to enable it scoped to a specific session or off by default, on by env / flag.
Bonus: the cascade also exhibits a known double-fire pattern (_populate_sd_cache runs twice per state_change because it observes both summary_sd and operations, set in sequence by _operation_result). Without observability that's hard to even notice.
Scope
Widget AND server — the dataflow code is shared. Both contexts would benefit; server logs are easier to read out of, notebook contexts could surface via a debug panel.
Impact
Summary
The dataflow cascade (
_operation_result→cleaned→_processed_result→_summary_sd→_merged_sd→_populate_sd_cache) is the hot path for every state_change. When it's slow — and it often is on xorq, polars on large frames, and pandas with expensive autocleaning — diagnosis today means manually addingtime.perf_counter()brackets around individual observers and reading them out of ad-hoc print statements.A few ad-hoc
[cache-timing]log lines have crept intodataflow.py(via thebuckaroo.dataflow.cache_timinglogger). They're useful but inconsistent: some observers are instrumented, some aren't; the format isn't standardised; there's no per-state-change correlation ID so concurrent state changes interleave in the logs; the channel is at INFO level so it floods normal operation.What would help:
_summary_sdzero times" without parsing log strings.Bonus: the cascade also exhibits a known double-fire pattern (
_populate_sd_cacheruns twice per state_change because it observes bothsummary_sdandoperations, set in sequence by_operation_result). Without observability that's hard to even notice.Scope
Widget AND server — the dataflow code is shared. Both contexts would benefit; server logs are easier to read out of, notebook contexts could surface via a debug panel.
Impact
_summary_sdcache short-circuit) are hard to validate without ad-hoc instrumentation.