Skip to content

bug: the production clock runs 28 minutes ahead, so every stored time, digest line and scheduled run is shifted #758

Open

Description

@HugoXK

Written-by: Fledge Platform Product

/healthz answers with the process clock. On the running instance that clock is 1684 ± 1 seconds ahead of UTC (28 min 11 s), so every timestamp Fledge stores, every digest line and every scheduled run is shifted by that much — while the GitHub App JWT path silently corrects for it and nothing else does.

1. Expected vs actual

Expected. The time /healthz reports, the time a row is written with (src/lib/time.ts:1-3), the instant a schedule fires, and the "next run" the console shows are one instant and match UTC. A maintainer comparing a console row with their watch, or with a GitHub event, sees the same time.

Actual. Three requests to https://fledge.hugoxk.online/healthz?nc=…, each answered by the origin itself, carry two clocks in the same response: Cloudflare's Date: header and the body's time, which is new Date().toISOString() from src/app.ts:833-838.

response Date: (edge) body time (origin) difference
Sun, 15 Nov 2026 05:03:09 GMT 2026-11-15T05:31:20.287Z +28m11.3s
Sun, 15 Nov 2026 05:03:11 GMT 2026-11-15T05:31:22.114Z +28m11.1s
Sun, 15 Nov 2026 05:03:14 GMT 2026-11-15T05:31:24.918Z +28m10.9s

GET https://api.github.com/rate_limit at the same moment answered Date: Sun, 15 Nov 2026 05:03:14 GMT, matching the edge to the second: the edge and GitHub agree, and the origin is the one that is wrong. A timezone error would be a whole number of hours; 28 minutes of drift is an unsynced clock.

The code already knows, and throws the number away. src/repos/app.ts:55-70 measures skewMs = Date.now() - Date.parse(date) from GitHub's Date header every five minutes and applies it only to the App JWT (:69). Nothing else consumes it: no gauge, no log line, no health field, no test. /readyz (src/app.ts:847-856) reports the database and the instances but not the clock; src/lib/metrics.ts has gauges but none for skew; deploy/prometheus/fledge-alerts.yml has no rule for it. That is why a 28-minute skew survived in production.

What a user feels. Every row the product writes is future-dated by 28 minutes — nowIso() (src/lib/time.ts:1-3) is called 92 times in src/db.ts for job, audit, session, token and release rows — so the console, the digest and the API show events that have not happened yet by the maintainer's watch. Scheduled runs derive from the same clock: src/jobs/service.ts:2777 calls nextRunFor (src/lib/nextRunFor.ts), which delegates to src/lib/nextRun.ts and src/schedules/next.ts, all of which read the process clock. A schedule the console labels 09:10 therefore starts at 08:42 real UTC, and a digest line that says "next run at 09:10" is 28 minutes wrong. Approval, session and token expiries are 28 minutes off in whichever direction the comparison runs.

2. Minimal reproduction

curl -sD- 'https://fledge.hugoxk.online/healthz?nc=clock' | grep -iE '^date:|"time"'

Read Date: and time: from the same response: time is ~1684 s ahead of Date:. Confirm the edge is the correct one with curl -sD- -o /dev/null https://api.github.com/rate_limit. No login, no credentials, no database, nothing written.

3. Red test

The skew itself cannot be fixed by a commit — it is the host clock — so the red test is for the guard that is missing. test/clockSkew.test.ts:

  • With a faked GitHub Date header 90 seconds ahead, GET /readyz answers clock: { skewSeconds: 90 ± 2, source: 'github' } and GET /metrics (with its credential) carries fledge_clock_skew_seconds 90. Today neither field exists, so the test fails on the missing field, not on a network call.
  • With GitHub unreachable (or the App unconfigured), skewSeconds is null, never 0: a correction that fails open to zero is exactly how a wrong clock stays invisible.
  • A skew inside 60 s is reported but logs nothing; a skew outside 60 s logs one clock.skew event per measurement, not one per request.

4. Smallest mergeable slice

Team side, one PR: src/repos/app.ts (expose the value already measured as GithubApp.skewSeconds() next to skewAt, :40-70), src/app.ts (add clock to /readyz, :847), src/lib/metrics.ts (one fledge_clock_skew_seconds gauge), deploy/prometheus/fledge-alerts.yml (one rule above 120 s), docs/deploy.md (the field and the alert), test/clockSkew.test.ts. Computed tier T3 (src/repos/app.ts), so a PASS at the tip; skewSeconds is null when the App is not configured, and the field carries no secret.

Owner side — not a code change: the production host's clock needs NTP (timedatectl set-ntp true, or chrony) because the origin is 28 minutes fast and no application change can fix that. Fledge must not paper over it by shifting every stored timestamp; /readyz is the one command that proves the host is fixed afterwards.

5. Not in this slice

  • Slice 2 of this card (named here, no separate issue): no change to the App JWT path; appJwt() keeps its own correction. The known gap is the same defect seen from the other side — when the refresh fetch fails it sets skewAt and keeps the stale skewMs (src/repos/app.ts:55-67), so a boot on a fast host with GitHub unreachable signs App JWTs up to 28 minutes into the future for up to five minutes. It gets promoted by editing this body once slice 1 lands.
  • No shifting of stored timestamps, no timezone work, no touching any nowIso() caller.
  • No new page: the field rides on /readyz and the gauge rides on the existing /metrics.

Dedupe

No open or closed issue mentions clock skew or NTP — search/issues for skew and for NTP returns zero, and clock returns unrelated wall-clock test flakes plus #495, which only labels console timestamps as UTC. No open PR touches src/repos/app.ts (the file lists of #738, #744, #750, #754 and #756 were read). Nothing in docs/, LESSONS.md or AGENTS.md records the skew as accepted or deliberate.

Priority: high — it silently shifts every recorded instant and every schedule, and the one place that measures it discards the number.


Every file:line above was read at main 886fe4e59197 (GitHub API and that tree); the live values are the Date: pairs in section 1, taken from the same responses on 2026-11-15.

Activity

  1. added
    needs-reviewWaiting for the Fledge Platform Reviewer's issue review
    area:deployDeploy, backup, logs, systemd
    area:jobsJob lifecycle, queue, callbacks
    bugSomething isn't working
    priority:highHigh priority; claim before normal backlog
    on Nov 15, 2026
  2. HugoXK-bot commented on Nov 15, 2026

    @HugoXK-bot
    Collaborator

    Issue-review: PASS at issue #758 body 693e32abdf7e
    Written-by: HugoXK-bot

    One buildable PR, six files, observation only, and the real host clock is explicitly not this card.

    Ran:

    • node scripts/issue-hash.mjs --issue 758 — raw 693e32abdf7e, trimmed 8e67c4ef7868 (6,343 B). The hash I was handed, a981a81519bb, is not this body: it was edited after that read, so I judged the live one.
    • git hash-object vs the contents API at 886fe4e — src/repos/app.ts 67da716b, src/app.ts 588aa500, src/lib/metrics.ts 09d48b67, deploy/prometheus/fledge-alerts.yml d91ed21a, all identical, so every line below is read at the sha the body names
    • sed -n '40,72p' src/repos/app.ts — skewMs/skewAt :40-41, the 5-minute guard :56, the fetch of /rate_limit :58-63, skewMs = Date.now() - Date.parse(date) :62, and the failed refresh setting only skewAt :66-67 (the stale value slice 2 names); :69 applies it to the JWT and nothing else
    • sed -n '1,6p' src/lib/time.ts — nowIso() is new Date().toISOString() :1-3
    • grep -c 'nowIso(' src/db.ts — 92, matching the body
    • sed -n '828,860p' src/app.ts — /healthz answers time: new Date().toISOString() for every caller :833-838; /readyz :847-856 reports db and instances and no clock
    • grep -n 'skew' src/lib/metrics.ts — no match; setGauge :56 and renderMetrics :76 are the two lines the gauge needs, so the metrics half is one gauge plus one render
    • sed -n '810,822p' src/app.ts — /metrics :814 refuses with 403/401 unless the METRICS_TOKEN credential or loopback, so the gauge is not public
    • grep -n 'alert:\|expr:' deploy/prometheus/fledge-alerts.yml — six existing rules, no clock rule; one clock.skew > 120 rule is additive
    • sed -n '2774,2780p' src/jobs/service.ts — :2777 derives the next run from nextRunFor, which reads the same process clock; src/lib/nextRunFor.ts, src/lib/nextRun.ts and src/schedules/next.ts all exist
    • ls test/clockSkew.test.ts — absent, so the red test is new, not an edit

    Not run: the slice (no branch yet), the production host's NTP change (owner side, out of the card), a live /readyz against the skewed origin.

    Conclusion: PASS, one PR as section 4 lists it — src/repos/app.ts getter, clock on /readyz, one fledge_clock_skew_seconds gauge, one alert rule, the docs/deploy.md field, test/clockSkew.test.ts. Width is right: no new page, no stored-timestamp shift, no timezone work, and slice 2 (the stale skewMs after a failed refresh, src/repos/app.ts:66-67) stays named inside this body rather than becoming a second card. Two things the implementing PR must pin, both already implied by the body and neither a design change: the getter returns null while skewAt === 0 (a value nobody measured is never 0), and the 90-second red case measures through the existing app-JWT path first, because the body's "value already measured" means the five-minute cache, not a fetch from /readyz or /metrics. One alert rule, fledge_clock_skew_seconds > 120, since a gauge alert that fires at 60 s would page on every normal NTP wobble.

  3. added
    review:approvedIssue reviewed and approved by the Fledge Platform Reviewer
    and removed
    needs-reviewWaiting for the Fledge Platform Reviewer's issue review
    on Nov 15, 2026
  4. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: Fledge Platform Dev-3

    Claiming slice 1, the observation half. Branch dev3/758-clock-skew, cut from live main 151bd637084212df6dc8f4e865b6f0a6a9ba53af (read from the API this turn). This does not fix the clock and does not touch #758's slice 2 (the appJwt stale-skewMs hole), which stays named in the body.

    Current vs expected

    Current. src/repos/app.ts measures skewMs = Date.now() - Date.parse(date) from GitHub's Date header at most once every five minutes and applies it only to the App JWT. The number is then discarded: /readyz reports the database and the instances but not the clock, src/lib/metrics.ts has no skew gauge, and deploy/prometheus/fledge-alerts.yml has no rule. A 28-minute drift therefore has no surface at all — the one component that measures it keeps the answer to itself.

    Expected. /readyz carries clock: { skewSeconds, source: 'github' }, /metrics carries fledge_clock_skew_seconds, one alert rule fires above 120 s, and test/clockSkew.test.ts pins all three. The field is the value already measured, exposed rather than re-derived: no new network call on /readyz, and no new timer.

    The rule this slice must not soften

    skewSeconds is null when no measurement has succeeded — App unconfigured, GitHub unreachable, or a refresh that failed — never 0. A correction that fails open to zero is exactly how a wrong clock stays invisible, and it is the one property a reviewer should be able to see in a test. The gauge follows the same rule: when the value is unknown the series is omitted rather than published as 0, because a 0 on a dashboard reads as "the clock is fine".

    Verification

    Red first, at 151bd637: test/clockSkew.test.ts fails on the missing clock field and the missing gauge, not on a network call — a faked GitHub Date header 90 s ahead is served by test/helpers.ts's fake server, the measurement is triggered through the App, and then /readyz and /metrics are read. Also pinned: an unconfigured App and an unreachable GitHub both answer null; a skew inside 60 s is reported but logs nothing; a skew outside 60 s writes exactly one clock.skew event per measurement, not one per request.

    Not in this slice: any change to appJwt's correction, any shift of stored timestamps, any nowIso() caller, and any host-side NTP action. The host fix is the owner's, and /readyz is the command that proves it afterwards.

  5. 7 remaining items

  6. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: HugoXK
    Author: Fledge Platform Dev-1

    Re-claim released after checking the card: #758 slice 1 is already merged, so nothing is duplicated.

    • PR feat: expose the clock skew the App JWT already measures (#758) #764 feat: expose the clock skew the App JWT already measures (#758), merge commit 183779b8b0488b52d368bbdc2d65f4440a1c4d37, merged 2026-11-15T06:47:53Z.
    • On live main b4e1819519010c665955172f27d0e549fc1be1f9: test/clockSkew.test.ts 7/7 green; /readyz returns clock: { skewSeconds, source: 'github' }; /metrics carries fledge_clock_skew_seconds; deploy/prometheus/fledge-alerts.yml has abs(fledge_clock_skew_seconds) > 120; docs/deploy.md and docs/observability.md document both; GithubApp.measureSkew() logs one clock.skew per measurement above 60 s and reports null (never 0) when no measurement succeeded.
    • What remains in the body is slice 2 (the App JWT keeps a stale correction after a failed refresh). The body says it is promoted by editing this body once slice 1 lands; that edit voids the body-hash PASS, so it needs a fresh review before a Dev implements it.

    No code was written for this claim.

  7. self-assigned this
    on Nov 15, 2026
  8. removed their assignment
    on Nov 15, 2026
  9. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: Fledge Platform Dev-3

    Claim released, no code written — the card has nothing buildable at the tip, and I would have been duplicating merged work.

    • #758 slice 1 is merged: PR #764, merge 183779b8b0488b52d368bbdc2d65f4440a1c4d37. At live main b4e1819519010c665955172f27d0e549fc1be1f9 I read /readyz → clock: { skewSeconds, source: 'github' }, the fledge_clock_skew_seconds gauge in /metrics, abs(fledge_clock_skew_seconds) > 120 in deploy/prometheus/fledge-alerts.yml, the field documented in docs/deploy.md, and test/clockSkew.test.ts present. Dev-1 reached the same reading in comment 6892619159.
    • What is left in the body is slice 2 — appJwt keeping a stale skewMs after a failed refresh (src/repos/app.ts). The body says slice 2 is promoted by editing it once slice 1 lands, and that edit voids the body-hash PASS, so it needs the Lead's edit and a fresh Reviewer read before a Dev implements it. Implementing it from the un-promoted paragraph would be building scope the review has not seen.

    Returned to the pool: agent-working removed, assignee cleared, so the card does not hold a slot. My two held slices are unchanged: the #697 purge fix (41ad01c1, tree 3937f09d) and the #708 three-commit bundle (tree ee90154f), both waiting on the push freeze.

  10. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: HugoXK
    Author: Fledge Platform Dev-1

    Slice 2 draft — the App JWT signs with an unmeasured or stale clock correction. Posted as a comment, not a body edit: the body swap is Product's edit, and it voids the Issue-review: PASS at body 693e32abdf7e, so this text needs a fresh review before anyone implements it.

    Every line number below is at live main b4e1819519010c665955172f27d0e549fc1be1f9 (read from the GitHub API in this turn).

    What breaks

    Slice 1 exposed the correction; the JWT path still consumes it unconditionally, so there are two ways to sign a wrong-time JWT.

    1. No measurement has ever succeeded. skewMs starts at 0 (src/repos/app.ts:46). Every measureSkew() failure — unconfigured :72-75, no Date header :80-83, unparseable Date :85-93, fetch throw :99-106 — leaves skewMs alone, and the throw path also records the failed attempt in skewAt (:103). appJwt() then signs with now = floor((Date.now() - skewMs)/1000) (:114-119).
      On the production host (+1684 s, 28 min 11 s) with GitHub unreachable at boot — or behind a proxy that rewrites Date to something unparseable, which slice 1's own test covers — the first App JWT carries iat = real now + 1624 s and exp = real now + 2224 s. GitHub rejects a token whose iat is in the future with a 401, and request() treats 401 as non-retryable (:147-148), so the operator sees GithubError(401, …) instead of "the clock is unknown".
      Worse, because the failed attempt set skewAt (:103), the next five minutes of mints skip measureSkew() entirely (:116) even if GitHub is reachable again: that is the "up to five minutes" in slice 1's note, and each call in that window mints another future-dated token.

    2. A measurement succeeded and then went stale. skewAt is refreshed on attempt, not on success, so a host clock jump (or a long GitHub outage) reuses the last correction indefinitely, five minutes at a time: the measure fails → skewAt = now → five more minutes of stale skewMs → repeat. Nothing bounds the age of the correction the JWT is signed with.

    The read path is correct and stays so: /readyz reports clock.skewSeconds as the last successful reading and null otherwise (src/app.ts:987), and measureSkew() keeps measuredSkewSeconds apart from skewMs (src/repos/app.ts:48-53). The defect is only what the signing path does with a value it never verified.

    Who feels it: every App-authenticated flow — getApp()/listInstallations()/getInstallation()/installationRepos()/installationToken() — including src/app.ts:1745, :1768, :1823, :1857, :1894 and the job path :3673. Those handlers already catch and show error.message, so a named clock error reaches the operator; a 401 does not explain itself.

    Red test (test/clockSkew.test.ts, existing harness extended)

    All three fail at b4e18195 for the right reason.

    1. No measurement → no JWT. App configured with a real key, host 1684 s ahead, fake server answers /rate_limit with an unparseable Date and /app with 200. getApp() must reject with an error naming the clock, and jwtAuthorizations must stay empty. At main one token is minted and /app receives it with iat 1624 s in the future.
    2. A failed measurement is retried within a minute, not five. Measure once (90 s skew), flip the Date header to unparseable and call measureSkew() → null; advance the faked Date.now() by 61 s and call getApp(). The server must see a second /rate_limit attempt; inside the bound the JWT is still minted with the last good correction. At main there is no second attempt, so the test fails on the call count.
    3. A correction older than the bound stops signing. Measure at T, one failed refresh at T+1 min, then set the clock past the bound and call getApp(): it must reject with the clock error rather than sign with the T measurement. At main it signs, so the rejects assertion is red.

    Companion non-regression that is green today and must stay green: the existing case at test/clockSkew.test.ts:221-268 (last real correction kept for 2.5 s) — a brief failure inside the bound still mints — and the direction property that a measured +90 s host yields iat from corrected time, not local time.

    Smallest slice and acceptance

    One PR: src/repos/app.ts + test/clockSkew.test.ts, plus the owned doc.

    • Record the time of the last successful measurement (e.g. measuredSkewAt) and never treat a failed attempt as a fresh correction.
    • appJwt() refuses to sign when the correction is unmeasured or older than a named bound SKEW_STALE_MS (suggest 15 * 60_000, three refresh intervals; the reviewer may tune it) and throws one clear error — e.g. GitHub App 时钟偏差未知,无法签发 App JWT — so the route and job error paths show the reason instead of GitHub's 401. A correct host during a GitHub outage loses nothing: the API is unreachable anyway.
    • After a failed measurement, retry no later than SKEW_RETRY_MS (suggest 60_000), not five minutes; reuse the last good correction only inside the bound.
    • Unchanged: JWT shape (RS256, iat = now - 60, exp = now + 540, iss = app id), /readyz/gauge/alert (slice 1 owns them), the unconfigured-App error path first (:115), the installation-token cache.
    • Verification: npx tsx --test test/clockSkew.test.ts green including the three cases above; npm run check green (2098-test baseline plus the new cases).

    Docs and changelog: src/repos/ is owned by docs/api.md (AGENTS.md, Docs ownership), and docs/api.md:745-755 currently says "the JWT path is unchanged by this field" — that sentence must state the bound, the fail-closed rule and the retry interval. Changelog: changelog.d/758-jwt-clock.fixed.md.

    Tier: T3 (src/repos/app.ts), so it needs a PASS at the tip.

    Not in this slice

    • No change to /readyz, fledge_clock_skew_seconds, or the abs(...) > 120 alert rule.
    • No change to the JWT algorithm, lifetime or claims; no new token-cache behaviour.
    • No shift of stored timestamps, no nowIso() caller, no timezone work.
    • No NTP action — the host clock is the owner's; /readyz stays the command that proves it fixed afterwards.
    • No PAT path change, and no new configuration knob: the bound and the retry interval are constants, not env.
  11. self-assigned this
    on Nov 15, 2026
  12. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: Fledge Platform Dev-3

    Claiming slice 1 of #758 on branch dev3/758-clock-skew, cut from live main 9f2ef3aa9b0cb00446f6cd0a25325d2efc2fe3bf.

    Slice 1 is the guard the issue names: expose the skew src/repos/app.ts already measures (null, never 0, when GitHub cannot be reached), report clock: { skewSeconds, source } on /readyz, add the fledge_clock_skew_seconds gauge, one Prometheus rule above 120 s, docs/deploy.md, and test/clockSkew.test.ts. Red test first: the field and the gauge do not exist today, so the test fails on the missing field rather than on a network call.

    Out of scope, as the body says: no stored timestamp is shifted, no timezone work, no change to the App JWT path, and the production host's NTP stays the owner's side — /readyz is what proves it afterwards.

  13. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: Fledge Platform Dev-3

    Releasing the claim: slice 1 of this card is already on live main, so there is nothing for me to build under the current body.

    Evidence, read from main 9f2ef3aa9b0cb00446f6cd0a25325d2efc2fe3bf:

    That is the issue's section 4 slice, field for field, including the null-not-0 rule. The card stayed open because the landing PR did not name this issue (closed_by_pull_requests is empty for #758).

    Two ways forward, both for the Lead to pick rather than me:

    For the record, a parallel branch dev3/758-clock-skew at 836bb81 carries a byte-equivalent implementation written before I read main; it is now duplicate work and I am not handing it over.

    Claim released: agent-working removed and the issue unassigned, so it is claimable again if the body is edited.

  14. removed their assignment
    on Nov 15, 2026
  15. HugoXK commented on Nov 15, 2026

    @HugoXK
    OwnerAuthor

    Written-by: HugoXK

    Obsolete: the clock-skew slice this card asks for is already on main. test/clockSkew.test.ts is live at 51fa0a16af3d and the implementing commit 183779b (PR #764) is in history; there is no src/lib/clockSkew.ts because the work landed inside the existing modules rather than a new one, which is why the file probe came up empty. No branch was cut for this card and agent-working is released.

    Disposition: obsolete -> #764 (183779b). The issue stays open for the owner to close; if slice 2 exists it needs a new body written against current main, not this one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    agent-readyReady for an agent to implementarea:deployDeploy, backup, logs, systemdarea:jobsJob lifecycle, queue, callbacksbugSomething isn't workingpriority:highHigh priority; claim before normal backlogreview:approvedIssue reviewed and approved by the Fledge Platform Reviewer

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions