diff --git a/client/internal/engine.go b/client/internal/engine.go index f8b65f7d8..d517d1d68 100644 --- a/client/internal/engine.go +++ b/client/internal/engine.go @@ -14,12 +14,14 @@ import ( "sort" "strings" "sync" + "sync/atomic" "time" "github.com/hashicorp/go-multierror" "github.com/pion/ice/v4" "github.com/pion/stun/v3" log "github.com/sirupsen/logrus" + wgdevice "golang.zx2c4.com/wireguard/device" "golang.zx2c4.com/wireguard/tun/netstack" "golang.zx2c4.com/wireguard/wgctrl/wgtypes" @@ -236,6 +238,12 @@ type Engine struct { wgInterface WGIface + // wgDevice is a lock-free handle on the WireGuard device behind + // wgInterface. Reaching the device through wgInterface requires + // syncMsgMux, which handleSync holds while it adds and removes peers; + // SetPerformance must stay reachable exactly when that work is stuck. + wgDevice atomic.Pointer[wgdevice.Device] + udpMux *udpmux.UniversalUDPMuxDefault // networkSerial is the latest CurrentSerial (state ID) of the network sent by the Management service @@ -651,6 +659,7 @@ func (e *Engine) Start(netbirdConfig *mgmProto.NetbirdConfig, mgmtURL *url.URL) log.Errorf("failed to pull up wgInterface [%s]: %s", e.wgInterface.Name(), err.Error()) return fmt.Errorf("up wg interface: %w", err) } + e.wgDevice.Store(e.wgInterface.GetWGDevice()) // Set up notrack rules immediately after proxy is listening to prevent // conntrack entries from being created before the rules are in place @@ -2144,6 +2153,10 @@ func (e *Engine) close() { log.Debugf("removing Netbird interface %s", e.config.WgIfaceName) if e.wgInterface != nil { + // Drop the handle before the close starts: a retune that loads it + // afterwards would touch a device on its way out and report success + // for an engine that is already gone. + e.wgDevice.Store(nil) if err := e.wgInterface.Close(); err != nil { log.Errorf("failed closing Netbird interface %s %v", e.config.WgIfaceName, err) } @@ -2303,15 +2316,16 @@ type Performance struct { } // SetPerformance applies the given tuning to this engine's live Device. +// +// It deliberately does not take syncMsgMux. Raising the buffer pool cap is the +// recovery path for a device whose pool is exhausted, and an exhausted pool +// blocks peer removal inside handleSync, which holds syncMsgMux for as long as +// it stays blocked. Taking the lock here would make the retune unreachable in +// the one situation that needs it. func (e *Engine) SetPerformance(t Performance) error { - e.syncMsgMux.Lock() - defer e.syncMsgMux.Unlock() - if e.wgInterface == nil { - return fmt.Errorf("wg interface not initialized") - } - dev := e.wgInterface.GetWGDevice() + dev := e.wgDevice.Load() if dev == nil { - return fmt.Errorf("wg device not initialized") + return errors.New("wg device not initialized") } if t.PreallocatedBuffersPerPool != nil { dev.SetPreallocatedBuffersPerPool(*t.PreallocatedBuffersPerPool) diff --git a/proxy/internal/debug/handler.go b/proxy/internal/debug/handler.go index 6300228d7..960c3e089 100644 --- a/proxy/internal/debug/handler.go +++ b/proxy/internal/debug/handler.go @@ -105,6 +105,20 @@ type Handler struct { startTime time.Time templates *template.Template templateMu sync.RWMutex + + // setPerformance applies a buffer cap to one client. Held as a field so + // tests can drive applyBufferCap without a live embedded client. + setPerformance func(*nbembed.Client, uint32) error + + perfMu sync.Mutex + perfInflight map[types.AccountID]*perfWorker +} + +// perfWorker is the single in-flight retune for one account. err is valid once +// done is closed. +type perfWorker struct { + done chan struct{} + err error } // NewHandler creates a new debug handler. @@ -113,10 +127,11 @@ func NewHandler(provider clientProvider, healthChecker healthChecker, logger *lo logger = log.StandardLogger() } h := &Handler{ - provider: provider, - health: healthChecker, - logger: logger, - startTime: time.Now(), + provider: provider, + health: healthChecker, + logger: logger, + startTime: time.Now(), + setPerformance: setClientPerformance, } if err := h.loadTemplates(); err != nil { logger.Errorf("failed to load embedded templates: %v", err) @@ -716,15 +731,7 @@ func (h *Handler) handlePerf(w http.ResponseWriter, r *http.Request) { } capN := uint32(n) - applied := 0 - failed := map[string]string{} - for accountID, client := range h.provider.ListClientsForStartup() { - if err := client.SetPerformance(nbembed.Performance{PreallocatedBuffersPerPool: &capN}); err != nil { - failed[string(accountID)] = err.Error() - continue - } - applied++ - } + applied, failed, inFlight := h.applyBufferCap(capN) resp := map[string]any{ "success": true, @@ -734,9 +741,165 @@ func (h *Handler) handlePerf(w http.ResponseWriter, r *http.Request) { if len(failed) > 0 { resp["failed"] = failed } + if len(inFlight) > 0 { + resp["in_flight"] = inFlight + } h.writeJSON(w, resp) } +// perfApplyTimeout bounds the whole apply, however many clients are registered. +// A var, not a const, so tests can shorten the wait. +var perfApplyTimeout = 5 * time.Second + +type perfResult struct { + accountID types.AccountID + err error +} + +// setClientPerformance is the production implementation behind Handler.setPerformance. +func setClientPerformance(client *nbembed.Client, capN uint32) error { + return client.SetPerformance(nbembed.Performance{PreallocatedBuffersPerPool: &capN}) +} + +// collectBuffered takes every result already sitting in the channel, removing +// those accounts from pending, and returns how many of them succeeded. It is +// called when the deadline fires: select picks at random among ready cases, so +// a result that landed in time would otherwise be reported as a timeout. +func collectBuffered(results <-chan perfResult, pending map[types.AccountID]*perfWorker, failed map[string]string) int { + applied := 0 + for { + select { + case res := <-results: + delete(pending, res.accountID) + if res.err != nil { + failed[string(res.accountID)] = res.err.Error() + continue + } + applied++ + default: + return applied + } + } +} + +// resolvePending closes out the accounts still pending when the deadline fires. +// A worker whose done channel is closed has finished, whatever the results +// channel has managed to deliver, so its own error is the truth; the rest are +// genuinely still running and are reported as timed out. Returns how many of +// them had in fact succeeded. +func resolvePending(pending map[types.AccountID]*perfWorker, failed map[string]string) int { + applied := 0 + for accountID, w := range pending { + select { + case <-w.done: + if w.err != nil { + failed[string(accountID)] = w.err.Error() + continue + } + applied++ + default: + failed[string(accountID)] = fmt.Sprintf("timed out after %s waiting for the client", perfApplyTimeout) + } + } + return applied +} + +// startPerfWorker returns the in-flight retune for the account, starting one if +// there is none. The bool reports whether this call started it. +// +// At most one retune runs per account at a time. A client wedged inside its own +// lock never returns, so without this a caller could add one permanently blocked +// goroutine per request just by retrying the endpoint. +func (h *Handler) startPerfWorker(accountID types.AccountID, client *nbembed.Client, capN uint32, results chan<- perfResult) (*perfWorker, bool) { + h.perfMu.Lock() + defer h.perfMu.Unlock() + + if w, ok := h.perfInflight[accountID]; ok { + return w, false + } + + w := &perfWorker{done: make(chan struct{})} + if h.perfInflight == nil { + h.perfInflight = make(map[types.AccountID]*perfWorker) + } + h.perfInflight[accountID] = w + + go func() { + err := h.setPerformance(client, capN) + w.err = err + close(w.done) + + // Publish before touching the registry: perfMu is taken once per + // account by every caller walking the fleet, so a finishing worker + // can queue behind a long apply and miss its own deadline. + results <- perfResult{accountID: accountID, err: err} + + h.perfMu.Lock() + delete(h.perfInflight, accountID) + h.perfMu.Unlock() + }() + + return w, true +} + +// applyBufferCap sets the WireGuard buffer pool cap on every registered client +// and reports how many took it, a per-account error for those that did not, and +// the accounts whose earlier retune has not come back yet. +// +// Clients are handled concurrently and the wait is bounded: SetPerformance goes +// through the embedded client's lock, which Start and Stop hold for as long as +// they take - and on a wedged client Stop never returns. This endpoint is the +// recovery path for exactly that fleet, so one stuck account must neither delay +// the others nor accumulate goroutines across retries. +func (h *Handler) applyBufferCap(capN uint32) (int, map[string]string, []string) { + clients := h.provider.ListClientsForStartup() + results := make(chan perfResult, len(clients)) + + applied := 0 + failed := map[string]string{} + var inFlight []string + pending := make(map[types.AccountID]*perfWorker, len(clients)) + + for accountID, client := range clients { + w, started := h.startPerfWorker(accountID, client, capN, results) + if started { + pending[accountID] = w + continue + } + // Another request owns this account's retune. Take its result if it + // has already landed, otherwise report it as still running instead of + // waiting on it again. + select { + case <-w.done: + if w.err != nil { + failed[string(accountID)] = w.err.Error() + continue + } + applied++ + default: + inFlight = append(inFlight, string(accountID)) + } + } + + deadline := time.After(perfApplyTimeout) + for range len(pending) { + select { + case res := <-results: + delete(pending, res.accountID) + if res.err != nil { + failed[string(res.accountID)] = res.err.Error() + continue + } + applied++ + case <-deadline: + applied += collectBuffered(results, pending, failed) + applied += resolvePending(pending, failed) + return applied, failed, inFlight + } + } + return applied, failed, inFlight +} + // handleRuntime returns cheap runtime and process stats. Safe to hit on a // running proxy; does not read pprof profiles. func (h *Handler) handleRuntime(w http.ResponseWriter, _ *http.Request) { diff --git a/proxy/internal/debug/perf_test.go b/proxy/internal/debug/perf_test.go new file mode 100644 index 000000000..abcfccb50 --- /dev/null +++ b/proxy/internal/debug/perf_test.go @@ -0,0 +1,158 @@ +package debug + +import ( + "context" + "errors" + "sync/atomic" + "testing" + "time" + + nbembed "github.com/netbirdio/netbird/client/embed" + "github.com/netbirdio/netbird/proxy/internal/health" + "github.com/netbirdio/netbird/proxy/internal/roundtrip" + "github.com/netbirdio/netbird/proxy/internal/types" +) + +// perfProvider serves a fixed set of accounts. The clients are nil: the tests +// drive Handler.setPerformance, which never dereferences them. +type perfProvider struct { + accounts []types.AccountID +} + +func (p *perfProvider) GetClient(types.AccountID) (*nbembed.Client, bool) { return nil, false } + +func (p *perfProvider) ListClientsForDebug() map[types.AccountID]roundtrip.ClientDebugInfo { + return nil +} + +func (p *perfProvider) ListClientsForStartup() map[types.AccountID]*nbembed.Client { + out := make(map[types.AccountID]*nbembed.Client, len(p.accounts)) + for _, id := range p.accounts { + out[id] = nil + } + return out +} + +type stubHealth struct{} + +func (stubHealth) ReadinessProbe() bool { return true } +func (stubHealth) StartupProbe(context.Context) bool { return true } +func (stubHealth) CheckClientsConnected(context.Context) (bool, map[types.AccountID]health.ClientHealth) { + return true, nil +} + +func shortenPerfTimeout(t *testing.T, d time.Duration) { + t.Helper() + prev := perfApplyTimeout + perfApplyTimeout = d + t.Cleanup(func() { perfApplyTimeout = prev }) +} + +// TestCollectBufferedCountsResultsReadyAtTheDeadline covers the select-ordering +// trap: when the deadline fires, results already buffered must be counted, not +// reported as timeouts. Driving collectBuffered directly keeps it deterministic +// - through applyBufferCap the two select cases race by construction. +func TestCollectBufferedCountsResultsReadyAtTheDeadline(t *testing.T) { + results := make(chan perfResult, 3) + results <- perfResult{accountID: "ok"} + results <- perfResult{accountID: "broken", err: errors.New("boom")} + + pending := map[types.AccountID]*perfWorker{ + "ok": {done: make(chan struct{})}, + "broken": {done: make(chan struct{})}, + "wedged": {done: make(chan struct{})}, + } + failed := map[string]string{} + + applied := collectBuffered(results, pending, failed) + + if applied != 1 { + t.Fatalf("applied = %d, want 1", applied) + } + if failed["broken"] != "boom" { + t.Fatalf("failed = %v, want the error recorded for \"broken\"", failed) + } + if _, ok := pending["wedged"]; !ok || len(pending) != 1 { + t.Fatalf("pending = %v, want only the account that never answered", pending) + } +} + +// TestApplyBufferCapSingleFlightPerAccount covers the goroutine accumulation +// reported on PR #7452: repeated calls against a client stuck in its own lock +// must not start a second attempt for the same account. +func TestApplyBufferCapSingleFlightPerAccount(t *testing.T) { + shortenPerfTimeout(t, 50*time.Millisecond) + + release := make(chan struct{}) + t.Cleanup(func() { close(release) }) + + var calls atomic.Int32 + h := &Handler{ + provider: &perfProvider{accounts: []types.AccountID{"wedged"}}, + health: stubHealth{}, + setPerformance: func(_ *nbembed.Client, _ uint32) error { + calls.Add(1) + <-release + return nil + }, + } + + for i := range 5 { + applied, failed, inFlight := h.applyBufferCap(4096) + if applied != 0 { + t.Fatalf("call %d: applied = %d, want 0", i, applied) + } + if i == 0 { + if len(failed) != 1 { + t.Fatalf("first call: failed = %v, want the account reported as timed out", failed) + } + continue + } + if len(inFlight) != 1 { + t.Fatalf("call %d: inFlight = %v, want the account reported as still running", i, inFlight) + } + if len(failed) != 0 { + t.Fatalf("call %d: failed = %v, want empty while the retune is in flight", i, failed) + } + } + + if got := calls.Load(); got != 1 { + t.Fatalf("setPerformance called %d times, want 1: each retry started another blocked worker", got) + } +} + +// TestResolvePendingTrustsFinishedWorkers covers the reporting race cubic +// flagged on PR #7452: a retune that finished just before the deadline must be +// reported by its outcome, not as a timeout, whatever the results channel has +// delivered so far. +func TestResolvePendingTrustsFinishedWorkers(t *testing.T) { + ok := &perfWorker{done: make(chan struct{})} + close(ok.done) + + broken := &perfWorker{done: make(chan struct{}), err: errors.New("boom")} + close(broken.done) + + stillRunning := &perfWorker{done: make(chan struct{})} + + pending := map[types.AccountID]*perfWorker{ + "ok": ok, + "broken": broken, + "running": stillRunning, + } + failed := map[string]string{} + + applied := resolvePending(pending, failed) + + if applied != 1 { + t.Fatalf("applied = %d, want 1", applied) + } + if failed["broken"] != "boom" { + t.Fatalf("failed[broken] = %q, want the worker's own error", failed["broken"]) + } + if _, ok := failed["ok"]; ok { + t.Fatalf("failed = %v, want no entry for the account that succeeded", failed) + } + if got := failed["running"]; got == "" || got == "boom" { + t.Fatalf("failed[running] = %q, want the timeout message", got) + } +}