Skip to content

fix(lib): anchor Slurm grace period to job start, not submission - #503

Merged
cswaney merged 2 commits into
mainfrom
472-grace-period-clock
Aug 26, 2026
Merged

fix(lib): anchor Slurm grace period to job start, not submission#503
cswaney merged 2 commits into
mainfrom
472-grace-period-clock

Conversation

@cswaney

@cswaney cswaney commented Aug 25, 2026

Copy link
Copy Markdown
Member

Summary

  • Service.refresh measured the Slurm grace period from self.created_at (service submission), so queue time counted against startup. A busy cluster could mark a service UNHEALTHY before the container had begun loading.
  • SlurmJob.update now requests -o State,Start (prefixed with TZ=UTC) and stores the parsed timestamp on SlurmJob.started_at. Service.refresh measures the grace period from job.started_at when available, falling back to created_at on Unknown/parse failure. The PENDING branch already skipped the grace period, so the change is confined to the RUNNING/no-ping path.
  • Local (Docker/Apptainer) path unchanged; there is no queue locally and the bug is far less acute. docker inspect .State.StartedAt is a natural follow-up.

Test plan

  • uv run just lint
  • uv run just test (971 pass, 7 skipped — +9 new)
  • Verify on a real cluster: submit a large model on a queue, confirm status stays PENDING/STARTING for the full model-load window rather than flipping to UNHEALTHY after queue+grace.

Follow-ups

Closes #472

`Service.refresh` measured the grace period from `self.created_at`, i.e.
service submission time. On a busy cluster a job can sit `PENDING` well
past the grace period and be marked `UNHEALTHY` before the container has
begun loading. Queue time is unbounded, so no default is generous enough.

Fetch the job's actual start time from Slurm accounting: `sacct` is
already invoked on every refresh, so requesting `-o State,Start` instead
of `-o State` adds no round-trips. Prefix with `TZ=UTC` so Slurm emits
`Start` in UTC and we don't have to detect the cluster timezone. Store
the parsed timestamp on the transient `SlurmJob.started_at`; fall back
to `created_at` when `sacct` reports `Unknown` or fails to parse (this
preserves prior behavior on the fallback path).

The `PENDING` branch already avoids the grace period entirely, so this
change is confined to the `RUNNING`/no-ping path.

Local (Docker/Apptainer) path unchanged. Docker exposes an equivalent
`State.StartedAt` via `docker inspect`; leaving that as a follow-up
since there is no queue locally and the bug is far less acute.

Closes #472
@claude

claude Bot commented Aug 25, 2026

Copy link
Copy Markdown

Review: fix(lib): anchor Slurm grace period to job start, not submission

Nice fix for the underlying problem -- measuring the grace period from queue-submission time really was going to bite on any busy cluster, and anchoring to sacct's Start field (with TZ=UTC to sidestep timezone detection) is a clean way to get it without extra round-trips. The _split_state_start / parse_sacct_start split into small, pure, well-tested helpers is a good pattern, and the fallback to created_at when Start is Unknown/unparseable is sensible.

One correctness concern and a coverage gap worth addressing before merge:

1. Clock skew between the Slurm host and the Blackfish server can now trigger a false-immediate UNHEALTHY (lib/src/blackfish/server/services/base.py:456-462)

anchor is now a timestamp sourced from the remote cluster's clock (via sacct), whereas before it was always self.created_at, generated on the Blackfish server itself. If the two clocks are not perfectly synced -- even by a couple of seconds, which is common without tight NTP -- job.started_at can be slightly ahead of the Blackfish server's datetime.now(timezone.utc), making dt = datetime.now(timezone.utc) - anchor negative.

The comparison still uses dt.seconds (not dt.total_seconds()):

dt = datetime.now(timezone.utc) - anchor
...
if dt.seconds > self.grace_period:

timedelta.seconds is only the non-negative remainder component -- for a negative timedelta it normalizes to something like days=-1, seconds=86398. So a few seconds of clock skew in the "wrong" direction would make dt.seconds roughly 86398, which blows past any sane grace_period (180-600s) and immediately flips the service to UNHEALTHY right as it starts running -- the opposite of what this PR is trying to fix.

This .seconds vs .total_seconds() gap is called out in the PR description as pairing with #473, and it is pre-existing in the created_at-anchored path too, but it was much lower-risk there since both operands came from the same local clock (a negative dt was essentially impossible outside of the server's own clock jumping backward). Switching the anchor to a remote-clock value meaningfully raises the odds of hitting it. Given how small the fix is (dt.total_seconds() instead of dt.seconds, applied at both lib/src/blackfish/server/services/base.py:462 and :529), it may be worth folding into this PR rather than deferring -- total_seconds() also has the nice property that a negative dt just fails the > comparison (stays STARTING) instead of wrapping into a false positive.

2. No test exercises the actual behavior change in Service.refresh (lib/tests/unit/test_job.py)

All the new tests target SlurmJob.update/_split_state_start/parse_sacct_start in job.py, which is good coverage for the plumbing, but the actual bug fix -- Service.refresh preferring job.started_at over self.created_at when computing the grace period -- has no direct test. lib/tests/unit/test_services.py doesn't currently exercise refresh()/grace-period transitions at all. A test that mocks get_job() to return a SlurmJob with state=RUNNING and a started_at set well within the grace window (so it would not be if measured from an old created_at), asserting the status comes back STARTING rather than UNHEALTHY, would directly pin the fix and guard the regression this PR exists to prevent.

Minor / nit

  • sacct_cmd now starts with ["env", "TZ=UTC", "sacct", ...]. Since RemoteCommandError/RemoteTimeout build their message from cmd[0], a failing or timed-out sacct call will now log as 'env' exited/timed out rather than 'sacct', which is a small step down in log clarity when diagnosing sacct failures. Not a big deal given stderr is still included, just flagging.

Overall this is a solid, well-scoped fix with good rationale in the commit message/comments -- just want the clock-skew edge case addressed (or explicitly accepted with a comment) before it ships, since it can reintroduce the same false-UNHEALTHY symptom this PR is fixing, under a different trigger.

…h tests

- Compare grace period against `dt.total_seconds()` at both refresh sites
  so a service that has been running >24h isn't silently reset by
  `timedelta.seconds` wrapping (folds in the fix from #473).
- `RemoteCommandError` strips the `env TZ=UTC` prefix when reporting the
  program name, so sacct failures surface as `'sacct' exited N` instead
  of `'env' exited N`.
- New unit tests for `Service.refresh` covering STARTING->STARTING under
  grace and STARTING->UNHEALTHY over grace, using `job.started_at`.
@cswaney
cswaney merged commit 833b1e5 into main Aug 26, 2026
8 of 12 checks passed
@cswaney
cswaney deleted the 472-grace-period-clock branch August 26, 2026 00:28
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.

Grace period clock starts at job submission, so queue time counts as startup time

1 participant