Skip to content

feat: tick timing — durations, pinned scheduler semantics, health metrics#228

Merged
ArthurBernard merged 2 commits into
developfrom
feat/tick-timing-metrics
Jul 14, 2026
Merged

feat: tick timing — durations, pinned scheduler semantics, health metrics#228
ArthurBernard merged 2 commits into
developfrom
feat/tick-timing-metrics

Conversation

@ArthurBernard

Copy link
Copy Markdown
Owner

Summary

  • Leaf 03/3 of the daemon-logging plan (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/health and /api/strategies.

Why

  • The 2026-07-14 audit measured a realised ~74 s cadence vs the 60 s nominal with one misfire line ever logged. Root cause found and fixed: APScheduler's 1 s default misfire grace silently skips late ticks — real-data timing shows steady-state ticks at ~2 s (first tick ~46 s data load), so skips, not overruns, explain the shortfall. The job now runs coalesce=True, max_instances=1, misfire_grace_time=interval. ADR in 03-decisions.md.

Changes

  • cli/main.py: _TickMetrics closure state (last duration/ts, totals, overruns), timed _tick, heartbeat gains duration, overrun WARN (interval triggers), explicit add_job semantics (cron grace: 30 s), _schedule_info() exposes the fields.
  • supervisor.py: per-unit last_step_duration_ms measured in step's finally, on StrategyStatus.
  • 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.
  • Epic closeout: roadmap line 3b. removed, plan tree archived, status Done entry.

Changelog

Added under [Unreleased]: tick timing measured and pinned (closes the daemon-logging epic).

Test plan

  • python -m pytest — 1507 passed, 1 skipped, cov 96.33%
  • ruff check + ruff format --check green
  • Real-data verification: scratch daemon (port 8099), 10 ticks — /api/health reported last_tick_duration_ms=1965, ticks_total=10, ticks_overrun=0; per-unit last_step_duration_ms 1307/657 ms; tick 1 46.4 s, ticks 2–10 at 1.93–1.97 s exactly 60 s apart; live daemon untouched
  • CI green

…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.
@ArthurBernard
ArthurBernard force-pushed the feat/tick-timing-metrics branch from 00b9fb6 to bc1381d Compare July 14, 2026 13:40
@ArthurBernard
ArthurBernard merged commit 6e6c329 into develop Jul 14, 2026
3 checks passed
@ArthurBernard
ArthurBernard deleted the feat/tick-timing-metrics branch July 14, 2026 13:42
This was referenced Jul 14, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant