diff --git a/docs/deployment.md b/docs/deployment.md index f482da8a..24bb42e0 100644 --- a/docs/deployment.md +++ b/docs/deployment.md @@ -355,10 +355,28 @@ Both rolls are zero-loss in the other direction, because accept-both is on from phase 1: during the phase-2 roll, flipped and un-flipped instances are publishing different forms at the same time and every instance reads both. -**Rolling back** is symmetric: unset the variable and roll. Peers accept the -bare form throughout, so there is no window where a rollback loses events. -There is no Redis or database migration in either direction; the epoch key is -created by the first flipped publisher and is transient state. +**Rolling back to phase 1** is safe: make the effective value **false** and +roll. Peers accept the bare form throughout, so there is no window where this +direction loses events. + +Two things about rolling back that are easy to get wrong: + +- **Setting the value to false is not the same as unsetting the environment + variable.** `events_publish_epoch` can also be set in `~/.pad/config.toml`, + and the config file's value stands when the environment variable is absent. + Clear both, or set the environment variable explicitly to `false`. +- **Downgrading past phase 1 is a SECOND step, and the order is the reverse of + the upgrade.** A pre-phase-1 binary cannot parse the prefixed form. So: + first roll every instance to phase 1 (new binary, flip off) and let the roll + finish, *then* downgrade the binary. Introducing an old binary while any + flipped instance is still publishing drops events on the old one — the same + asymmetry that makes the upgrade two phases, in reverse. + +There is no Redis or database migration in either direction. The epoch key is +created by the first flipped publisher; a phase-1 instance deletes it if it +ever sees the sequence counter restart, so a counter that is reset while the +deployment sits on phase 1 does not leave a stale epoch for a later phase 2 to +adopt. **What you should see when phase 2 lands.** The first flipped message reaches each replica and, if that replica had already buffered un-prefixed events, it @@ -371,14 +389,24 @@ sequence key repeatedly; check `maxmemory-policy` against the events keyspace `pad_event_sequence_resets_total{reason="counter_backward"}` is the other counter to watch. It fires when an ID arrives at or below what a buffer had -already seen, which is expected in small numbers during **any** mixed-version -roll — an older binary assigns and publishes an ID in two separate calls, so -two instances can interleave and deliver them out of order. Phase 2 moves ID -assignment into a single atomic Redis script, which removes the interleave for -flipped publishers. It does **not** remove it for the roll itself: as long as -a deployment can run two publisher versions at once, out-of-order delivery is -possible, so this counter is expected to be non-zero during upgrades and near -zero between them. +already seen. + +**On phase 1 it can be non-zero at any time, not only during a roll.** Phase 1 +keeps the historical two-call publish — `INCR`, then `PUBLISH` — so two +instances can interleave (INCR 5, INCR 6, PUBLISH 6, PUBLISH 5) and a receiver +sees 5 arrive after 6. That window is older than this migration; phase 2 is +what closes it, by moving ID assignment into a single atomic script so publish +order equals ID order globally. + +So the expectation depends on where you are: + +- **Phase 1, steady state** — a low background rate on a busy multi-instance + deployment is normal and always was. +- **Any roll with two publisher versions running** — expect it to rise, in both + directions, for the length of the roll. +- **Phase 2, every publisher flipped** — expect it at or near zero. A + persistent rate here is an anomaly worth investigating rather than tuning + away. **What this migration does not fix.** A client's `Last-Event-ID` is still a bare integer with no epoch in it, and that is deliberate — every deployed diff --git a/internal/config/config.go b/internal/config/config.go index a6b0dc0c..8a6246ca 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -132,8 +132,13 @@ type Config struct { // 2 also moves ID assignment into a single atomic Redis script, so publish // order equals ID order globally. // - // Rolling BACK is safe in the same way and for the same reason: set it - // false and roll: peers accept the bare form throughout. See + // Rolling BACK TO PHASE 1 is safe for the same reason: set the EFFECTIVE + // value false and roll — peers accept the bare form throughout. Two + // wrinkles, both easy to get wrong: unsetting the environment variable is + // not the same as setting it false, because this field can also come from + // config.toml and the file's value stands when the variable is absent; and + // downgrading PAST phase 1 is a second step in the reverse order, because + // a pre-phase-1 binary still cannot parse the prefix. See // docs/deployment.md for the full procedure in both directions. EventsPublishEpoch bool `toml:"events_publish_epoch"` diff --git a/internal/events/redis_bus.go b/internal/events/redis_bus.go index ec5b9889..b819d34f 100644 --- a/internal/events/redis_bus.go +++ b/internal/events/redis_bus.go @@ -386,6 +386,37 @@ func (b *RedisBus) Publish(event Event) { // the JSON therefore cannot be marshalled until the ID is known — which is // the whole reason the atomic script and the prefix arrive together. id, err := b.client.Incr(b.ctx, b.keys.Name(redisSeqSuffix)).Result() + if err == nil && id == 1 { + // THE COUNTER RESTARTED WHILE WE WERE PUBLISHING THE BARE FORM, so + // any epoch left over from a previous phase-2 period now names a + // space that no longer exists — and phase 2's rotation cannot fix it, + // because that rotation is keyed on the script's own INCR returning 1 + // and by then the counter has already climbed past 1 under this path. + // + // The shape it closes (codex round 2): phase 2 mints epoch E and the + // sequence reaches 500; the deployment rolls back to phase 1; the seq + // key is then evicted or deleted; phase-1 publishers climb from 1 + // again; phase 2 is re-enabled and its SET NX finds E still there. A + // receiver that had adopted E sees no change, and if its high-water + // mark is below the new sequence — a replica that just started, or one + // whose buffers were empty — the numeric check does not see the reset + // either. Two ID spaces merge in one buffer silently, which is the one + // outcome this whole unit exists to prevent. + // + // Deleting rather than rotating: this path has no epoch to propose + // (it publishes no epoch at all), and an absent key is exactly what + // phase 2's SET NX expects to find when it mints a new one. + // + // The cost, stated so it is not rediscovered as a bug: during the + // phase-2 roll a phase-1 publisher could delete an epoch a flipped + // publisher had just minted, costing ONE extra buffer drop when the + // next epoch is minted. That is a loud, bounded resync, not a silent + // merge — the direction this family always chooses. + if delErr := b.client.Del(b.ctx, b.keys.Name(redisEpochSuffix)).Err(); delErr != nil { + slog.Warn("events: the sequence restarted but the stale ID-space epoch could not be cleared; a later phase-2 publish may reuse it", + "error", delErr) + } + } if err != nil { // NO LOCAL-COUNTER FALLBACK, and its removal is a fix rather than a // regression (BUG-2731). The previous version answered a failed INCR diff --git a/internal/events/redis_idspace_test.go b/internal/events/redis_idspace_test.go index d2aeedb1..5a7618f9 100644 --- a/internal/events/redis_idspace_test.go +++ b/internal/events/redis_idspace_test.go @@ -385,3 +385,63 @@ func TestABarePayloadAfterAdoptionLeavesTheEpochAlone(t *testing.T) { t.Fatalf("the adopted epoch must survive a bare message, got %q", b.epoch) } } + +func TestAPhaseOneRestartClearsAStaleEpoch(t *testing.T) { + // codex round 2. The sequence of events that made this reachable: + // phase 2 mints an epoch and the counter climbs; the deployment rolls + // back to phase 1; the seq key is lost; phase-1 publishers climb from 1 + // again; phase 2 is re-enabled and finds the OLD epoch still there, so + // nothing reports a change and two spaces can merge in one buffer. + mr := miniredis.RunT(t) + client := redis.NewClient(&redis.Options{Addr: mr.Addr()}) + t.Cleanup(func() { _ = client.Close() }) + + epochKey := redisns.Default.Name(redisEpochSuffix) + seqKey := redisns.Default.Name(redisSeqSuffix) + + // Phase 2 first: it is what writes an epoch at all. + flipped := NewRedisBusWithKeys(client, redisns.Default, true) + t.Cleanup(flipped.Close) + flipped.Publish(Event{Type: ItemUpdated, WorkspaceID: "ws-1"}) + + stale, err := mr.Get(epochKey) + if err != nil || stale == "" { + t.Fatalf("fixture: phase 2 must have written an epoch, got %q (%v)", stale, err) + } + + // Roll back to phase 1, then lose the counter. + phase1 := NewRedisBusWithKeys(client, redisns.Default, false) + t.Cleanup(phase1.Close) + mr.Del(seqKey) + + phase1.Publish(Event{Type: ItemUpdated, WorkspaceID: "ws-1"}) + + // PREMISE: the counter really did restart, or the branch under test was + // never entered and the assertion below would be about nothing. + if got, err := mr.Get(seqKey); err != nil || got != "1" { + t.Fatalf("fixture: the counter should have restarted at 1, reads %q (%v)", got, err) + } + if mr.Exists(epochKey) { + t.Fatal("a restarted counter must clear the stale epoch, or a later phase-2 publish reuses it for a space that no longer exists") + } + + // Control: an ordinary phase-1 publish, with the counter simply climbing, + // must NOT touch the epoch — otherwise every publish rotates it and the + // mechanism is worthless. + flipped.Publish(Event{Type: ItemUpdated, WorkspaceID: "ws-1"}) + fresh, err := mr.Get(epochKey) + if err != nil || fresh == "" { + t.Fatalf("fixture: the re-flipped publish must mint a new epoch, got %q (%v)", fresh, err) + } + if fresh == stale { + t.Fatal("the new epoch must differ from the one the dead space used") + } + phase1.Publish(Event{Type: ItemUpdated, WorkspaceID: "ws-1"}) + after, err := mr.Get(epochKey) + if err != nil { + t.Fatalf("read epoch: %v", err) + } + if after != fresh { + t.Fatalf("a phase-1 publish on a climbing counter must leave the epoch alone; %q became %q", fresh, after) + } +}