Diagnostic GitHub API
clock drift puts the JWT iat claim in GitHub's future
The same code, the same key, the same App. On a laptop it works every time. In the container it returns 401 {"message": "'Issued at' claim ('iat') must be an Integer representing the time that the assertion was issued"}, and on the third host it works again until Tuesday. Nothing about the JWT changed between those runs. What changed is which machine did the signing.
iat is a moment your host writes down and GitHub reads back against its clock. If your host is ahead, the moment you claim to have signed at has not happened yet as far as GitHub is concerned, and the JWT is refused before its signature matters. Containers with no time sync, suspended virtual machines and runners that boot with a cold clock all produce it, and they produce it intermittently, which is why it survives so many rounds of debugging.
You can measure the offset without any credential. Every GitHub response carries a Date header, so time the request from both ends and the skew falls out with an error bar attached: local midpoint - server time, plus or minus half the round trip. Then set iat to sixty seconds in the past, which is GitHub's own documented advice rather than a workaround, and fix the host's time sync so the number stays small.
The problem in plain words
It fails on the wrong axis. Everything a person reaches for during a 401 is a property of the credential, and every one of those properties is identical across the machine where it works and the machine where it does not. The key is the same file. The App is the same App. The library is pinned. So the search goes around the credential twice before anybody thinks to look at the clock, because the clock is not part of the request as far as the code is concerned.
Then the message misdirects. Must be an Integer representing the time that the assertion was issued reads like a type error, and the first reaction is to check whether milliseconds went in where seconds were expected, or whether a date string slipped through. Those are real defects and they are not this one: the value is an integer, it is in seconds, and it is simply too large by the amount your host is ahead.
Worst of all it is intermittent by construction. A clock a second or two fast fails only when the network is quick enough for the request to arrive before GitHub's own second ticks over, so the same deployment returns 401 for one call in five. That looks like an upstream flap, gets a retry loop wrapped around it, and the retry loop makes it invisible for another six months.
Why it happens
The claim is evaluated against a clock you do not own. iat means issued at, and a token issued in the future is a contradiction, so GitHub rejects it rather than waiting. The comparison is made on GitHub's clock, which is disciplined; yours may not be. Nothing in the JWT records which machine signed it, so the error can only describe the symptom.
The reference clock is free and unauthenticated. Every HTTP response carries a Date header in the format RFC 9110 fixes, and GET /rate_limit answers without a credential and without consuming quota. That makes the measurement cheap enough to run on a schedule on every host that signs, rather than during an incident on the one host somebody suspects.
A single reading is not a measurement. The Date value is truncated to the second and the response spent an unknown share of the round trip in each direction, so a naive comparison can be a second or two wrong in either direction. Recording the local time on both sides of the request and comparing the midpoint gives an offset with an uncertainty attached, and taking the exchange with the shortest round trip out of several is the same trick a time daemon uses: the fastest exchange had the least room to be asymmetric.
Offset and drift are different diseases. A host that is forty seconds ahead and staying there was set wrong once, probably at boot. A host whose offset grows while you watch has no discipline at all and will be wrong again next week whatever you set it to today. Telling those apart needs two readings a decent interval apart, and the script refuses to guess a rate from samples taken seconds apart rather than report a number it cannot support.
Whole hours are not drift. An offset that lands within a minute or two of a whole number of hours, or of a half hour, is a timezone conversion rather than a clock fault: something built iat from a naive local datetime and treated it as UTC. Backdating will not save that, and the script says so instead of recommending sixty seconds against a five-hour error.
This note does not open the JWT. The lifetime arithmetic on iat and exp belongs to the note on a JWT that expires in an hour, which decodes the payload locally and never needs a network. Here the payload is irrelevant: a perfectly legal ten-minute JWT is refused just the same if the host that signed it is ahead.
The fix, as a flow
The measurement needs no credential, which is what makes it worth running before anything is wrong. GitHub states its own clock on every response, so the samples are unauthenticated, cost no quota and can run as a startup probe on each host that signs. The confirming request is optional and it only ever agrees or disagrees: the number that matters was known before it was sent.
How to fix it
Measure on the host that signs, not on your laptop
The number is a property of one machine. Run the check inside the container, on the runner, in the pod that mints the JWT, and run it there even when the same code works elsewhere, because the whole finding is the difference between those two places. A measurement taken on a developer machine with working time sync proves nothing about a production host that has none.
Take several samples and keep the fastest
One request gives an offset contaminated by half an unknown round trip. Three or five, spread a couple of seconds apart, let you keep the exchange with the shortest round trip and report the rest as uncertainty. If the uncertainty is larger than the offset, the honest answer is that the path is too slow to resolve a skew this small, and the script says that rather than inventing precision.
Read the direction before the magnitude
Ahead of GitHub is the dangerous direction: it is the one that puts iat in the future and produces the 401. Behind GitHub is a different and quieter problem, because the JWT arrives having already spent part of its life, so a ten-minute token signed on a host five minutes slow is half gone when it lands.
Check the offset against the backdate you already apply
If your signing code sets iat to now - 60, an offset of ten seconds is absorbed and there is nothing to fix here. If it sets iat to now, any positive offset at all is a live failure waiting for a fast network. Pass the backdate you actually use and the report becomes a margin rather than a number.
Backdate by sixty seconds, then fix the host clock anyway
Backdating is GitHub's documented recommendation and it costs nothing, so do it first. It is still not a repair: a host whose clock is wrong enough to break a JWT is producing misordered logs, wrong certificate validity windows and confusing metrics on the same afternoon. Install time sync, or run the container on a host that has it.
How to check it worked
Re-run on the same host after the clock is disciplined. The state moves from iat-lands-in-the-future to clock-in-sync, and the confirming request, if you give it a JWT, stops naming iat.
python3 github_clock_skew.py --samples 5 --backdate 60
# best of 5 samples: skew=+2.4s uncertainty=1.2s round_trip=0.31s
# clock-in-sync: this host and GitHub agree to within the measurement error.
# drift over 128s: offset-is-static at 3.1 ppm
# GET /app returned 200
# accepted: GitHub did not complain about iat.The full code
The measurement is the whole script and it needs no credential: GET /rate_limit answers unauthenticated, does not consume quota, and carries the Date header that is the only thing being read. Everything that turns samples into a verdict is pure — parsing the header, computing an offset with its uncertainty, picking the fastest exchange, classifying direction against the backdate you already apply, and refusing to state a drift rate from samples too close together. The optional confirming GET /app sends a JWT you already hold; it is never decoded, stored or printed, and the report contains nothing but seconds.
"""Measure the clock on the machine that signs GitHub App JWTs.
Read only, and the part that matters needs no credential at all. Every GitHub
response carries a Date header, so the reference clock is free: send a request,
note the local time on both sides of it, and the offset between this host and
GitHub falls out with an error bar attached.
GET /rate_limit is used for the samples because it answers unauthenticated and
does not consume quota. Nothing here is written, minted or changed.
This script does not open your JWT. The arithmetic on iat and exp belongs to a
different note; the question here is whether the machine writing iat agrees
with the machine reading it. A host running fast puts iat in GitHub's future
and the JWT is refused however carefully the claim was computed.
Sign convention throughout: skew is local minus server, so a positive number
means this host is ahead of GitHub, which is the direction that breaks a JWT.
"""
import argparse
import json
import logging
import math
import os
import sys
import time
from datetime import timezone
from email.utils import parsedate_to_datetime
import requests
logging.basicConfig(level=logging.INFO, format="%(asctime)s %(levelname)s %(message)s")
log = logging.getLogger("github_clock_skew")
API = "https://api.github.com"
UA = "github-clock-skew/1.0"
# The Date header is truncated to the second, so the true server time is
# somewhere inside a one second window. That floor is added to every
# uncertainty rather than pretended away.
DATE_RESOLUTION = 1.0
# Below this the two clocks are close enough that nothing is actionable.
GRACE = 5
# GitHub's own documented advice for the signing code.
RECOMMENDED_BACKDATE = 60
# A drift rate computed over a shorter span than this is noise, given that
# every sample is quantised to a whole second.
MIN_DRIFT_SPAN = 60
# Roughly the discipline a working time daemon holds. Above it the clock is
# free running and will be wrong again whatever you set it to today.
FREE_RUNNING_PPM = 100
def parse_http_date(value):
"""Parse an RFC 9110 Date header into epoch seconds. Pure.
Returns None rather than raising: a response without a usable Date is a
sample to discard, not an exception to propagate out of a measurement.
"""
if not value:
return None
try:
moment = parsedate_to_datetime(str(value))
except (TypeError, ValueError):
return None
if moment is None:
return None
if moment.tzinfo is None:
moment = moment.replace(tzinfo=timezone.utc)
return moment.timestamp()
def sample_skew(server_epoch, sent, received):
"""One exchange reduced to an offset with an error bar. Pure.
The request left at `sent` and the response landed at `received`, so the
server read its clock somewhere in between. Comparing the midpoint of that
window against the server time gives the offset; half the round trip, plus
the one second the Date header is quantised to, bounds how wrong it can be.
"""
if server_epoch is None:
return None
round_trip = max(float(received) - float(sent), 0.0)
midpoint = (float(sent) + float(received)) / 2.0
return {"skew": round(midpoint - float(server_epoch), 3),
"uncertainty": round(round_trip / 2.0 + DATE_RESOLUTION, 3),
"round_trip": round(round_trip, 3),
"at": round(float(received), 3)}
def best_sample(samples):
"""The exchange with the shortest round trip. Pure.
Not the mean and not the median. The fastest exchange is the one with the
least room to be asymmetric between the two directions, which is the same
reason a time daemon prefers it.
"""
usable = [s for s in samples if s]
if not usable:
return None
return min(usable, key=lambda s: s["round_trip"])
def timezone_suspect(skew):
"""Hours of offset when the skew looks like a timezone rather than drift. Pure.
An offset within a minute and a half of a whole or half hour is almost
never a clock: it is a naive local datetime that was treated as UTC. Saying
so matters, because backdating sixty seconds does nothing about five hours.
"""
if skew is None:
return None
magnitude = abs(float(skew))
if magnitude < 1500:
return None
slots = round(magnitude / 1800.0)
if slots == 0:
return None
if abs(magnitude - slots * 1800) <= 90:
hours = slots / 2.0
return hours if skew > 0 else -hours
return None
def backdate_needed(skew, uncertainty):
"""How far to backdate iat so this offset cannot reach GitHub's future. Pure."""
need = float(skew) + float(uncertainty) + GRACE
if need <= RECOMMENDED_BACKDATE:
return RECOMMENDED_BACKDATE
return int(math.ceil(need / 30.0)) * 30
def classify(skew, uncertainty, backdate):
"""Turn one measured offset into a finding. Pure.
Direction first, because it decides which failure you have. A host ahead of
GitHub breaks iat; a host behind it burns the JWT lifetime early, which is
a quieter problem with a different repair.
"""
if skew is None:
return ("unmeasurable",
"no response carried a usable Date header, so there is no "
"reference clock to compare against. Check that something is "
"not stripping response headers in front of this host.")
hours = timezone_suspect(skew)
if hours is not None:
return ("timezone-not-drift",
"the offset is %+.1f hours, which is a timezone conversion "
"rather than a clock fault. Something built the timestamp from "
"a naive local datetime and treated it as UTC. Backdating will "
"not help; the conversion has to be fixed." % hours)
if skew > 0:
margin = float(backdate) - (float(skew) + float(uncertainty))
if margin < 0:
return ("iat-lands-in-the-future",
"this host is %.1fs ahead of GitHub and iat is backdated "
"by %ds, so the claim lands %.1fs into GitHub's future and "
"the JWT is refused. Backdate by %ds and fix the host clock."
% (skew, backdate, -margin, backdate_needed(skew, uncertainty)))
if margin < GRACE:
return ("backdate-has-no-headroom",
"this host is %.1fs ahead of GitHub and the %ds backdate "
"absorbs it with only %.1fs to spare, which is close enough "
"to fail on a fast network. Backdate by %ds."
% (skew, backdate, margin, backdate_needed(skew, uncertainty)))
if abs(skew) <= max(uncertainty, GRACE):
return ("clock-in-sync",
"this host and GitHub agree to within the measurement "
"error of %.1fs." % uncertainty)
return ("drift-absorbed-by-backdate",
"this host is %.1fs ahead of GitHub, and the %ds backdate "
"covers it with %.1fs to spare. The JWT is safe; the clock is "
"still wrong and worth fixing." % (skew, backdate, margin))
if abs(skew) <= max(uncertainty, GRACE):
return ("clock-in-sync",
"this host and GitHub agree to within the measurement error "
"of %.1fs." % uncertainty)
return ("clock-behind-github",
"this host is %.1fs behind GitHub. iat is safe, but every JWT "
"arrives having already spent %.1fs of its life, so a short "
"lifetime can expire on the way." % (-skew, -skew))
def drift_rate(readings, min_span=MIN_DRIFT_SPAN):
"""Parts per million of drift between the first and last reading. Pure.
readings: [(local_time, skew), ...]. Returns None when the samples are too
close together to support a rate, which they usually are: every sample is
quantised to a whole second, so a few seconds of span can only produce a
number that looks authoritative and is not.
"""
usable = [r for r in readings if r and r[1] is not None]
if len(usable) < 2:
return None
span = float(usable[-1][0]) - float(usable[0][0])
if span < min_span:
return None
return round((float(usable[-1][1]) - float(usable[0][1])) / span * 1e6, 1)
def classify_rate(ppm):
"""Say whether the offset is standing still or growing. Pure."""
if ppm is None:
return ("rate-not-measurable",
"the samples do not span %ds, which is the least this "
"measurement can support. Re-run with a longer interval if you "
"want a rate rather than an offset." % MIN_DRIFT_SPAN)
if abs(ppm) <= FREE_RUNNING_PPM:
return ("offset-is-static",
"the offset is holding at %.1f ppm, so the clock is "
"disciplined and was simply set wrong once." % ppm)
return ("clock-is-running-free",
"the offset is moving at %.1f ppm, which is about %.1f seconds a "
"day. Nothing is disciplining this clock, so setting it by hand "
"buys only a few days." % (ppm, ppm * 0.0864))
def interpret(status, message):
"""Map a confirming GET /app response to the defect it names. Pure.
Only the iat family is this note's business. The other messages are named
so the report can point at the right neighbour rather than absorbing them.
"""
if status == 200:
return ("accepted", "GitHub did not complain about iat.")
text = str(message or "").lower()
if "issued at" in text or "'iat'" in text:
return ("github-refused-iat",
"GitHub says iat is not a time that has happened, which is "
"this host being ahead of it.")
if "too far in the future" in text:
return ("lifetime-not-drift",
"GitHub is complaining about exp rather than iat, so the "
"requested lifetime is over the ceiling and the clock is not "
"the problem.")
if "could not be decoded" in text:
return ("key-or-encoding",
"GitHub could not decode the JWT at all, which is a signing "
"key or encoding fault rather than a clock one.")
if "integration not found" in text:
return ("issuer-does-not-resolve",
"the iss claim does not name an App GitHub can find, which is "
"a key and issuer problem rather than a clock one.")
return ("unrelated",
"the response does not mention a claim, so this failure has "
"another cause.")
def take_samples(count, interval):
"""Time `count` exchanges against GitHub. The only network in this script."""
out = []
for i in range(count):
if i:
time.sleep(interval)
sent = time.time()
try:
r = requests.get(API + "/rate_limit", timeout=30, headers={
"Accept": "application/vnd.github+json",
"X-GitHub-Api-Version": "2022-11-28",
"User-Agent": UA,
})
except requests.RequestException as err:
log.warning("sample %d failed: %s", i + 1, err)
continue
received = time.time()
served = parse_http_date(r.headers.get("Date"))
if served is None:
log.warning("sample %d carried no usable Date header", i + 1)
continue
out.append(sample_skew(served, sent, received))
return out
def main():
ap = argparse.ArgumentParser(description=__doc__)
ap.add_argument("--samples", type=int, default=3,
help="how many exchanges to time (default 3)")
ap.add_argument("--interval", type=float, default=2.0,
help="seconds between samples; use 30 or more if you want "
"a drift rate as well as an offset (default 2)")
ap.add_argument("--backdate", type=int, default=0,
help="the seconds your signing code already subtracts from "
"iat (default 0, which is the common case)")
ap.add_argument("--confirm", action="store_true",
help="also send GITHUB_APP_JWT to GET /app and report what "
"GitHub says about the claim")
args = ap.parse_args()
samples = take_samples(max(args.samples, 1), max(args.interval, 0.0))
best = best_sample(samples)
if best is None:
log.error("no sample produced a reading; nothing can be said about "
"this clock")
return 2
log.info("best of %d sample(s): skew=%+.1fs uncertainty=%.1fs "
"round_trip=%.2fs", len(samples), best["skew"],
best["uncertainty"], best["round_trip"])
state, detail = classify(best["skew"], best["uncertainty"], args.backdate)
log.info("%s: %s", state, detail)
readings = [(s["at"], s["skew"]) for s in samples if s]
ppm = drift_rate(readings)
rate_state, rate_detail = classify_rate(ppm)
log.info("%s: %s", rate_state, rate_detail)
if args.confirm:
jwt = os.environ.get("GITHUB_APP_JWT")
if not jwt:
log.warning("--confirm needs GITHUB_APP_JWT set to the JWT your "
"own signing code produces")
else:
# The JWT is sent and nothing else. It is not decoded, stored or
# logged, in whole or in part.
r = requests.get(API + "/app", timeout=30, headers={
"Authorization": "Bearer " + jwt,
"Accept": "application/vnd.github+json",
"X-GitHub-Api-Version": "2022-11-28",
"User-Agent": UA,
})
try:
body = r.json()
except ValueError:
body = None
message = body.get("message") if isinstance(body, dict) else None
log.info("GET /app returned %d", r.status_code)
live_state, live_detail = interpret(r.status_code, message)
log.info("%s: %s", live_state, live_detail)
if state in ("iat-lands-in-the-future", "backdate-has-no-headroom"):
log.info("repair: set iat to now minus %ds when minting, then "
"install time sync on this host so the offset stops moving",
backdate_needed(best["skew"], best["uncertainty"]))
print(json.dumps({"skew_seconds": best["skew"],
"uncertainty_seconds": best["uncertainty"],
"round_trip_seconds": best["round_trip"],
"samples": len(samples), "backdate_seconds": args.backdate,
"drift_ppm": ppm, "state": state}, indent=2))
return 0 if state in ("clock-in-sync", "drift-absorbed-by-backdate") else 1
if __name__ == "__main__":
sys.exit(main())
/**
* Measure the clock on the machine that signs GitHub App JWTs.
*
* Read only, and the part that matters needs no credential. Every GitHub
* response carries a Date header, so the reference clock is free: time a
* request from both ends and the offset falls out with an error bar attached.
*
* GET /rate_limit is used for the samples because it answers unauthenticated
* and does not consume quota.
*
* This script does not open your JWT. The question is whether the machine
* writing iat agrees with the machine reading it.
*
* Sign convention: skew is local minus server, so positive means this host is
* ahead of GitHub, which is the direction that breaks a JWT.
*/
const API = 'https://api.github.com';
const UA = 'github-clock-skew/1.0';
/** The Date header is quantised to a whole second, so every reading carries this floor. */
export const DATE_RESOLUTION = 1.0;
/** Below this the two clocks are close enough that nothing is actionable. */
export const GRACE = 5;
/** GitHub's own documented advice for the signing code. */
export const RECOMMENDED_BACKDATE = 60;
/** A rate computed over a shorter span than this is noise. */
export const MIN_DRIFT_SPAN = 60;
/** Roughly the discipline a working time daemon holds. */
export const FREE_RUNNING_PPM = 100;
/** Parse an RFC 9110 Date header into epoch seconds. Pure. null on anything odd. */
export function parseHttpDate(value) {
if (!value) return null;
const ms = Date.parse(String(value));
return Number.isNaN(ms) ? null : ms / 1000;
}
/**
* One exchange reduced to an offset with an error bar. Pure.
* The server read its clock somewhere between sent and received, so the
* midpoint is the fairest local comparison and half the round trip, plus the
* one second of quantisation, bounds how wrong it can be.
*/
export function sampleSkew(serverEpoch, sent, received) {
if (serverEpoch === null || serverEpoch === undefined) return null;
const roundTrip = Math.max(Number(received) - Number(sent), 0);
const midpoint = (Number(sent) + Number(received)) / 2;
const round3 = (n) => Math.round(n * 1000) / 1000;
return {
skew: round3(midpoint - Number(serverEpoch)),
uncertainty: round3(roundTrip / 2 + DATE_RESOLUTION),
round_trip: round3(roundTrip),
at: round3(Number(received)),
};
}
/**
* The exchange with the shortest round trip. Pure.
* Not the mean and not the median: the fastest exchange had the least room to
* be asymmetric, which is the same reason a time daemon prefers it.
*/
export function bestSample(samples) {
const usable = (samples || []).filter(Boolean);
if (!usable.length) return null;
return usable.reduce((a, b) => (b.round_trip < a.round_trip ? b : a));
}
/**
* Hours of offset when the skew looks like a timezone rather than drift. Pure.
* Backdating sixty seconds does nothing about five hours, so this is worth
* naming separately.
*/
export function timezoneSuspect(skew) {
if (skew === null || skew === undefined) return null;
const magnitude = Math.abs(Number(skew));
if (magnitude < 1500) return null;
const slots = Math.round(magnitude / 1800);
if (slots === 0) return null;
if (Math.abs(magnitude - slots * 1800) <= 90) {
const hours = slots / 2;
return skew > 0 ? hours : -hours;
}
return null;
}
/** How far to backdate iat so this offset cannot reach GitHub's future. Pure. */
export function backdateNeeded(skew, uncertainty) {
const need = Number(skew) + Number(uncertainty) + GRACE;
if (need <= RECOMMENDED_BACKDATE) return RECOMMENDED_BACKDATE;
return Math.ceil(need / 30) * 30;
}
/**
* Turn one measured offset into a finding. Pure.
* Direction first: ahead of GitHub breaks iat, behind it burns the lifetime.
*/
export function classify(skew, uncertainty, backdate) {
if (skew === null || skew === undefined) {
return ['unmeasurable',
'no response carried a usable Date header, so there is no reference ' +
'clock to compare against. Check that something is not stripping ' +
'response headers in front of this host.'];
}
const hours = timezoneSuspect(skew);
if (hours !== null) {
return ['timezone-not-drift',
`the offset is ${hours > 0 ? '+' : ''}${hours.toFixed(1)} hours, which ` +
'is a timezone conversion rather than a clock fault. Something built ' +
'the timestamp from a naive local datetime and treated it as UTC. ' +
'Backdating will not help; the conversion has to be fixed.'];
}
if (skew > 0) {
const margin = Number(backdate) - (Number(skew) + Number(uncertainty));
if (margin < 0) {
return ['iat-lands-in-the-future',
`this host is ${skew.toFixed(1)}s ahead of GitHub and iat is ` +
`backdated by ${backdate}s, so the claim lands ${(-margin).toFixed(1)}s ` +
'into GitHub\'s future and the JWT is refused. Backdate by ' +
`${backdateNeeded(skew, uncertainty)}s and fix the host clock.`];
}
if (margin < GRACE) {
return ['backdate-has-no-headroom',
`this host is ${skew.toFixed(1)}s ahead of GitHub and the ${backdate}s ` +
`backdate absorbs it with only ${margin.toFixed(1)}s to spare, which ` +
'is close enough to fail on a fast network. Backdate by ' +
`${backdateNeeded(skew, uncertainty)}s.`];
}
if (Math.abs(skew) <= Math.max(uncertainty, GRACE)) {
return ['clock-in-sync',
`this host and GitHub agree to within the measurement error of ` +
`${Number(uncertainty).toFixed(1)}s.`];
}
return ['drift-absorbed-by-backdate',
`this host is ${skew.toFixed(1)}s ahead of GitHub, and the ${backdate}s ` +
`backdate covers it with ${margin.toFixed(1)}s to spare. The JWT is ` +
'safe; the clock is still wrong and worth fixing.'];
}
if (Math.abs(skew) <= Math.max(uncertainty, GRACE)) {
return ['clock-in-sync',
`this host and GitHub agree to within the measurement error of ` +
`${Number(uncertainty).toFixed(1)}s.`];
}
return ['clock-behind-github',
`this host is ${(-skew).toFixed(1)}s behind GitHub. iat is safe, but ` +
`every JWT arrives having already spent ${(-skew).toFixed(1)}s of its ` +
'life, so a short lifetime can expire on the way.'];
}
/**
* Parts per million of drift between the first and last reading. Pure.
* readings: [[localTime, skew], ...]. null when the span is too short to
* support a rate, which is most of the time.
*/
export function driftRate(readings, minSpan = MIN_DRIFT_SPAN) {
const usable = (readings || []).filter((r) => r && r[1] !== null && r[1] !== undefined);
if (usable.length < 2) return null;
const span = Number(usable[usable.length - 1][0]) - Number(usable[0][0]);
if (span < minSpan) return null;
const delta = Number(usable[usable.length - 1][1]) - Number(usable[0][1]);
return Math.round((delta / span) * 1e6 * 10) / 10;
}
/** Say whether the offset is standing still or growing. Pure. */
export function classifyRate(ppm) {
if (ppm === null || ppm === undefined) {
return ['rate-not-measurable',
`the samples do not span ${MIN_DRIFT_SPAN}s, which is the least this ` +
'measurement can support. Re-run with a longer interval if you want a ' +
'rate rather than an offset.'];
}
if (Math.abs(ppm) <= FREE_RUNNING_PPM) {
return ['offset-is-static',
`the offset is holding at ${ppm.toFixed(1)} ppm, so the clock is ` +
'disciplined and was simply set wrong once.'];
}
return ['clock-is-running-free',
`the offset is moving at ${ppm.toFixed(1)} ppm, which is about ` +
`${(ppm * 0.0864).toFixed(1)} seconds a day. Nothing is disciplining this ` +
'clock, so setting it by hand buys only a few days.'];
}
/** Map a confirming GET /app response to the defect it names. Pure. */
export function interpret(status, message) {
if (status === 200) return ['accepted', 'GitHub did not complain about iat.'];
const text = String(message ?? '').toLowerCase();
if (text.includes('issued at') || text.includes("'iat'")) {
return ['github-refused-iat',
'GitHub says iat is not a time that has happened, which is this host ' +
'being ahead of it.'];
}
if (text.includes('too far in the future')) {
return ['lifetime-not-drift',
'GitHub is complaining about exp rather than iat, so the requested ' +
'lifetime is over the ceiling and the clock is not the problem.'];
}
if (text.includes('could not be decoded')) {
return ['key-or-encoding',
'GitHub could not decode the JWT at all, which is a signing key or ' +
'encoding fault rather than a clock one.'];
}
if (text.includes('integration not found')) {
return ['issuer-does-not-resolve',
'the iss claim does not name an App GitHub can find, which is a key ' +
'and issuer problem rather than a clock one.'];
}
return ['unrelated',
'the response does not mention a claim, so this failure has another cause.'];
}
const wait = (seconds) => new Promise((r) => setTimeout(r, seconds * 1000));
async function takeSamples(count, interval) {
const out = [];
for (let i = 0; i < count; i += 1) {
if (i) await wait(interval);
const sent = Date.now() / 1000;
let res;
try {
res = await fetch(`${API}/rate_limit`, {
headers: {
Accept: 'application/vnd.github+json',
'X-GitHub-Api-Version': '2022-11-28',
'User-Agent': UA,
},
});
} catch (err) {
console.error(`sample ${i + 1} failed: ${err.message}`);
continue;
}
const received = Date.now() / 1000;
const served = parseHttpDate(res.headers.get('date'));
if (served === null) {
console.error(`sample ${i + 1} carried no usable Date header`);
continue;
}
out.push(sampleSkew(served, sent, received));
}
return out;
}
function flag(name, fallback) {
const at = process.argv.indexOf(name);
if (at === -1 || at === process.argv.length - 1) return fallback;
const value = Number(process.argv[at + 1]);
return Number.isFinite(value) ? value : fallback;
}
async function main() {
const count = Math.max(flag('--samples', 3), 1);
const interval = Math.max(flag('--interval', 2), 0);
const backdate = flag('--backdate', 0);
const samples = await takeSamples(count, interval);
const best = bestSample(samples);
if (!best) {
console.error('no sample produced a reading; nothing can be said about this clock');
process.exitCode = 2;
return;
}
console.log(`best of ${samples.length} sample(s): skew=${best.skew >= 0 ? '+' : ''}` +
`${best.skew.toFixed(1)}s uncertainty=${best.uncertainty.toFixed(1)}s ` +
`round_trip=${best.round_trip.toFixed(2)}s`);
const [state, detail] = classify(best.skew, best.uncertainty, backdate);
console.log(`${state}: ${detail}`);
const ppm = driftRate(samples.filter(Boolean).map((s) => [s.at, s.skew]));
const [rateState, rateDetail] = classifyRate(ppm);
console.log(`${rateState}: ${rateDetail}`);
if (process.argv.includes('--confirm')) {
const jwt = process.env.GITHUB_APP_JWT;
if (!jwt) {
console.error('--confirm needs GITHUB_APP_JWT set to the JWT your own ' +
'signing code produces');
} else {
// The JWT is sent and nothing else. Never decoded, stored or logged.
const res = await fetch(`${API}/app`, {
headers: {
Authorization: `Bearer ${jwt}`,
Accept: 'application/vnd.github+json',
'X-GitHub-Api-Version': '2022-11-28',
'User-Agent': UA,
},
});
let body = null;
try { body = await res.json(); } catch { body = null; }
const message = body && typeof body === 'object' ? body.message : null;
console.log(`GET /app returned ${res.status}`);
const [liveState, liveDetail] = interpret(res.status, message);
console.log(`${liveState}: ${liveDetail}`);
}
}
if (state === 'iat-lands-in-the-future' || state === 'backdate-has-no-headroom') {
console.log(`repair: set iat to now minus ` +
`${backdateNeeded(best.skew, best.uncertainty)}s when minting, then ` +
'install time sync on this host so the offset stops moving');
}
console.log(JSON.stringify({
skew_seconds: best.skew,
uncertainty_seconds: best.uncertainty,
round_trip_seconds: best.round_trip,
samples: samples.length,
backdate_seconds: backdate,
drift_ppm: ppm,
state,
}, null, 2));
process.exitCode = (state === 'clock-in-sync' || state === 'drift-absorbed-by-backdate') ? 0 : 1;
}
// Only run when invoked directly, so importing this module from the test file
// does not execute main() and set an exit code that fails a passing suite.
if (import.meta.url === `file://${process.argv[1]}`) {
main().catch((err) => { console.error(err.message); process.exitCode = 2; });
}
Add a test
There is no credential anywhere in these tests, because there is none in the measurement either. Every case is three numbers — a server time and the two local times either side of the request — so a host forty seconds fast, a host five hours out by timezone and a network too slow to resolve either are all one line each. The two rules worth pinning are that the fastest exchange wins rather than the average, and that a drift rate over a four second span is refused rather than reported.
from github_clock_skew import (
GRACE, backdate_needed, best_sample, classify, classify_rate, drift_rate,
interpret, parse_http_date, sample_skew, timezone_suspect,
)
NOW = 1_772_000_000.0
def test_a_date_header_parses_to_epoch_seconds():
assert parse_http_date("Thu, 01 Jan 1970 00:00:10 GMT") == 10.0
assert parse_http_date("not a date") is None
assert parse_http_date("") is None
assert parse_http_date(None) is None
def test_one_exchange_becomes_an_offset_with_an_error_bar():
s = sample_skew(NOW, NOW + 40.0, NOW + 40.4)
assert s["skew"] == 40.2
assert s["uncertainty"] == 1.2
assert s["round_trip"] == 0.4
def test_a_response_without_a_date_produces_no_sample():
assert sample_skew(None, NOW, NOW + 0.2) is None
def test_the_fastest_exchange_wins_rather_than_the_average():
slow = sample_skew(NOW, NOW + 40.0, NOW + 44.0)
quick = sample_skew(NOW, NOW + 40.0, NOW + 40.1)
assert best_sample([slow, quick, None])["round_trip"] == 0.1
assert best_sample([]) is None
assert best_sample([None]) is None
def test_a_host_running_fast_with_no_backdate_is_the_headline_finding():
state, detail = classify(40.0, 1.0, 0)
assert state == "iat-lands-in-the-future"
assert "41.0s into GitHub" in detail
def test_the_same_offset_is_harmless_once_iat_is_backdated():
state, detail = classify(40.0, 1.0, 60)
assert state == "drift-absorbed-by-backdate"
assert "19.0s to spare" in detail
def test_a_backdate_that_only_just_covers_the_drift_is_still_flagged():
assert classify(58.0, 1.0, 60)[0] == "backdate-has-no-headroom"
def test_a_slow_path_cannot_resolve_a_small_offset():
# Three seconds of skew measured over a six second round trip is inside
# the error bar, so the honest answer is that the clocks agree.
assert classify(3.0, 4.0, 60)[0] == "clock-in-sync"
def test_a_clock_behind_github_is_its_own_state_and_its_own_consequence():
state, detail = classify(-45.0, 1.0, 60)
assert state == "clock-behind-github"
assert "already spent 45.0s" in detail
def test_whole_hours_are_a_timezone_and_not_drift():
assert timezone_suspect(-18000.0) == -5.0
assert timezone_suspect(19800.0) == 5.5
assert timezone_suspect(41.0) is None
assert timezone_suspect(2400.0) is None
state, detail = classify(18000.0, 1.0, 60)
assert state == "timezone-not-drift"
assert "naive local datetime" in detail
def test_the_backdate_recommendation_covers_the_offset_and_its_error_bar():
assert backdate_needed(5.0, 1.0) == 60
assert backdate_needed(200.0, 2.0) == 210
assert backdate_needed(-30.0, 1.0) == 60
def test_a_rate_is_refused_when_the_samples_are_too_close_together():
readings = [(NOW, 10.0), (NOW + 4, 10.4)]
assert drift_rate(readings) is None
state, detail = classify_rate(None)
assert state == "rate-not-measurable"
assert "60s" in detail
def test_a_growing_offset_is_reported_as_a_free_running_clock():
readings = [(NOW, 10.0), (NOW + 100, 10.05)]
ppm = drift_rate(readings)
assert ppm == 500.0
state, detail = classify_rate(ppm)
assert state == "clock-is-running-free"
assert "43.2 seconds a day" in detail
def test_a_static_offset_says_the_clock_was_set_wrong_once():
readings = [(NOW, 40.0), (NOW + 600, 40.0)]
assert classify_rate(drift_rate(readings))[0] == "offset-is-static"
def test_an_unmeasurable_clock_says_so_rather_than_guessing():
state, _ = classify(None, 1.0, 60)
assert state == "unmeasurable"
def test_the_live_messages_separate_iat_from_its_neighbours():
assert interpret(200, None)[0] == "accepted"
assert interpret(401, "'Issued at' claim ('iat') must be an Integer "
"representing the time that the assertion was "
"issued")[0] == "github-refused-iat"
assert interpret(401, "'Expiration time' claim ('exp') is too far in the "
"future")[0] == "lifetime-not-drift"
assert interpret(401, "A JSON web token could not be "
"decoded")[0] == "key-or-encoding"
assert interpret(404, "Integration not found")[0] == "issuer-does-not-resolve"
assert interpret(403, "Resource not accessible by integration")[0] == "unrelated"
def test_the_grace_band_is_the_one_place_a_number_is_shared():
assert GRACE == 5
import { test } from 'node:test';
import assert from 'node:assert/strict';
import {
GRACE, backdateNeeded, bestSample, classify, classifyRate, driftRate,
interpret, parseHttpDate, sampleSkew, timezoneSuspect,
} from './github-clock-skew.mjs';
const NOW = 1772000000;
test('a date header parses to epoch seconds', () => {
assert.equal(parseHttpDate('Thu, 01 Jan 1970 00:00:10 GMT'), 10);
assert.equal(parseHttpDate('not a date'), null);
assert.equal(parseHttpDate(''), null);
assert.equal(parseHttpDate(null), null);
});
test('one exchange becomes an offset with an error bar', () => {
const s = sampleSkew(NOW, NOW + 40.0, NOW + 40.4);
assert.equal(s.skew, 40.2);
assert.equal(s.uncertainty, 1.2);
assert.equal(s.round_trip, 0.4);
});
test('a response without a date produces no sample', () => {
assert.equal(sampleSkew(null, NOW, NOW + 0.2), null);
});
test('the fastest exchange wins rather than the average', () => {
const slow = sampleSkew(NOW, NOW + 40.0, NOW + 44.0);
const quick = sampleSkew(NOW, NOW + 40.0, NOW + 40.1);
assert.equal(bestSample([slow, quick, null]).round_trip, 0.1);
assert.equal(bestSample([]), null);
assert.equal(bestSample([null]), null);
});
test('a host running fast with no backdate is the headline finding', () => {
const [state, detail] = classify(40.0, 1.0, 0);
assert.equal(state, 'iat-lands-in-the-future');
assert.match(detail, /41.0s into GitHub/);
});
test('the same offset is harmless once iat is backdated', () => {
const [state, detail] = classify(40.0, 1.0, 60);
assert.equal(state, 'drift-absorbed-by-backdate');
assert.match(detail, /19.0s to spare/);
});
test('a backdate that only just covers the drift is still flagged', () => {
assert.equal(classify(58.0, 1.0, 60)[0], 'backdate-has-no-headroom');
});
test('a slow path cannot resolve a small offset', () => {
assert.equal(classify(3.0, 4.0, 60)[0], 'clock-in-sync');
});
test('a clock behind github is its own state and its own consequence', () => {
const [state, detail] = classify(-45.0, 1.0, 60);
assert.equal(state, 'clock-behind-github');
assert.match(detail, /already spent 45.0s/);
});
test('whole hours are a timezone and not drift', () => {
assert.equal(timezoneSuspect(-18000), -5);
assert.equal(timezoneSuspect(19800), 5.5);
assert.equal(timezoneSuspect(41), null);
assert.equal(timezoneSuspect(2400), null);
const [state, detail] = classify(18000, 1.0, 60);
assert.equal(state, 'timezone-not-drift');
assert.match(detail, /naive local datetime/);
});
test('the backdate recommendation covers the offset and its error bar', () => {
assert.equal(backdateNeeded(5, 1), 60);
assert.equal(backdateNeeded(200, 2), 210);
assert.equal(backdateNeeded(-30, 1), 60);
});
test('a rate is refused when the samples are too close together', () => {
assert.equal(driftRate([[NOW, 10.0], [NOW + 4, 10.4]]), null);
const [state, detail] = classifyRate(null);
assert.equal(state, 'rate-not-measurable');
assert.match(detail, /60s/);
});
test('a growing offset is reported as a free running clock', () => {
const ppm = driftRate([[NOW, 10.0], [NOW + 100, 10.05]]);
assert.equal(ppm, 500);
const [state, detail] = classifyRate(ppm);
assert.equal(state, 'clock-is-running-free');
assert.match(detail, /43.2 seconds a day/);
});
test('a static offset says the clock was set wrong once', () => {
assert.equal(classifyRate(driftRate([[NOW, 40], [NOW + 600, 40]]))[0], 'offset-is-static');
});
test('an unmeasurable clock says so rather than guessing', () => {
assert.equal(classify(null, 1.0, 60)[0], 'unmeasurable');
});
test('the live messages separate iat from its neighbours', () => {
assert.equal(interpret(200, null)[0], 'accepted');
assert.equal(interpret(401,
"'Issued at' claim ('iat') must be an Integer representing the time that the assertion was issued")[0],
'github-refused-iat');
assert.equal(interpret(401, "'Expiration time' claim ('exp') is too far in the future")[0],
'lifetime-not-drift');
assert.equal(interpret(401, 'A JSON web token could not be decoded')[0], 'key-or-encoding');
assert.equal(interpret(404, 'Integration not found')[0], 'issuer-does-not-resolve');
assert.equal(interpret(403, 'Resource not accessible by integration')[0], 'unrelated');
});
test('the grace band is the one place a number is shared', () => {
assert.equal(GRACE, 5);
});
FAQ
How far ahead does the clock have to be before GitHub refuses the JWT?
In practice, any amount at all, because there is no published tolerance to rely on and the comparison is against a moment that has to have already happened. A host a second fast fails only when the request arrives before GitHub's own second ticks over, so it fails intermittently rather than never, which is worse. That is the whole reason the documented advice is to set iat sixty seconds in the past: it is not a tolerance you are given, it is one you build yourself, and it costs nothing because the JWT is discarded after the exchange anyway.
Why measure against the Date header rather than an NTP server?
Because the clock that matters is GitHub's, and the Date header is GitHub's clock stated directly. An NTP server tells you your offset from a reference that GitHub is also tracking, which is nearly always the same answer, but it needs UDP 123 open outbound and it does not run from inside a locked-down build container. A GET you are already able to make does, and GET /rate_limit answers unauthenticated without consuming quota, so the check can run as a startup probe on every host that signs.
The offset it reports is about two seconds and my clock is fine. Is that real?
Probably not, and the uncertainty figure is there to tell you. The Date header is truncated to the whole second, so a reading can be up to a second off before the network is considered at all, and half the round trip is added on top of that. When the offset is smaller than the uncertainty the script says the clocks agree rather than reporting the number as a finding. If you want a tighter measurement, take more samples from a host with a quiet path and let it keep the fastest exchange.
Should I fix the container's clock or the host's?
The host's, because a container does not have one. Containers share the kernel's clock, so a container cannot be fast relative to the machine it runs on; what you are seeing is the machine being fast, and it will be fast for every container on it. Virtual machines are where this usually comes from: a suspended and resumed VM wakes up with the time it went to sleep with, and a hypervisor without guest time sync leaves it there. Fix time sync on the node and the whole fleet moves at once.
Can I just retry until the JWT is accepted?
It will appear to work and it will hide the fault for a year. A retry loop against a clock a few seconds fast succeeds roughly whenever the network is slow enough for GitHub's second to tick over first, so the failure rate drops to something that looks like ordinary upstream noise and the real offset keeps growing underneath. It also spends real time on every token exchange in a hot path. Backdating iat fixes it in one line and costs nothing, which is why the retry loop is not worth writing.
Related field notes
- A JWT that asks to live for an hour
- A JWT signed with the wrong key
- 401 Bad credentials on every endpoint
Sources
Every figure in this note is traced to one of these. Prices are list rates and change — check them for your own region before acting.
- Generating a JSON Web Token (JWT) for a GitHub App — GitHub Docs
- Authenticating as a GitHub App — GitHub Docs
- HTTP Semantics, the Date field — RFC 9110
- Rate limits for the REST API — GitHub Docs
If your setup is misbehaving in a way this note does not cover, message me on LinkedIn with what you are seeing.