Skip to content

OPTI-3818: stop a transient DigitalOcean 422 from permanently stranding a Reserved IP - #1

Open
craig-johnston wants to merge 5 commits into
base-7db46fefrom
devin/OPTI-3818-flipop-422-retry
Open

OPTI-3818: stop a transient DigitalOcean 422 from permanently stranding a Reserved IP#1
craig-johnston wants to merge 5 commits into
base-7db46fefrom
devin/OPTI-3818-flipop-422-retry

Conversation

@craig-johnston

@craig-johnston craig-johnston commented Aug 5, 2026

Copy link
Copy Markdown

Fixes the flipop defect behind OPTI-3818: a transient DigitalOcean 422 permanently stranded the turn pool's Reserved IPs, causing a 2h31m production TURN outage on rts-sgp-1-production-cluster.

Based on base-7db46fe, the exact commit we run in production (digitaloceanapps/flipop:7db46fe, digest sha256:e627e528…), so this diff is the precise production delta. Upstream main (02016d5) does not fix any of this.

Root cause — not "missing retry"

Retrying on 422 would not have prevented the outage on its own, because no retry was ever attempted. The work item is lost from its queue before the retry machinery matters.

  1. orderedSet.Front() is a pop (ip_controller.go:847). reconcileAssignment pops the IP (:516) and the node (:527); the deferred requeue (:496-504) replays only the two early-continue guards. The AssignIP-error branch requeues neither, so both are dropped.
  2. The assignment is recorded before the API call (:546, :549) and never unwound. EnableNodes then reads that phantom entry (:676), logs enabling node; already assigned to ip — the exact line in our logs at 03:27:15Z — deletes the IP from assignableIPs (:685) and continues (:686), never reaching assignableNodes.Add (:689).
  3. reconcileIPStatus partially heals — re-adds the IP, clears nodeProviderID, sets state unassigned (our observed 8×unassigned) — but cannot requeue the node: the assignableNodes.Add at :470 is guarded by providerIDToNodeName[providerID], and providerID is "" by then.
  4. EnableNodes can never help again (:665, "Already enabled").
  5. assignableNodes is permanently empty, so the loop guard at :505 never passes again.

The 1-minute reconcile loop ran ~150 times and was structurally incapable of recovering. Only a restart rebuilds the queues — which is why rollout restart bound the IPs in 45 seconds.

Changes

floatingip: unwind assignment bookkeeping and requeue on AssignIP failure — the primary fix. Unwinds the two premature writes and requeues both the IP and the node. status.state / assignmentErrors are deliberately left set so the failure stays visible in the CRD status and the ip_assignment_errors metric.

provider/digitalocean: treat a 422 for an unowned IP as fast-retryable — secondary. When the 422 probe shows the IP is owned by nobody, return NewRetryError(err, RetryFast) rather than a bare error that ErrorToRetrySchedule maps to RetrySlow (1m/5m/10m, then 10m forever). The iErr == nil guard prevents misclassifying a failed IPToProviderID lookup. A 422 naming a different owner still yields RetrySlow — that is a real conflict.

floatingip: requeue a node whose IP is removed out of band — a second, independent stranding path, found by running the reproduction against the deployed image on dev. reconcileIPStatus guards the reassignment requeue on providerID (the IP's new owner) but requeues expectedProviderID (the node that lost it). When an IP is taken away entirely, providerID is "", the lookup fails, and the node is never returned to assignableNodes. No AssignIP call fails here, because none is ever made. Also stops writing providerIDToIP[""] = ip, which is read back as expectedIP on the next pass and fabricates a "node assignment mismatch" against an unrelated pool IP.

floatingip: defer assignment only on a retry deadline that has not elapsed — see below. Required by the first commit; without it the fix trades a stranded IP for a pegged CPU.

The retry gates: an earlier revision of this PR called these correct. That was wrong.

Both gates in reconcileAssignment deferred when the retry deadline had elapsed, then handed that already-past timestamp to i.retry():

if !status.nextRetry.IsZero() && !status.nextRetry.After(now) {
    retryIPs = append(retryIPs, ip)
    i.retry(status.nextRetry)   // already in the past
    continue
}

run() sleeps until i.nextRetry, so it re-enters reconcile() at or just after the deadline it was given — an elapsed deadline is the normal state on wake-up. retryTimerDuration() maps any past timestamp to 0, so the loop re-enters immediately, the gate skips again, and the controller busy-loops without ever retrying the bind.

Upstream never reached this, because the error branch dropped the IP and node from their queues entirely. Requeueing them — the first commit — makes the gates reachable. Deploying that commit alone to our dev cluster produced ~1,280 reconciles/sec, CPU pegged at the 250m limit, 173,963 log lines in 60 seconds, and zero assignment attempts.

Two things made this hard to see, and both are worth flagging to anyone else testing this code:

Naively flipping the IP gate to a plain After(now) is also wrong, and that is what the earlier revision tried. reconcileIPStatus reuses status.nextRetry for the routine healthyRetrySchedule (5m) refresh and sets it on every healthy IP immediately before reconcileAssignment runs. An unqualified check therefore defers every IP and nothing is ever assigned — which is exactly the TestFloatingIPPoolUpdateK8s failure across 6 subtests that the earlier revision saw and misread as "the guard is not a defect". The fix gates on IPStateError as well, which is what the comment always claimed the check meant. The node gate needs no qualifier: providerIDToRetry only holds nodes whose assignment failed, and the entry is deleted on success.

RetrySchedule.Next() builds its deadlines from time.Now(), not from the injectable i.now(). Several existing tests pin i.now to a 2021 constant, so every retry deadline lands years in the future, no retry gate is ever reached, and the tests pass without exercising the code under test. A first attempt at a spin regression test went green against the wedged build for exactly this reason. Those clocks are now seeded from time.Now().

TestIPControllerRunDoesNotSpinOnPersistentFailure drives the real run() loop against the real clock — the only level at which this bug is visible, since the spin is a disagreement between the deadlines reconcile() schedules and the timer run() derives from them. It counts reconcile passes via the clock rather than via the provider, because a wedged controller skips the provider calls on every pass and provider call counts stay flat:

clock reads in 1.5s
buggy gate 966,295
fixed a handful

TestIPControllerElapsedNodeRetryDoesNotSpin / TestIPControllerElapsedIPRetryDoesNotSpin cover each gate in isolation; TestIPControllerPendingIPRetryIsDeferred / TestIPControllerHealthyIPIsAssignable pin the converse so the fix cannot regress into "never defer" or "always defer".

Test plan

  • Red/green proven both directions with the project's own runner (make test, Go 1.23, dockerised)
  • Applied to pristine 7db46fe, the new tests fail with exactly the defect signature: assignableNodes.Len() == 0 ("node should have been requeued"), providerIDToIP retaining the providerID, and RetrySlow{1m,5m,10m} where RetryFast is required
  • With the fix, go test ./... is green across all packages; gofmt and go vet clean
  • TestFloatingIPPoolUpdateK8s and TestNodeDNSRecordSetController fail under -race at pristine upstream 7db46fe as well — pre-existing, not introduced here
  • Deployed to do-dev-sgp-1 and validated against a real unassigned Reserved IP

One pre-existing expectation changed: the "assignment error" case in TestIPControllerReconcileAssignment asserted that providerIDToIP retains the mapping after a failed assignment — it encoded this defect as intended behaviour. It now asserts the mapping is unwound and both sides requeued.

Reproduction on dev, against the deployed image, with no API failure at all

05:45:46  doctl compute reserved-ip-action unassign 144.126.243.20
05:50:38  "ip address is available for assignment"   (both pool IPs)
05:50:38  "node assignment mismatch ... expected_ip=144.126.241.39 provider_id="   <- the junk "" key
05:50–05:56 "no IPs assigned; skipping DNS update"  every minute, indefinitely
          ZERO "assigning IP to node" attempts. No error. No retry.
05:56:36  kubectl -n infra rollout restart deploy/flipop
05:58:02  IP rebound, state active   (~85s)

That is the same end state as the production incident, reached without any API failure at all.

Generated with Devin

craig-johnston and others added 5 commits August 5, 2026 14:59
…lure

reconcileAssignment optimistically records an assignment before calling
provider.AssignIP:

    status.nodeProviderID = providerID
    i.providerIDToIP[providerID] = ip

On failure neither write is unwound, and because orderedSet.Front() is a pop
and the deferred requeue only replays retryIPs/retryProviders - which the
error branch never appends to - both the IP and the node are dropped from
their queues.

The node is then leaked permanently:

  * EnableNodes sees the stale providerIDToIP entry, logs "enabling node;
    already assigned to ip", deletes the IP from assignableIPs and returns
    early, so it never adds the node to assignableNodes.
  * reconcileIPStatus partially recovers - it observes the IP is unowned,
    clears status.nodeProviderID and re-adds the IP to assignableIPs - but it
    cannot requeue the node, because the assignableNodes.Add call is guarded
    by providerIDToNodeName[providerID] and providerID is "" by that point.
  * EnableNodes can never help again, since the node is already present in
    providerIDToNodeName.

With assignableNodes permanently empty, the reconcileAssignment loop guard
(assignableIPs.Len() != 0 && assignableNodes.Len() != 0) is never satisfied,
so no further attempt is ever made at any backoff. Only a process restart
rebuilds the queues.

Observed in production: a single transient HTTP 422 from the DigitalOcean API
on a freshly-created droplet left a Reserved IP bound to nothing for 2h31m,
with the pool reporting every IP as "unassigned". Restarting the controller
bound the IPs within 45 seconds.

Unwind both writes and requeue the IP and the node so the pair is retried on
the existing schedule. status.state and status.assignmentErrors are
deliberately left set: the failure did happen and must stay visible in the
CRD status and in the ip_assignment_errors metric.

The "assignment error" case in TestIPControllerReconcileAssignment asserted
that providerIDToIP retained the mapping after a failed assignment, i.e. it
encoded this defect as expected behaviour; it now asserts the mapping is
unwound and both sides requeued.
On HTTP 422 AssignIP probes the IP's current owner to distinguish "already
assigned to us" (success) from "the target node already holds another IP"
(ErrNodeInUse). If neither matches it falls through to a bare `return err`,
which ErrorToRetrySchedule maps to RetrySlow - 1m, 5m, 10m, then 10m forever.

A freshly-created droplet is therefore indistinguishable from a permanent
failure. DigitalOcean returns

    422 Droplet already has a pending event

for a droplet that is still settling, which was observed roughly 35 seconds
after droplet creation during a node rotation. That condition clears within
seconds, so it belongs on RetryFast (1s, 1s, 5s, 5s, 10s ...) rather than a
schedule measured in minutes.

When the lookup succeeds and reports the IP is owned by nobody, the 422 cannot
be an ownership conflict, so return a fast-retryable error. The iErr == nil
guard matters: without it a failed IPToProviderID call that happens to yield
an empty owner would be misclassified as transient.

A 422 naming a different owner is deliberately unchanged and still reaches
RetrySlow - that is a genuine conflict needing external resolution, and
retrying it quickly would only add API load.
reconcileIPStatus guards the reassignment requeue on providerID - the IP's *new*
owner - but the thing it requeues is expectedProviderID, the node that lost the
IP. When an IP is taken away entirely, providerID is "" and the lookup fails, so
the evicted node is never returned to assignableNodes. reconcileAssignment's loop
guard needs both queues non-empty, so no assignment is ever attempted again and
the IP is stranded until the process restarts.

Reproduced on rts-sgp-1-dev-cluster against 7db46fe by unassigning one Reserved
IP through the DigitalOcean API. flipop noticed within its 5m status refresh and
logged "ip address is available for assignment" for both pool IPs, then
"no IPs assigned; skipping DNS update" once a minute indefinitely, with zero
"assigning IP to node" attempts and no error. A rollout restart rebound the IP
in ~85s.

This is a second, independent path to the same end state as the 422 defect: no
AssignIP call fails here, because none is ever made. Guard on expectedProviderID
instead, which also covers the original case of the IP being claimed by another
node, since the evicted node needs a replacement either way.

Also stop writing i.providerIDToIP[""] = ip for an unowned IP. That empty key is
read back as expectedIP on the next pass and produced a bogus "node assignment
mismatch" that reset an unrelated pool IP to error - observed in the same dev
run against 144.126.241.39.
run() sleeps until i.nextRetry, and retryTimerDuration() turns any timestamp at
or before now into 0, so scheduling a past wake-up busy-loops the controller.
Nothing asserted that invariant, because the existing tests drive reconcile()
directly and never observe the timer.

This does NOT reproduce the hot loop seen on dev (CPU pegged at its 250m limit,
~1,280 reconciles/sec, ~77k log lines a minute); that needs a DigitalOcean action
to be in flight so IPToProviderID returns ErrInProgress, which the mock provider
does not model. It does pin the two invariants that matter: the wake-up is always
in the future, and a failed assignment is retried rather than skipped forever.
…apsed

Both retry gates in reconcileAssignment were inverted. They deferred when the
retry deadline HAD elapsed and then handed that already-past timestamp to
i.retry():

    if !status.nextRetry.IsZero() && !status.nextRetry.After(now) {
        retryIPs = append(retryIPs, ip)
        i.retry(status.nextRetry)
        continue
    }

run() sleeps until i.nextRetry, so it re-enters reconcile() at or just after
the deadline it was given - an elapsed deadline is the normal state on wake-up.
retryTimerDuration() maps any past timestamp to 0, so run() reconciles again
immediately, the gate skips again, and the controller busy-loops without ever
retrying the bind.

Upstream never reached this because the error branch dropped the IP and node
from their queues entirely (fixed in the preceding commit); requeueing them
makes the gates reachable. Observed on dev after that fix: ~1,280 reconciles/s,
CPU pegged at the 250m limit, 173,963 log lines in 60s, zero assignment
attempts.

Naively flipping the IP gate to a plain After(now) is also wrong.
reconcileIPStatus reuses status.nextRetry for the routine
healthyRetrySchedule (5m) refresh and sets it on every healthy IP immediately
before reconcileAssignment runs, so an unqualified check defers every IP and
nothing is ever assigned. Gate on IPStateError as well, which is what the
comment always claimed the check meant. The node gate needs no such qualifier:
providerIDToRetry only ever holds nodes whose assignment failed, and the entry
is deleted on success.

Tests:

  * TestIPControllerRunDoesNotSpinOnPersistentFailure drives the real run()
    loop against the real clock - the only level at which this bug is visible,
    since the spin is a disagreement between the deadlines reconcile()
    schedules and the timer run() derives from them. It counts reconcile passes
    via the clock rather than via the provider, because a wedged controller
    skips the provider calls on every pass and provider call counts stay flat.
    966,295 clock reads in 1.5s before, a handful after.
  * TestIPControllerElapsedNodeRetryDoesNotSpin and
    TestIPControllerElapsedIPRetryDoesNotSpin cover each gate in isolation.
  * TestIPControllerPendingIPRetryIsDeferred and
    TestIPControllerHealthyIPIsAssignable pin the converse, so the fix cannot
    regress into "never defer" or "always defer".

Also seed the fake clocks in these tests, and in
TestIPControllerAssignmentRetriesAfterTransientError, from time.Now().
RetrySchedule.Next() builds its deadlines from the real clock rather than
i.now(), so a fakeNow (2021) base leaves every deadline years in the future,
no retry gate is ever reached, and such tests pass vacuously. That is why the
first attempt at a spin regression test went green against the wedged build.

Generated with [Devin](https://devin.ai)

Co-Authored-By: Devin <158243242+devin-ai-integration[bot]@users.noreply.github.com>
@craig-johnston
craig-johnston force-pushed the devin/OPTI-3818-flipop-422-retry branch from db41fbc to afff39c Compare August 6, 2026 04:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant