diff --git a/spinifex/network/reconcile/apply.go b/spinifex/network/reconcile/apply.go index 6c5d9c484..5db4c4fe3 100644 --- a/spinifex/network/reconcile/apply.go +++ b/spinifex/network/reconcile/apply.go @@ -43,6 +43,63 @@ var ( // reset re-syncs that view. Package var so tests can shrink it. var sbResetEscalateAfter = 3 +// Backoff applied to a guest port that burned its convergence deadline. Doubles +// per consecutive failure from the base and holds at the cap. Package vars so +// tests shorten them. +var ( + guestPortBackoffBase = time.Minute + guestPortBackoffMax = 30 * time.Minute +) + +// portBackoffUntil reports whether lspName is inside its convergence backoff, +// and when that expires. +func (r *reconciler) portBackoffUntil(lspName string) (time.Time, bool) { + r.portBackoffMu.Lock() + defer r.portBackoffMu.Unlock() + state, ok := r.portBackoff[lspName] + if !ok || !time.Now().Before(state.until) { + return time.Time{}, false + } + return state.until, true +} + +// recordPortFailure counts another failed convergence for lspName and returns +// the new consecutive-failure count and the backoff now in force. +func (r *reconciler) recordPortFailure(lspName string) (int, time.Duration) { + r.portBackoffMu.Lock() + defer r.portBackoffMu.Unlock() + if r.portBackoff == nil { + r.portBackoff = map[string]portBackoffState{} + } + state := r.portBackoff[lspName] + state.failures++ + backoff := guestPortBackoffBase << min(state.failures-1, 16) + if backoff > guestPortBackoffMax || backoff <= 0 { + backoff = guestPortBackoffMax + } + state.until = time.Now().Add(backoff) + r.portBackoff[lspName] = state + return state.failures, backoff +} + +// clearPortBackoff drops any backoff for lspName, reporting whether one was held +// so the caller can log the recovery rather than a routine convergence. +func (r *reconciler) clearPortBackoff(lspName string) bool { + r.portBackoffMu.Lock() + defer r.portBackoffMu.Unlock() + if _, ok := r.portBackoff[lspName]; !ok { + return false + } + delete(r.portBackoff, lspName) + return true +} + +// eniIDFromPort recovers the ENI a guest port belongs to. Telemetry carried only +// the LSP name, which no operator can map back to a guest. +func eniIDFromPort(lspName string) string { + return strings.TrimPrefix(lspName, "port-") +} + // applyVPCs ensures every intent VPC has a LogicalRouter. Stray OVN-only // routers are left alone. func (r *reconciler) applyVPCs(ctx context.Context, intent IntentState, actual ActualState) { @@ -498,7 +555,7 @@ func (r *reconciler) applyEIPs(ctx context.Context, intent IntentState, _ Actual if err := r.nat.AddEIP(ctx, spec); err != nil { slog.Error("reconcile/apply: AddEIP failed", "external_ip", spec.ExternalIP, "logical_ip", spec.LogicalIP, "err", err) } - r.ensureGuestPortDatapath(ctx, spec.VPCID, spec.PortName) + r.ensureGuestPortDatapath(ctx, spec) } } @@ -643,10 +700,19 @@ func subnetIDForIP(subnets map[string]topology.SubnetSpec, ip string) string { // not once: post-reboot the guest tap is replumbed seconds after this runs, so a // single early nudge fires before the port exists and never binds it. No-op when no // verifier is wired or the EIP carries no guest port. -func (r *reconciler) ensureGuestPortDatapath(ctx context.Context, vpcID, lspName string) { +func (r *reconciler) ensureGuestPortDatapath(ctx context.Context, spec policy.EIPSpec) { + vpcID, lspName := spec.VPCID, spec.PortName if r.gwClaim == nil || lspName == "" { return } + // A port with no tap behind it never binds, so without this every cycle pays + // the full nudge sequence and files another ERROR for a guest that is gone. + if until, held := r.portBackoffUntil(lspName); held { + slog.Debug("reconcile/apply: guest port still in convergence backoff; not re-probing", + "vpc_id", vpcID, "lsp", lspName, "eni_id", eniIDFromPort(lspName), + "retry_in_ms", otelsetup.Millis(time.Until(until))) + return + } deadline := time.Now().Add(guestPortDatapathTimeout) nudged := false misses := 0 @@ -658,7 +724,11 @@ func (r *reconciler) ensureGuestPortDatapath(ctx context.Context, vpcID, lspName return } if up { - if nudged { + if r.clearPortBackoff(lspName) { + slog.Info("reconcile/apply: guest port datapath recovered after repeated failures", + "vpc_id", vpcID, "lsp", lspName, "eni_id", eniIDFromPort(lspName), + "external_ip", spec.ExternalIP, "logical_ip", spec.LogicalIP) + } else if nudged { slog.Info("reconcile/apply: guest port datapath converged after recompute", "vpc_id", vpcID, "lsp", lspName) } return @@ -674,8 +744,13 @@ func (r *reconciler) ensureGuestPortDatapath(ctx context.Context, vpcID, lspName resetEscalated = r.escalateSBReset(ctx, "vpc_id", vpcID, "lsp", lspName) } if time.Now().After(deadline) { + failures, backoff := r.recordPortFailure(lspName) slog.Error("reconcile/apply: guest port datapath did not converge; EIP ingress may be unreachable", - "vpc_id", vpcID, "lsp", lspName, "timeout_ms", otelsetup.Millis(guestPortDatapathTimeout)) + "vpc_id", vpcID, "lsp", lspName, "eni_id", eniIDFromPort(lspName), + "external_ip", spec.ExternalIP, "logical_ip", spec.LogicalIP, + "consecutive_failures", failures, + "timeout_ms", otelsetup.Millis(guestPortDatapathTimeout), + "retry_in_ms", otelsetup.Millis(backoff)) return } select { diff --git a/spinifex/network/reconcile/apply_gateway_claim_test.go b/spinifex/network/reconcile/apply_gateway_claim_test.go index 6b5e0e6d0..515e0fd46 100644 --- a/spinifex/network/reconcile/apply_gateway_claim_test.go +++ b/spinifex/network/reconcile/apply_gateway_claim_test.go @@ -7,6 +7,7 @@ import ( "time" "github.com/mulgadc/spinifex/spinifex/network/ovn/nbdb" + "github.com/mulgadc/spinifex/spinifex/network/policy" ) // fakeClaimVerifier scripts a sequence of GatewayPortClaimed results and counts @@ -386,7 +387,7 @@ func TestEnsureGatewayDatapath_EIPUnreachableRepairs(t *testing.T) { func TestEnsureGuestPortDatapath_NoVerifierIsNoop(t *testing.T) { r := &reconciler{} // gwClaim nil - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) // Reaching here without panic is the assertion. } @@ -394,7 +395,7 @@ func TestEnsureGuestPortDatapath_EmptyLSPIsNoop(t *testing.T) { f := &fakeClaimVerifier{} r := &reconciler{gwClaim: f} - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a"}) if f.guestChecks != 0 { t.Errorf("guestChecks = %d, want 0 (empty lsp must skip the probe)", f.guestChecks) @@ -406,7 +407,7 @@ func TestEnsureGuestPortDatapath_UpNoNudge(t *testing.T) { f := &fakeClaimVerifier{guestUpAfter: 0} r := &reconciler{gwClaim: f} - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) if f.nudges != 0 { t.Errorf("up guest port nudged %d times, want 0", f.nudges) @@ -425,7 +426,7 @@ func TestEnsureGuestPortDatapath_NudgeThenConverge(t *testing.T) { f := &fakeClaimVerifier{guestUpAfter: 1} r := &reconciler{gwClaim: f} - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) if f.nudges != 1 { t.Errorf("nudges = %d, want exactly 1 (nudge once, then converge)", f.nudges) @@ -439,7 +440,7 @@ func TestEnsureGuestPortDatapath_NeverConvergesRecomputesEachMiss(t *testing.T) done := make(chan struct{}) go func() { - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) close(done) }() select { @@ -463,7 +464,7 @@ func TestEnsureGuestPortDatapath_ProbeErrorBailsOut(t *testing.T) { f := &fakeClaimVerifier{guestErr: errors.New("ovn-sbctl down")} r := &reconciler{gwClaim: f} - r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) if f.nudges != 0 { t.Errorf("nudges = %d, want 0 (bail out on probe error, do not nudge blindly)", f.nudges) @@ -482,7 +483,7 @@ func TestEnsureGuestPortDatapath_ContextCancelStops(t *testing.T) { done := make(chan struct{}) go func() { - r.ensureGuestPortDatapath(ctx, "vpc-a", "port-eni-1") + r.ensureGuestPortDatapath(ctx, policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) close(done) }() time.Sleep(20 * time.Millisecond) @@ -551,7 +552,9 @@ func TestEnsureGuestPortDatapath_WedgedSBEscalatesResetOnce(t *testing.T) { f := &fakeClaimVerifier{guestUpAfter: -1, sbNotConnected: true} r := &reconciler{gwClaim: f} - runToDeadline(t, func() { r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") }) + runToDeadline(t, func() { + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) + }) if f.sbResets != 1 { t.Errorf("sbResets = %d, want exactly 1 (escalate once on a wedged SB)", f.sbResets) @@ -564,7 +567,9 @@ func TestEnsureGuestPortDatapath_ConnectedSBNeverResets(t *testing.T) { f := &fakeClaimVerifier{guestUpAfter: -1, sbNotConnected: false} r := &reconciler{gwClaim: f} - runToDeadline(t, func() { r.ensureGuestPortDatapath(context.Background(), "vpc-a", "port-eni-1") }) + runToDeadline(t, func() { + r.ensureGuestPortDatapath(context.Background(), policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"}) + }) if f.sbResets != 0 { t.Errorf("sbResets = %d, want 0 (connected SB must never be reset)", f.sbResets) diff --git a/spinifex/network/reconcile/apply_guest_port_backoff_test.go b/spinifex/network/reconcile/apply_guest_port_backoff_test.go new file mode 100644 index 000000000..1f97b8893 --- /dev/null +++ b/spinifex/network/reconcile/apply_guest_port_backoff_test.go @@ -0,0 +1,98 @@ +package reconcile + +import ( + "context" + "testing" + "time" + + "github.com/mulgadc/spinifex/spinifex/network/policy" +) + +// withFastGuestPortBackoff shrinks the post-failure backoff so a test can cross +// it without sleeping for a minute. +func withFastGuestPortBackoff(t *testing.T, base, ceiling time.Duration) { + t.Helper() + b, m := guestPortBackoffBase, guestPortBackoffMax + guestPortBackoffBase, guestPortBackoffMax = base, ceiling + t.Cleanup(func() { guestPortBackoffBase, guestPortBackoffMax = b, m }) +} + +// TestEnsureGuestPortDatapath_BacksOffAfterFailure covers the zombie port: one +// whose guest is gone can never bind, so the second pass must cost nothing +// rather than paying the whole nudge sequence again. +func TestEnsureGuestPortDatapath_BacksOffAfterFailure(t *testing.T) { + withFastGuestPortBounds(t) + withFastGuestPortBackoff(t, time.Minute, time.Hour) + + f := &fakeClaimVerifier{guestUpAfter: -1} // never up + r := &reconciler{gwClaim: f} + spec := policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"} + + r.ensureGuestPortDatapath(context.Background(), spec) + afterFirst := f.nudges + if afterFirst == 0 { + t.Fatal("first pass nudged 0 times, want the full sequence") + } + + r.ensureGuestPortDatapath(context.Background(), spec) + if f.nudges != afterFirst { + t.Errorf("nudges = %d after the second pass, want %d: a port inside its backoff must not be re-probed", + f.nudges, afterFirst) + } +} + +// TestEnsureGuestPortDatapath_BackoffGrowsAndCaps checks the interval doubles +// per consecutive failure and then holds, so a permanently dead port settles at +// a fixed low rate instead of one report per reconcile cycle. +func TestEnsureGuestPortDatapath_BackoffGrowsAndCaps(t *testing.T) { + r := &reconciler{} + withFastGuestPortBackoff(t, time.Minute, 8*time.Minute) + + want := []time.Duration{time.Minute, 2 * time.Minute, 4 * time.Minute, 8 * time.Minute, 8 * time.Minute} + for i, w := range want { + failures, backoff := r.recordPortFailure("port-eni-1") + if failures != i+1 { + t.Errorf("failure %d: count = %d, want %d", i+1, failures, i+1) + } + if backoff != w { + t.Errorf("failure %d: backoff = %s, want %s", i+1, backoff, w) + } + } +} + +// TestEnsureGuestPortDatapath_BackoffClearsOnConverge covers the guest coming +// back: the port must be probed again immediately once it binds, and the held +// backoff must not survive to delay the next real failure. +func TestEnsureGuestPortDatapath_BackoffClearsOnConverge(t *testing.T) { + withFastGuestPortBounds(t) + withFastGuestPortBackoff(t, time.Millisecond, time.Millisecond) + + f := &fakeClaimVerifier{guestUpAfter: -1} + r := &reconciler{gwClaim: f} + spec := policy.EIPSpec{VPCID: "vpc-a", PortName: "port-eni-1"} + + r.ensureGuestPortDatapath(context.Background(), spec) + if _, held := r.portBackoffUntil(spec.PortName); held { + time.Sleep(2 * time.Millisecond) + } + + // The guest comes back. + f.guestUpAfter = 0 + f.nudges = 0 + r.ensureGuestPortDatapath(context.Background(), spec) + + if _, held := r.portBackoffUntil(spec.PortName); held { + t.Error("backoff still held after the port converged") + } + if _, ok := r.portBackoff[spec.PortName]; ok { + t.Error("backoff entry not cleared after the port converged") + } +} + +// TestEniIDFromPort pins the attribution added to the failure log: the LSP name +// alone cannot be mapped back to a guest. +func TestEniIDFromPort(t *testing.T) { + if got := eniIDFromPort("port-eni-6b9b6e142f20ed708"); got != "eni-6b9b6e142f20ed708" { + t.Errorf("eniIDFromPort = %q, want %q", got, "eni-6b9b6e142f20ed708") + } +} diff --git a/spinifex/network/reconcile/reconcile.go b/spinifex/network/reconcile/reconcile.go index eebe9c720..805e8f84b 100644 --- a/spinifex/network/reconcile/reconcile.go +++ b/spinifex/network/reconcile/reconcile.go @@ -8,6 +8,8 @@ import ( "errors" "fmt" "log/slog" + "sync" + "time" "github.com/mulgadc/spinifex/spinifex/network/external" "github.com/mulgadc/spinifex/spinifex/network/ovn" @@ -127,6 +129,18 @@ type reconciler struct { ipsecEnabled bool underlayMTU int reloadIntent func(ctx context.Context) (IntentState, error) + + // Guest ports that burned their convergence deadline, so a port whose guest + // is gone stops paying the full nudge sequence every cycle. + portBackoffMu sync.Mutex + portBackoff map[string]portBackoffState +} + +// portBackoffState is one guest port's consecutive failure count and the instant +// its backoff expires. +type portBackoffState struct { + failures int + until time.Time } var _ Reconciler = (*reconciler)(nil)