feat: tick timing — durations, pinned scheduler semantics, health metrics#228
Merged
Conversation
…elds Measure and expose the daemon's tick cadence so the ~74 s-vs-60 s realised shortfall a health audit measured can be proven or refuted with data. - cli/main.py: a `_TickMetrics` closure counter times every `step_all` with a monotonic clock; the leaf-01 heartbeat now carries the duration (`stepped N strategy(ies) in <s.mmm>s`) and an interval overrun logs a WARN. The tick job is scheduled with explicit `coalesce=True`, `max_instances=1`, and `misfire_grace_time=<interval>` (derived, not hardcoded; 30 s for a cron trigger) — APScheduler's 1 s default grace silently skips a late tick, the presumed source of the shortfall. - supervisor.py: `step` times the unit's evaluation onto `last_step_duration_ms` (survives stop, like the cached accounting report); surfaced on StrategyStatus. - api/app.py: additive-only serialization — `/api/health` gains `last_tick_duration_ms`, `last_tick_ts`, `ticks_total`, `ticks_overrun` (null/0 with no scheduler hook); `/api/strategies` rows gain `last_step_duration_ms`. No existing field changed name, type, or semantics. Real-data scratch run (10 ticks, 60 s): tick 1 = 46.4 s (dccd load + genesis rebalance), steady-state ticks ~1.9-2.0 s, zero overruns, clean 60 s cadence — refuting the tick-exceeds-60 s hypothesis and pointing the production shortfall at misfire-grace skips, which the explicit grace now prevents.
…oved, plan archived
ArthurBernard
force-pushed
the
feat/tick-timing-metrics
branch
from
July 14, 2026 13:40
00b9fb6 to
bc1381d
Compare
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
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
daemon-loggingplan (docs: plan daemon-logging #225) — closes the epic. Every tick's duration is measured and logged on the heartbeat (in <s.mmm>s, WARN on interval overrun); per-unit step durations captured in the supervisor; the tick job's APScheduler semantics are pinned explicitly; additive timing fields on/api/healthand/api/strategies.Why
coalesce=True, max_instances=1, misfire_grace_time=interval. ADR in03-decisions.md.Changes
cli/main.py:_TickMetricsclosure state (last duration/ts, totals, overruns), timed_tick, heartbeat gains duration, overrun WARN (interval triggers), explicitadd_jobsemantics (cron grace: 30 s),_schedule_info()exposes the fields.supervisor.py: per-unitlast_step_duration_msmeasured instep'sfinally, onStrategyStatus.api/app.py: additive/api/health(last_tick_duration_ms,last_tick_ts,ticks_total,ticks_overrun) +/api/strategies(last_step_duration_ms); no existing field changed.3b.removed, plan tree archived, status Done entry.Changelog
Added under [Unreleased]: tick timing measured and pinned (closes the
daemon-loggingepic).Test plan
python -m pytest— 1507 passed, 1 skipped, cov 96.33%ruff check+ruff format --checkgreen/api/healthreportedlast_tick_duration_ms=1965, ticks_total=10, ticks_overrun=0; per-unitlast_step_duration_ms1307/657 ms; tick 1 46.4 s, ticks 2–10 at 1.93–1.97 s exactly 60 s apart; live daemon untouched