Skip to content

Commit 1c81c8b

Browse files
authored
fix(tsa): gate on the clock's post-correction error, not the raw offset (#369)
Engine.succeed() stored LastOffset as the offset measured before any correction, and the TSA clock gate treated that as the clock's current error. A step corrects the offset down to roughly its root distance plus half the round-trip delay, but the gate kept judging it by the size of the correction that was just applied, so a boot step larger than max_clock_error_ms left every TSA request refused with timeNotAvailable until the next poll, even though the clock was already correct. Add last_sync_error to TimeSyncStatus: for a step, the residual actually passed to Clock.MarkSynced; for a slew, the full offset measured, since a slew has not caught up to it yet. ClockGate and EstimatedClockError now read that field instead of last_offset. last_offset keeps its old meaning (the pre-correction measurement) for display. Refs #364 Signed-off-by: Bugs5382 <12115015+Bugs5382@users.noreply.github.com> Co-authored-by: Bugs5382 <12115015+Bugs5382@users.noreply.github.com>
1 parent 40d5477 commit 1c81c8b

9 files changed

Lines changed: 301 additions & 163 deletions

File tree

‎docs/tsa.md‎

Lines changed: 11 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -102,11 +102,17 @@ so one unanswered poll does not stop it. Every request is answered
102102
| `max_sync_age` | the last good sync is older than `max_sync_age_seconds` | 3600 (1 hour) |
103103
| `max_clock_error` | the estimated clock error is larger than `max_clock_error_ms` | `accuracy_ms` (1 second) |
104104

105-
The estimated clock error is the offset measured at the last good sync plus
106-
`max_drift_ppm` parts per million of the time since it. At the defaults, a
107-
sync that measured 20 ms gives an estimate of 20 ms + 360 ms = 380 ms an hour
108-
later, inside the 1 second bound. `max_drift_ppm` defaults to 100, a
109-
conservative bound for a server crystal; 500 is the NTP frequency tolerance.
105+
The estimated clock error is the clock's error right after the last good
106+
sync, plus `max_drift_ppm` parts per million of the time since it. That
107+
right-after-sync figure is not the offset the sync corrected: once a sync
108+
steps the clock, what remains is bounded by the server's root distance and
109+
half the round-trip delay, typically a few milliseconds, not the (possibly
110+
much larger) step that was just applied; a slew has not caught up to its
111+
offset yet, so its figure is the full measured offset until the next sync. At
112+
the defaults, a sync left with a 20 ms error gives an estimate of
113+
20 ms + 360 ms = 380 ms an hour later, inside the 1 second bound.
114+
`max_drift_ppm` defaults to 100, a conservative bound for a server crystal;
115+
500 is the NTP frequency tolerance.
110116

111117
`max_clock_error_ms` may not be larger than the effective `accuracy_ms`:
112118
`config apply` refuses it, because a token must never claim more accuracy than

‎gen/go/cryptos/node/v1/status.pb.go‎

Lines changed: 132 additions & 109 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎internal/init/tsa_test.go‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -70,9 +70,10 @@ func newTSAFixture(t *testing.T) *tsaFixture {
7070
return &nodev1.TimeSyncStatus{State: nodev1.TimeSyncState_TIME_SYNC_STATE_PENDING}
7171
}
7272
return &nodev1.TimeSyncStatus{
73-
State: nodev1.TimeSyncState_TIME_SYNC_STATE_SYNCED,
74-
LastOffset: durationpb.New(3 * time.Millisecond),
75-
LastSync: timestamppb.Now(),
73+
State: nodev1.TimeSyncState_TIME_SYNC_STATE_SYNCED,
74+
LastOffset: durationpb.New(3 * time.Millisecond),
75+
LastSyncError: durationpb.New(3 * time.Millisecond),
76+
LastSync: timestamppb.Now(),
7677
}
7778
},
7879
}

‎internal/timesync/engine.go‎

Lines changed: 31 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -128,17 +128,18 @@ type Engine struct {
128128
// round serialises sync rounds.
129129
round sync.Mutex
130130

131-
mu sync.Mutex
132-
state nodev1.TimeSyncState
133-
syncedOnce bool
134-
lastServer string
135-
lastOffset time.Duration
136-
hasOffset bool
137-
stratum uint32
138-
lastSync time.Time
139-
stepped bool
140-
lastErr string
141-
refused bool
131+
mu sync.Mutex
132+
state nodev1.TimeSyncState
133+
syncedOnce bool
134+
lastServer string
135+
lastOffset time.Duration
136+
lastSyncError time.Duration
137+
hasOffset bool
138+
stratum uint32
139+
lastSync time.Time
140+
stepped bool
141+
lastErr string
142+
refused bool
142143
}
143144

144145
// New builds an Engine. It does no I/O.
@@ -223,6 +224,7 @@ func (e *Engine) Status() *nodev1.TimeSyncStatus {
223224
}
224225
if e.hasOffset {
225226
st.LastOffset = durationpb.New(e.lastOffset)
227+
st.LastSyncError = durationpb.New(e.lastSyncError)
226228
}
227229
if !e.lastSync.IsZero() {
228230
st.LastSync = timestamppb.New(e.lastSync)
@@ -613,7 +615,7 @@ func (e *Engine) apply(samples []Sample, errs map[string]error, boot bool) {
613615
if err := e.cfg.Floor.Advance(synced); err != nil {
614616
e.log.Error("clock floor: could not record the synced time", "err", err)
615617
}
616-
e.succeed(s, synced, boot && step)
618+
e.succeed(s, synced, boot && step, step)
617619
}
618620

619621
// refuse records a round in which servers answered but the clock was not
@@ -638,20 +640,21 @@ func (e *Engine) fail(msg string, level slog.Level) {
638640
e.log.Log(context.Background(), level, "time sync round did not adjust the clock", "reason", msg)
639641
}
640642

641-
func (e *Engine) succeed(s Sample, at time.Time, stepped bool) {
643+
func (e *Engine) succeed(s Sample, at time.Time, bootStep, stepped bool) {
642644
e.mu.Lock()
643645
prev := e.state
644646
first := !e.syncedOnce
645647
e.state = nodev1.TimeSyncState_TIME_SYNC_STATE_SYNCED
646648
e.syncedOnce = true
647649
e.lastServer = s.Server
648650
e.lastOffset = s.Offset
651+
e.lastSyncError = syncError(s, stepped)
649652
e.hasOffset = true
650653
e.stratum = uint32(s.Stratum)
651654
e.lastSync = at
652655
e.lastErr = ""
653656
e.refused = false
654-
if stepped {
657+
if bootStep {
655658
e.stepped = true
656659
}
657660
e.mu.Unlock()
@@ -663,6 +666,20 @@ func (e *Engine) succeed(s Sample, at time.Time, stepped bool) {
663666
}
664667
}
665668

669+
// syncError is the clock's estimated error right after this round, for the
670+
// gate TSA uses to decide whether to trust the clock: a step corrects the
671+
// clock down to about its root distance plus half the round-trip delay (the
672+
// same figure passed to Clock.MarkSynced), so that residual is what remains,
673+
// not the much larger offset the step was asked to correct; a slew has not
674+
// caught up to the offset yet, so its estimate is still the full offset
675+
// measured, as before.
676+
func syncError(s Sample, stepped bool) time.Duration {
677+
if stepped {
678+
return s.RootDistance + s.Delay/2
679+
}
680+
return absDuration(s.Offset)
681+
}
682+
666683
// fmtFloorError is the reason a step below the floor was refused.
667684
func fmtFloorError(target, floor time.Time) string {
668685
return fmt.Sprintf("server time %s is behind already-issued certificates or the last good sync (floor %s)",

‎internal/timesync/engine_test.go‎

Lines changed: 71 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -96,12 +96,14 @@ type fakeServer struct {
9696
clock *fakeClock
9797
requests atomic.Int32
9898

99-
mu sync.Mutex
100-
offset time.Duration
101-
stratum uint8
102-
leap uint8
103-
kiss string
104-
drop bool
99+
mu sync.Mutex
100+
offset time.Duration
101+
stratum uint8
102+
leap uint8
103+
kiss string
104+
drop bool
105+
rootDelay Short
106+
rootDispersion Short
105107
}
106108

107109
func newFakeServer(t *testing.T, clock *fakeClock, offset time.Duration) *fakeServer {
@@ -110,12 +112,18 @@ func newFakeServer(t *testing.T, clock *fakeClock, offset time.Duration) *fakeSe
110112
if err != nil {
111113
t.Fatalf("listen: %v", err)
112114
}
113-
s := &fakeServer{conn: conn, clock: clock, offset: offset, stratum: 2}
115+
s := &fakeServer{conn: conn, clock: clock, offset: offset, stratum: 2, rootDelay: 0x00000100, rootDispersion: 0x00000100}
114116
t.Cleanup(func() { _ = conn.Close() })
115117
go s.serve()
116118
return s
117119
}
118120

121+
// shortFrom converts d to the NTP 16.16 fixed-point form used for root delay
122+
// and root dispersion.
123+
func shortFrom(d time.Duration) Short {
124+
return Short(uint64(d) * 65536 / uint64(time.Second))
125+
}
126+
119127
func (s *fakeServer) set(fn func(*fakeServer)) {
120128
s.mu.Lock()
121129
defer s.mu.Unlock()
@@ -136,14 +144,15 @@ func (s *fakeServer) serve() {
136144
}
137145
s.mu.Lock()
138146
drop, off, stratum, leap, kiss := s.drop, s.offset, s.stratum, s.leap, s.kiss
147+
rootDelay, rootDispersion := s.rootDelay, s.rootDispersion
139148
s.mu.Unlock()
140149
if drop {
141150
continue
142151
}
143152
now := TimestampFromTime(s.clock.Now().Add(off))
144153
reply := Header{
145154
Leap: leap, Version: 4, Mode: ModeServer, Stratum: stratum,
146-
RootDelay: 0x00000100, RootDispersion: 0x00000100,
155+
RootDelay: rootDelay, RootDispersion: rootDispersion,
147156
Origin: req.Transmit, Receive: now, Transmit: now,
148157
}
149158
if kiss != "" {
@@ -289,6 +298,44 @@ func TestBootSyncStepsALargeOffset(t *testing.T) {
289298
}
290299
}
291300

301+
// A boot step corrects the clock down to roughly its root distance, so the
302+
// TSA's clock gate (which reads GetLastSyncError, not the raw offset the step
303+
// was asked to correct) sees it as trustworthy at once, not still 5s off.
304+
func TestBootSyncStepLeavesASmallPostStepSyncError(t *testing.T) {
305+
h := newHarness(t)
306+
h.add("192.0.2.1", 5*time.Second)
307+
e := h.engine()
308+
e.BootSync(context.Background())
309+
310+
st := e.Status()
311+
if !approx(st.GetLastOffset().AsDuration(), 5*time.Second) {
312+
t.Fatalf("last offset = %v, want it to keep the raw measured offset", st.GetLastOffset().AsDuration())
313+
}
314+
if got := st.GetLastSyncError().AsDuration(); got >= time.Second {
315+
t.Fatalf("last sync error = %v, want well under the 5s step (the clock was already corrected)", got)
316+
}
317+
}
318+
319+
// A server with a large root distance leaves the clock genuinely less
320+
// trustworthy even after a step corrects the bulk of the offset; the post-step
321+
// sync error estimate must still reflect that, not collapse to near zero.
322+
func TestBootSyncStepRecordsSyncErrorFromRootDistance(t *testing.T) {
323+
h := newHarness(t)
324+
s := h.add("192.0.2.1", 5*time.Second)
325+
s.set(func(s *fakeServer) { s.rootDelay = 0; s.rootDispersion = shortFrom(600 * time.Millisecond) })
326+
e := h.engine()
327+
e.BootSync(context.Background())
328+
329+
st := e.Status()
330+
if !approx(st.GetLastOffset().AsDuration(), 5*time.Second) {
331+
t.Fatalf("last offset = %v, want it to keep the raw measured offset", st.GetLastOffset().AsDuration())
332+
}
333+
got := st.GetLastSyncError().AsDuration()
334+
if got < 550*time.Millisecond || got > 750*time.Millisecond {
335+
t.Fatalf("last sync error = %v, want it to track the 600ms root distance, not the 5s offset or ~0", got)
336+
}
337+
}
338+
292339
func TestBootSyncSlewsASmallOffset(t *testing.T) {
293340
h := newHarness(t)
294341
h.add("192.0.2.1", 60*time.Millisecond)
@@ -303,6 +350,22 @@ func TestBootSyncSlewsASmallOffset(t *testing.T) {
303350
}
304351
}
305352

353+
// A slew has not caught up to the offset yet when the round finishes, so its
354+
// post-sync error estimate is still the full offset measured, unchanged from
355+
// before this estimate existed.
356+
func TestBootSyncSlewSyncErrorIsTheFullOffset(t *testing.T) {
357+
h := newHarness(t)
358+
h.add("192.0.2.1", 60*time.Millisecond)
359+
e := h.engine()
360+
e.BootSync(context.Background())
361+
362+
st := e.Status()
363+
if !approx(st.GetLastSyncError().AsDuration(), st.GetLastOffset().AsDuration()) {
364+
t.Fatalf("last sync error = %v, last offset = %v; want them equal for a slew",
365+
st.GetLastSyncError().AsDuration(), st.GetLastOffset().AsDuration())
366+
}
367+
}
368+
306369
// A node with no time source runs on its hardware clock and is never gated.
307370
func TestNoSourceIsNotConfiguredAndNeverGated(t *testing.T) {
308371
h := newHarness(t)

‎internal/tsa/clock.go‎

Lines changed: 14 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -84,29 +84,30 @@ func (r *ClockRefusal) Public() string {
8484
}
8585

8686
// EstimatedClockError is how far the clock may be off: the magnitude of the
87-
// offset measured at the last good sync plus ppm parts per million of the
88-
// time since it.
89-
func EstimatedClockError(offset, age time.Duration, ppm uint32) time.Duration {
90-
return offset.Abs() + age/1_000_000*time.Duration(ppm) + age%1_000_000*time.Duration(ppm)/1_000_000
87+
// clock's error estimate at the last good sync plus ppm parts per million of
88+
// the time since it.
89+
func EstimatedClockError(syncErr, age time.Duration, ppm uint32) time.Duration {
90+
return syncErr.Abs() + age/1_000_000*time.Duration(ppm) + age%1_000_000*time.Duration(ppm)/1_000_000
9191
}
9292

9393
// ClockGate returns the TSA's clock check over the node's time-sync status.
9494
// The clock may be stamped while the last good sync of this boot is no
9595
// older than MaxSyncAge and the estimated clock error (EstimatedClockError
96-
// over the offset it measured and the time since) is no larger than
97-
// MaxClockError. A poll that no server answered does not refuse on its own,
98-
// so one lost packet does not stop the TSA; a round that was answered but
99-
// not applied (adjustment_refused: the sources disagree, or a step was
100-
// refused) does, until the next good sync. A node with no time source never
101-
// syncs and is always refused. Unlike certificate signing there is no
102-
// override: a timestamp is nothing but a claim about the time.
96+
// over the clock's post-correction error estimate at that sync and the time
97+
// since) is no larger than MaxClockError. A poll that no server answered does
98+
// not refuse on its own, so one lost packet does not stop the TSA; a round
99+
// that was answered but not applied (adjustment_refused: the sources
100+
// disagree, or a step was refused) does, until the next good sync. A node
101+
// with no time source never syncs and is always refused. Unlike certificate
102+
// signing there is no override: a timestamp is nothing but a claim about the
103+
// time.
103104
func ClockGate(status func() *nodev1.TimeSyncStatus, limits ClockLimits, now func() time.Time) func() error {
104105
return func() error {
105106
st := status()
106107
if st == nil {
107108
return &ClockRefusal{Limit: LimitNoGoodSync, Detail: "the time sync status is unavailable"}
108109
}
109-
if st.GetLastSync() == nil || st.GetLastOffset() == nil {
110+
if st.GetLastSync() == nil || st.GetLastSyncError() == nil {
110111
return &ClockRefusal{Limit: LimitNoGoodSync, Detail: st.GetLastError()}
111112
}
112113
if st.GetAdjustmentRefused() {
@@ -116,7 +117,7 @@ func ClockGate(status func() *nodev1.TimeSyncStatus, limits ClockLimits, now fun
116117
if age > limits.MaxSyncAge {
117118
return &ClockRefusal{Limit: LimitMaxSyncAge, Value: age.Round(time.Millisecond).String(), Bound: limits.MaxSyncAge.String()}
118119
}
119-
if est := EstimatedClockError(st.GetLastOffset().AsDuration(), age, limits.MaxDriftPPM); est > limits.MaxClockError {
120+
if est := EstimatedClockError(st.GetLastSyncError().AsDuration(), age, limits.MaxDriftPPM); est > limits.MaxClockError {
120121
return &ClockRefusal{Limit: LimitMaxClockError, Value: est.String(), Bound: limits.MaxClockError.String()}
121122
}
122123
return nil

‎internal/tsa/clock_test.go‎

Lines changed: 22 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -30,13 +30,17 @@ import (
3030

3131
var gateNow = time.Date(2026, 6, 1, 12, 0, 0, 0, time.UTC)
3232

33-
// goodSync is a time-sync status whose last good sync was age ago and
34-
// measured offset. state is what the latest round left behind.
35-
func goodSync(state nodev1.TimeSyncState, offset, age time.Duration) *nodev1.TimeSyncStatus {
33+
// goodSync is a time-sync status whose last good sync was age ago, with
34+
// syncErr as both the raw measured offset and the post-correction error
35+
// estimate (the two coincide for a slew, or a step whose residual happens to
36+
// match what was measured; see the gate tests below for a step where they
37+
// differ). state is what the latest round left behind.
38+
func goodSync(state nodev1.TimeSyncState, syncErr, age time.Duration) *nodev1.TimeSyncStatus {
3639
return &nodev1.TimeSyncStatus{
37-
State: state,
38-
LastOffset: durationpb.New(offset),
39-
LastSync: timestamppb.New(gateNow.Add(-age)),
40+
State: state,
41+
LastOffset: durationpb.New(syncErr),
42+
LastSyncError: durationpb.New(syncErr),
43+
LastSync: timestamppb.New(gateNow.Add(-age)),
4044
}
4145
}
4246

@@ -93,6 +97,18 @@ func TestClockGate(t *testing.T) {
9397
return st
9498
}(), limit: LimitAdjustmentRefused},
9599
"last sync after now counts as fresh": {status: goodSync(synced, 0, -time.Minute)},
100+
"a boot step's large raw offset does not by itself refuse": {status: &nodev1.TimeSyncStatus{
101+
State: synced,
102+
LastOffset: durationpb.New(5 * time.Second),
103+
LastSyncError: durationpb.New(10 * time.Millisecond),
104+
LastSync: timestamppb.New(gateNow),
105+
}},
106+
"a genuinely large post-correction error still refuses despite a small raw offset": {status: &nodev1.TimeSyncStatus{
107+
State: synced,
108+
LastOffset: durationpb.New(20 * time.Millisecond),
109+
LastSyncError: durationpb.New(1500 * time.Millisecond),
110+
LastSync: timestamppb.New(gateNow),
111+
}, limit: LimitMaxClockError},
96112
} {
97113
t.Run(name, func(t *testing.T) {
98114
l := tc.limits

‎internal/tsa/doc.go‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -31,9 +31,9 @@
3131
// refuses before the first good sync of the boot, after a round the servers
3232
// answered but that was not applied (adjustment_refused), once the last good
3333
// sync is older than ClockLimits.MaxSyncAge, and once the estimated clock
34-
// error (EstimatedClockError: the offset at the last good sync plus
35-
// MaxDriftPPM of the time since) is above MaxClockError, which is never
36-
// larger than the accuracy tokens claim.
34+
// error (EstimatedClockError: the clock's post-correction error estimate at
35+
// the last good sync plus MaxDriftPPM of the time since) is above
36+
// MaxClockError, which is never larger than the accuracy tokens claim.
3737
//
3838
// # Keys and certificates
3939
//

‎proto/cryptos/node/v1/status.proto‎

Lines changed: 13 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -147,8 +147,10 @@ message TimeSyncStatus {
147147
// sync, as queried (a hostname or an IPv4 literal). Empty until the first
148148
// good sync.
149149
string last_server = 4;
150-
// last_offset is the clock offset measured at the latest good sync: the
151-
// server's time minus the node's. Unset until the first good sync.
150+
// last_offset is the clock offset measured at the latest good sync, before
151+
// any correction: the server's time minus the node's. A step corrects most
152+
// of it at once, so after a step this is not how far off the clock still
153+
// is; see last_sync_error for that. Unset until the first good sync.
152154
google.protobuf.Duration last_offset = 5;
153155
// stratum is the stratum of last_server at the latest good sync. Zero until
154156
// the first good sync.
@@ -168,6 +170,15 @@ message TimeSyncStatus {
168170
// in which no server answered leaves it as it was, and the next good sync
169171
// clears it. The TSA refuses to stamp while it is set.
170172
bool adjustment_refused = 10;
173+
// last_sync_error is the clock's estimated error right after the latest
174+
// good sync: for a step, the residual the correction left behind (about
175+
// root distance plus half the round-trip delay, the same figure passed to
176+
// the kernel's MarkSynced); for a slew, the full measured offset, since a
177+
// slew has not caught up to it yet. Unlike last_offset, which keeps the
178+
// offset as measured before any correction, this is what the clock is
179+
// actually still off by, and is what gates time-stamping. Unset until the
180+
// first good sync.
181+
google.protobuf.Duration last_sync_error = 11;
171182
}
172183

173184
// TimeSyncState is the node's clock synchronisation state.

0 commit comments

Comments
 (0)