From dca5d87126ed1aec55594da60614806b6aa4af8a Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Fri, 5 Jun 2026 13:05:12 +0100 Subject: [PATCH 1/6] enable pprof profiling: - add debug build flag which builds with symbols and pprof enabled - modify Dockerfile to build a profiling image based on debian - add k8s config files to handle deploying the binary inside a cluster - add some pprof commands with explanations of their function --- Makefile | 12 +- build/Dockerfile | 36 +- cmd/nginx-ingress/debug_transport.go | 303 ++++++++++++ cmd/nginx-ingress/debug_transport_release.go | 9 + cmd/nginx-ingress/main.go | 2 + cmd/nginx-ingress/pprof_debug.go | 22 + cmd/nginx-ingress/pprof_release.go | 6 + docs/developer/README.md | 1 + docs/developer/profiling.md | 457 +++++++++++++++++++ 9 files changed, 846 insertions(+), 2 deletions(-) create mode 100644 cmd/nginx-ingress/debug_transport.go create mode 100644 cmd/nginx-ingress/debug_transport_release.go create mode 100644 cmd/nginx-ingress/pprof_debug.go create mode 100644 cmd/nginx-ingress/pprof_release.go create mode 100644 docs/developer/profiling.md diff --git a/Makefile b/Makefile index 2ab8edcad6..9220096625 100644 --- a/Makefile +++ b/Makefile @@ -149,6 +149,12 @@ $(BINARY_NAME)-$(ARCH): $(GO_SRCS) CGO_ENABLED=0 GOOS=$(strip $(GOOS)) GOARCH=$(strip $(ARCH)) go build -trimpath -ldflags "$(GO_LINKER_FLAGS)" -o $(BINARY_NAME)-$(ARCH) github.com/nginx/kubernetes-ingress/cmd/nginx-ingress @cp $(BINARY_NAME)-$(ARCH) $(BINARY_NAME) +.PHONY: build-debug +build-debug: ## Build Ingress Controller binary with debug flags and pprof on :6060 + @go version || (code=$$?; printf "\033[0;31mError\033[0m: unable to build locally, try using the parameter TARGET=container or TARGET=download\n"; exit $$code) + CGO_ENABLED=0 GOOS=$(strip $(GOOS)) GOARCH=$(strip $(ARCH)) go build -tags debug -ldflags "$(DEBUG_GO_LINKER_FLAGS)" -gcflags "$(DEBUG_GO_GC_FLAGS)" -o $(BINARY_NAME)-$(ARCH) github.com/nginx/kubernetes-ingress/cmd/nginx-ingress + @cp $(BINARY_NAME)-$(ARCH) $(BINARY_NAME) + .PHONY: build build: ## Build Ingress Controller binary ifeq ($(strip $(TARGET)),local) @@ -159,7 +165,7 @@ else ifeq ($(strip $(TARGET)),download) else ifeq ($(strip $(TARGET)),debug) # Debug builds run unconditionally (no incremental file target) since they are infrequent. @go version || (code=$$?; printf "\033[0;31mError\033[0m: unable to build locally, try using the parameter TARGET=container or TARGET=download\n"; exit $$code) - CGO_ENABLED=0 GOOS=$(strip $(GOOS)) GOARCH=$(strip $(ARCH)) go build -ldflags "$(DEBUG_GO_LINKER_FLAGS)" -gcflags "$(DEBUG_GO_GC_FLAGS)" -o $(BINARY_NAME)-$(ARCH) github.com/nginx/kubernetes-ingress/cmd/nginx-ingress + CGO_ENABLED=0 GOOS=$(strip $(GOOS)) GOARCH=$(strip $(ARCH)) go build -tags debug -ldflags "$(DEBUG_GO_LINKER_FLAGS)" -gcflags "$(DEBUG_GO_GC_FLAGS)" -o $(BINARY_NAME)-$(ARCH) github.com/nginx/kubernetes-ingress/cmd/nginx-ingress @cp $(BINARY_NAME)-$(ARCH) $(BINARY_NAME) else ifeq ($(strip $(TARGET)),container) # Binary is built inside Docker as part of the image build; nothing to do here. @@ -184,6 +190,10 @@ build-goreleaser: ## Build Ingress Controller binary using GoReleaser @goreleaser -v || (code=$$?; printf "\033[0;31mError\033[0m: there was a problem with GoReleaser. Follow the docs to install it https://goreleaser.com/install\n"; exit $$code) GOOS=$(strip $(GOOS)) GOPATH=$(shell go env GOPATH) GOARCH=$(strip $(ARCH)) goreleaser build --clean --snapshot --id kubernetes-ingress --single-target +.PHONY: debian-image-profiling +debian-image-profiling: build-debug ## Create Docker image for profiling (Debian + pprof on :6060, includes Delve) + docker build --platform linux/$(strip $(ARCH)) $(strip $(DOCKER_BUILD_OPTIONS)) --target profiling -f build/Dockerfile -t $(BUILD_IMAGE) . --build-arg BUILD_OS=debian --build-arg NGINX_OSS_VERSION=$(NGINX_OSS_VERSION) --build-arg AGENT_V3_VERSION=$(AGENT_V3_VERSION) + .PHONY: debian-image debian-image: build ## Create Docker image for Ingress Controller (Debian) $(DOCKER_CMD) --build-arg BUILD_OS=debian --build-arg NGINX_OSS_VERSION=$(NGINX_OSS_VERSION) --build-arg AGENT_V3_VERSION=$(AGENT_V3_VERSION) diff --git a/build/Dockerfile b/build/Dockerfile index c7569cfb29..784ff3b581 100644 --- a/build/Dockerfile +++ b/build/Dockerfile @@ -822,7 +822,7 @@ RUN apk add --no-cache git RUN --mount=type=bind,target=/go/src/github.com/nginx/kubernetes-ingress/ --mount=type=cache,target=/root/.cache/go-build \ go mod download RUN --mount=type=bind,target=/go/src/github.com/nginx/kubernetes-ingress/ --mount=type=cache,target=/root/.cache/go-build \ - CGO_ENABLED=0 GOOS=linux GOARCH=$TARGETARCH go build -gcflags "all=-N -l" -o /nginx-ingress github.com/nginx/kubernetes-ingress/cmd/nginx-ingress + CGO_ENABLED=0 GOOS=linux GOARCH=$TARGETARCH go build -tags debug -gcflags "all=-N -l" -o /nginx-ingress github.com/nginx/kubernetes-ingress/cmd/nginx-ingress RUN CGO_ENABLED=0 go install -ldflags "-s -w -extldflags '-static'" github.com/go-delve/delve/cmd/dlv@latest @@ -903,6 +903,40 @@ USER 101 ENTRYPOINT ["/dlv"] +############################################# profiling — host debug binary + Delve, pprof on :6060, normal entrypoint ############################################# +FROM common AS profiling +ARG BUILD_OS +ENV BUILD_OS=${BUILD_OS} + +LABEL org.nginx.kic.image.build.version="profiling" + +ENV GOPATH="/work" +ENV GOROOT="/go" +ENV PATH="$PATH:${GOROOT}/bin:${GOPATH}/bin" + +COPY --link --from=debug-builder --chown=101:0 /go/bin/dlv /dlv +COPY --link --chown=101:0 nginx-ingress / +# root is required for `setcap` invocation +USER 0 +RUN --mount=type=bind,target=/tmp if [ -z "${BUILD_OS##*plus*}" ]; then PLUS=-plus; fi \ + && cp -a /tmp/internal/configs/version1/nginx$PLUS.ingress.tmpl \ + /tmp/internal/configs/version1/nginx$PLUS.tmpl \ + /tmp/internal/configs/version2/nginx$PLUS.virtualserver.tmpl \ + /tmp/internal/configs/version2/nginx$PLUS.transportserver.tmpl / \ + && if [ -z "${BUILD_OS##*plus*}" ]; then cp -a /tmp/internal/configs/version2/oidc.tmpl /; fi \ + && chown -R 101:0 /*.tmpl \ + && chmod -R g=u /*.tmpl \ + && setcap 'cap_net_bind_service=+ep' /nginx-ingress && setcap -v 'cap_net_bind_service=+ep' /nginx-ingress \ + && setcap 'cap_net_bind_service=+ep' /dlv && setcap -v 'cap_net_bind_service=+ep' /dlv \ + && mkdir -p /nonexistent /work /go/bin /go-build \ + && chown 101:0 /nonexistent /work /go-build +COPY --link --from=debug-builder --chown=101:0 /usr/local/go/bin/go /go/bin/go +# 101 is nginx, defined above +USER 101 + +EXPOSE 6060 + + ############################################# local-prebuilt — host binary into pre-downloaded base image ############################################# FROM ${PREBUILT_BASE_IMG} AS local-prebuilt ARG BUILD_OS diff --git a/cmd/nginx-ingress/debug_transport.go b/cmd/nginx-ingress/debug_transport.go new file mode 100644 index 0000000000..8d510ffed1 --- /dev/null +++ b/cmd/nginx-ingress/debug_transport.go @@ -0,0 +1,303 @@ +//go:build debug + +package main + +import ( + "encoding/json" + "fmt" + "net/http" + "sort" + "strings" + "sync" + "sync/atomic" + "text/tabwriter" + "time" + + "k8s.io/client-go/rest" +) + +// apiStatsCollector aggregates K8s API call statistics across all clients. +var apiStats = &apiStatsCollector{ + stats: make(map[string]*callStats), + started: time.Now(), +} + +func init() { + http.HandleFunc("/debug/api-stats", apiStats.serveHTTP) + http.HandleFunc("/debug/api-stats/reset", apiStats.serveReset) +} + +// wrapTransportWithDebugTracking instruments the rest.Config transport to +// record per-verb, per-resource API call counts and latencies. +// In release builds this is a no-op (see debug_transport_release.go). +func wrapTransportWithDebugTracking(config *rest.Config) { + existing := config.WrapTransport + config.WrapTransport = func(rt http.RoundTripper) http.RoundTripper { + if existing != nil { + rt = existing(rt) + } + return &trackingTransport{inner: rt, collector: apiStats} + } +} + +// trackingTransport wraps an http.RoundTripper and records stats for each request. +type trackingTransport struct { + inner http.RoundTripper + collector *apiStatsCollector +} + +func (t *trackingTransport) RoundTrip(req *http.Request) (*http.Response, error) { + start := time.Now() + resp, err := t.inner.RoundTrip(req) + elapsed := time.Since(start) + + isErr := err != nil || (resp != nil && resp.StatusCode >= 400) + verb, resource, group := classifyRequest(req) + t.collector.record(verb, resource, group, elapsed, isErr) + + return resp, err +} + +// callStats holds per-verb/resource aggregate statistics. +type callStats struct { + Verb string + Resource string + Group string + Count int64 + Errors int64 + TotalTime time.Duration + MinTime time.Duration + MaxTime time.Duration + LastCall time.Time +} + +// apiStatsCollector is the shared, concurrency-safe stats store. +type apiStatsCollector struct { + mu sync.Mutex + stats map[string]*callStats + total atomic.Int64 + started time.Time +} + +func (c *apiStatsCollector) record(verb, resource, group string, elapsed time.Duration, isErr bool) { + c.total.Add(1) + key := verb + " " + resource + + c.mu.Lock() + defer c.mu.Unlock() + + s, ok := c.stats[key] + if !ok { + s = &callStats{ + Verb: verb, + Resource: resource, + Group: group, + MinTime: elapsed, + } + c.stats[key] = s + } + s.Count++ + s.TotalTime += elapsed + s.LastCall = time.Now() + if elapsed < s.MinTime { + s.MinTime = elapsed + } + if elapsed > s.MaxTime { + s.MaxTime = elapsed + } + if isErr { + s.Errors++ + } +} + +func (c *apiStatsCollector) reset() { + c.mu.Lock() + defer c.mu.Unlock() + c.stats = make(map[string]*callStats) + c.total.Store(0) + c.started = time.Now() +} + +func (c *apiStatsCollector) snapshot() ([]callStats, int64, time.Time) { + c.mu.Lock() + defer c.mu.Unlock() + + out := make([]callStats, 0, len(c.stats)) + for _, s := range c.stats { + out = append(out, *s) + } + sort.Slice(out, func(i, j int) bool { + return out[i].Count > out[j].Count + }) + return out, c.total.Load(), c.started +} + +// classifyRequest extracts verb, resource, and API group from a K8s API request. +func classifyRequest(req *http.Request) (verb, resource, group string) { + path := strings.Trim(req.URL.Path, "/") + parts := strings.Split(path, "/") + + // Determine API group and skip version prefix. + // /api/v1/... -> group="core", skip 2 + // /apis/networking.k8s.io/v1/... -> group="networking.k8s.io", skip 3 + var idx int + switch { + case len(parts) >= 2 && parts[0] == "api": + group = "core" + idx = 2 + case len(parts) >= 3 && parts[0] == "apis": + group = parts[1] + idx = 3 + default: + return req.Method, path, "" + } + + if idx >= len(parts) { + return req.Method, path, group + } + + // Remaining: [namespaces, , , ] or [, ] + remaining := parts[idx:] + if len(remaining) >= 2 && remaining[0] == "namespaces" { + remaining = remaining[2:] + } + + if len(remaining) == 0 { + return req.Method, path, group + } + resource = remaining[0] + hasName := len(remaining) > 1 + + // Classify the verb. + verb = req.Method + if req.URL.Query().Get("watch") == "true" { + verb = "WATCH" + } else if req.Method == http.MethodGet && !hasName { + verb = "LIST" + } + + return verb, resource, group +} + +// --- HTTP handlers (served on the pprof :6060 mux) --- + +// serveHTTP returns stats as JSON (default) or plain text (?format=text). +func (c *apiStatsCollector) serveHTTP(w http.ResponseWriter, r *http.Request) { + if r.Method != http.MethodGet { + http.Error(w, "method not allowed", http.StatusMethodNotAllowed) + return + } + + stats, total, started := c.snapshot() + uptime := time.Since(started) + + if r.URL.Query().Get("format") == "text" { + c.writeText(w, stats, total, uptime) + return + } + c.writeJSON(w, stats, total, uptime) +} + +func (c *apiStatsCollector) serveReset(w http.ResponseWriter, r *http.Request) { + if r.Method != http.MethodPost { + http.Error(w, "use POST to reset", http.StatusMethodNotAllowed) + return + } + c.reset() + w.WriteHeader(http.StatusOK) + fmt.Fprintln(w, "stats reset") +} + +type jsonOutput struct { + Uptime string `json:"uptime"` + UptimeSec float64 `json:"uptime_seconds"` + TotalCalls int64 `json:"total_calls"` + APICallStats []jsonEntry `json:"calls"` +} + +type jsonEntry struct { + Verb string `json:"verb"` + Resource string `json:"resource"` + Group string `json:"group"` + Count int64 `json:"count"` + Errors int64 `json:"errors"` + TotalMs float64 `json:"total_ms"` + AvgMs float64 `json:"avg_ms"` + MinMs float64 `json:"min_ms"` + MaxMs float64 `json:"max_ms"` + LastCall string `json:"last_call"` +} + +func (c *apiStatsCollector) writeJSON(w http.ResponseWriter, stats []callStats, total int64, uptime time.Duration) { + entries := make([]jsonEntry, 0, len(stats)) + for _, s := range stats { + avg := float64(0) + if s.Count > 0 { + avg = float64(s.TotalTime.Microseconds()) / float64(s.Count) / 1000 + } + entries = append(entries, jsonEntry{ + Verb: s.Verb, + Resource: s.Resource, + Group: s.Group, + Count: s.Count, + Errors: s.Errors, + TotalMs: float64(s.TotalTime.Microseconds()) / 1000, + AvgMs: avg, + MinMs: float64(s.MinTime.Microseconds()) / 1000, + MaxMs: float64(s.MaxTime.Microseconds()) / 1000, + LastCall: s.LastCall.Format(time.RFC3339), + }) + } + out := jsonOutput{ + Uptime: uptime.Round(time.Second).String(), + UptimeSec: uptime.Seconds(), + TotalCalls: total, + APICallStats: entries, + } + w.Header().Set("Content-Type", "application/json") + enc := json.NewEncoder(w) + enc.SetIndent("", " ") + _ = enc.Encode(out) +} + +func (c *apiStatsCollector) writeText(w http.ResponseWriter, stats []callStats, total int64, uptime time.Duration) { + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + + fmt.Fprintf(w, "K8s API Call Statistics\n") + fmt.Fprintf(w, "Uptime: %s | Total calls: %d\n\n", uptime.Round(time.Second), total) + + if len(stats) == 0 { + fmt.Fprintln(w, "(no calls recorded)") + return + } + + tw := tabwriter.NewWriter(w, 0, 4, 2, ' ', 0) + fmt.Fprintln(tw, "VERB\tRESOURCE\tGROUP\tCOUNT\tERRORS\tAVG\tMIN\tMAX\tLAST CALL") + fmt.Fprintln(tw, "----\t--------\t-----\t-----\t------\t---\t---\t---\t---------") + for _, s := range stats { + avg := time.Duration(0) + if s.Count > 0 { + avg = s.TotalTime / time.Duration(s.Count) + } + ago := time.Since(s.LastCall).Round(time.Second) + fmt.Fprintf(tw, "%s\t%s\t%s\t%d\t%d\t%s\t%s\t%s\t%s ago\n", + s.Verb, s.Resource, s.Group, + s.Count, s.Errors, + fmtDuration(avg), fmtDuration(s.MinTime), fmtDuration(s.MaxTime), + ago, + ) + } + tw.Flush() +} + +// fmtDuration formats a duration in a compact, human-readable way. +func fmtDuration(d time.Duration) string { + switch { + case d < time.Millisecond: + return fmt.Sprintf("%.0fus", float64(d.Microseconds())) + case d < time.Second: + return fmt.Sprintf("%.1fms", float64(d.Microseconds())/1000) + default: + return d.Round(time.Millisecond).String() + } +} diff --git a/cmd/nginx-ingress/debug_transport_release.go b/cmd/nginx-ingress/debug_transport_release.go new file mode 100644 index 0000000000..72a2fc91aa --- /dev/null +++ b/cmd/nginx-ingress/debug_transport_release.go @@ -0,0 +1,9 @@ +//go:build !debug + +package main + +import "k8s.io/client-go/rest" + +// wrapTransportWithDebugTracking is a no-op in release builds. +// Build with `-tags debug` to enable K8s API call tracking on :6060/debug/api-stats. +func wrapTransportWithDebugTracking(_ *rest.Config) {} diff --git a/cmd/nginx-ingress/main.go b/cmd/nginx-ingress/main.go index 3a11e1ddfc..9fea585528 100644 --- a/cmd/nginx-ingress/main.go +++ b/cmd/nginx-ingress/main.go @@ -426,6 +426,8 @@ func mustCreateConfigAndKubeClient(ctx context.Context) (*rest.Config, *kubernet } } + wrapTransportWithDebugTracking(config) + kubeClient, err := kubernetes.NewForConfig(config) if err != nil { nl.Fatalf(l, "Failed to create client: %v.", err) diff --git a/cmd/nginx-ingress/pprof_debug.go b/cmd/nginx-ingress/pprof_debug.go new file mode 100644 index 0000000000..ea2a20f2f4 --- /dev/null +++ b/cmd/nginx-ingress/pprof_debug.go @@ -0,0 +1,22 @@ +//go:build debug + +package main + +import ( + "fmt" + "log" + "net/http" + _ "net/http/pprof" +) + +const pprofPort = 6060 + +func init() { + go func() { + addr := fmt.Sprintf(":%d", pprofPort) + fmt.Printf("[debug] pprof server listening on %s\n", addr) + if err := http.ListenAndServe(addr, nil); err != nil { //nolint:gosec + log.Printf("[debug] pprof server error: %v\n", err) + } + }() +} diff --git a/cmd/nginx-ingress/pprof_release.go b/cmd/nginx-ingress/pprof_release.go new file mode 100644 index 0000000000..ab41528175 --- /dev/null +++ b/cmd/nginx-ingress/pprof_release.go @@ -0,0 +1,6 @@ +//go:build !debug + +package main + +// pprof is disabled in release builds. +// Build with `-tags debug` to enable the pprof HTTP server on :6060. diff --git a/docs/developer/README.md b/docs/developer/README.md index 3bfe8d1241..0a6a737c5c 100644 --- a/docs/developer/README.md +++ b/docs/developer/README.md @@ -2,3 +2,4 @@ - [Architecture](./architecture.md) - [Debugging](./debugging.md) +- [Profiling](./profiling.md) diff --git a/docs/developer/profiling.md b/docs/developer/profiling.md new file mode 100644 index 0000000000..27de31a1b8 --- /dev/null +++ b/docs/developer/profiling.md @@ -0,0 +1,457 @@ +# Profiling + +This guide covers how to build, deploy, and profile NGINX Ingress Controller using Go's built-in [pprof](https://pkg.go.dev/net/http/pprof) tooling. The pprof HTTP server is compiled in only when the `debug` build tag is set, so production binaries are completely unaffected. + +- [How it works](#how-it-works) +- [Quickstart](#quickstart) +- [Building the profiling image](#building-the-profiling-image) + - [Local binary (recommended)](#local-binary-recommended) + - [Container-built binary](#container-built-binary) +- [Deploying to Kubernetes](#deploying-to-kubernetes) + - [Using the provided manifest](#using-the-provided-manifest) + - [Using Helm](#using-helm) +- [Accessing pprof](#accessing-pprof) + - [kubectl port-forward](#kubectl-port-forward) + - [NodePort](#nodeport) +- [K8s API call tracking](#k8s-api-call-tracking) + - [Viewing stats](#viewing-stats) + - [Isolating API calls for a specific action](#isolating-api-calls-for-a-specific-action) + - [Verb classification](#verb-classification) + - [What is tracked](#what-is-tracked) + - [Implementation](#implementation) +- [Collecting profiles](#collecting-profiles) + - [Function call frequency (CPU profile)](#function-call-frequency-cpu-profile) + - [Goroutine analysis](#goroutine-analysis) + - [Execution trace](#execution-trace) + - [Heap (memory) profile](#heap-memory-profile) + - [All available profiles](#all-available-profiles) +- [Continuous profiling with an external tool](#continuous-profiling-with-an-external-tool) +- [Interactive debugging with Delve](#interactive-debugging-with-delve) +- [Make targets reference](#make-targets-reference) + +## How it works + +Profiling is controlled entirely by Go [build tags](https://pkg.go.dev/go/build#hdr-Build_Constraints). Two files in `cmd/nginx-ingress/` implement the toggle: + +| File | Build constraint | Effect | +| --- | --- | --- | +| `pprof_debug.go` | `//go:build debug` | Imports `net/http/pprof` and starts an HTTP server on `:6060` in an `init()` function | +| `pprof_release.go` | `//go:build !debug` | No-op stub; documents the debug counterpart | + +When built without `-tags debug` (the default), the Go compiler excludes `pprof_debug.go` entirely. The resulting binary contains zero pprof code or symbols. + +## Quickstart + +```shell +# 1. Build the debug binary with pprof +make build-debug + +# 2. Build the profiling Docker image +make debian-image-profiling TAG=profiling + +# 3. Create a local Kind cluster (if you don't have one) +make -f tests/Makefile create-kind-cluster + +# 4. Load the image into the cluster +kind load docker-image nginx/nginx-ingress:profiling + +# 5. Deploy prerequisites +kubectl apply -f deploy/crds.yaml +kubectl apply -f deployments/common/ns-and-sa.yaml +kubectl apply -f deployments/rbac/rbac.yaml +kubectl apply -f deployments/common/nginx-config.yaml +kubectl apply -f deployments/common/ingress-class.yaml + +# 6. Deploy NIC with pprof exposed +kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml + +# 7. Forward the pprof port +kubectl port-forward -n nginx-ingress deploy/nginx-ingress 6060:6060 + +# 8. Collect a 30-second CPU profile +go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30 +``` + +## Building the profiling image + +### Local binary (recommended) + +This cross-compiles the binary on the host and copies it into the container. Faster iteration. + +```shell +# Builds with -tags debug, debug symbols, and no optimizations +make build-debug + +# Packages into a Debian-based image targeting the "profiling" Dockerfile stage +make debian-image-profiling TAG=profiling +``` + +Set `ARCH=arm64` or `ARCH=amd64` to match your target architecture (defaults to `amd64`): + +```shell +make build-debug ARCH=arm64 +make debian-image-profiling TAG=profiling ARCH=arm64 +``` + +### Container-built binary + +If you prefer the binary to be built inside Docker (no local Go toolchain required), the `debug-builder` stage in `build/Dockerfile` also includes `-tags debug`. Use the existing debug image targets: + +```shell +make debian-image TARGET=debug TAG=profiling +``` + +Note: this image uses `/dlv` as its entrypoint (Delve debugger), not `/nginx-ingress`. For profiling without Delve, use the `debian-image-profiling` target above. + +## Deploying to Kubernetes + +### Using the provided manifest + +A ready-to-use manifest is provided at `deployments/debug/nginx-ingress-profiling.yaml`. It contains: + +- A **Deployment** identical to the standard one, with an additional `pprof` container port (6060) +- A **NodePort Service** (`nginx-ingress-pprof`) exposing port 6060 for pprof +- A **NodePort Service** (`nginx-ingress`) for standard HTTP/HTTPS traffic + +```shell +# Deploy prerequisites (if not already done) +kubectl apply -f deploy/crds.yaml +kubectl apply -f deployments/common/ns-and-sa.yaml +kubectl apply -f deployments/rbac/rbac.yaml +kubectl apply -f deployments/common/nginx-config.yaml +kubectl apply -f deployments/common/ingress-class.yaml + +# Deploy the profiling variant +kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml +``` + +Verify the pod is running and pprof is active: + +```shell +kubectl get pods -n nginx-ingress +kubectl logs -n nginx-ingress deploy/nginx-ingress | grep pprof +# Expected: [debug] pprof server listening on :6060 +``` + +### Using Helm + +If you use the Helm chart, add port 6060 via `customPorts` and ensure the image is the profiling build: + +```yaml +controller: + image: + tag: profiling + repository: nginx/nginx-ingress + customPorts: + - name: pprof + containerPort: 6060 + protocol: TCP + service: + type: NodePort + customPorts: + - name: pprof + nodePort: 30060 + port: 6060 + protocol: TCP + targetPort: 6060 +``` + +```shell +helm upgrade --install my-release charts/nginx-ingress -f values-profiling.yaml +``` + +## Accessing pprof + +### kubectl port-forward + +The simplest method, works with any cluster and requires no extra Service configuration: + +```shell +kubectl port-forward -n nginx-ingress deploy/nginx-ingress 6060:6060 +``` + +pprof is then available at `http://localhost:6060/debug/pprof/`. + +### NodePort + +If you deployed with the provided manifest or the Helm configuration above, find the assigned NodePort: + +```shell +kubectl get svc -n nginx-ingress nginx-ingress-pprof +``` + +Access pprof at `http://:/debug/pprof/`. + +## K8s API call tracking + +The debug build includes a custom HTTP transport wrapper that records **every Kubernetes API call** NIC makes. It tracks per-verb, per-resource call counts, error counts, and latency statistics. This is the most direct way to answer "how often are we calling the K8s API, and for what?" + +Served on the same `:6060` port at `/debug/api-stats`. + +### Viewing stats + +```shell +# Human-readable table: per-verb, per-resource call counts, error rates, and latencies +# Shows e.g.: LIST pods (156 calls, avg 12ms), WATCH ingresses (12 calls), etc. +curl http://localhost:6060/debug/api-stats?format=text + +# JSON output for programmatic consumption by an external monitoring tool +curl http://localhost:6060/debug/api-stats +``` + +#### Text response example + +```text +K8s API Call Statistics +Uptime: 5m32s | Total calls: 1234 + +VERB RESOURCE GROUP COUNT ERRORS AVG MIN MAX LAST CALL +---- -------- ----- ----- ------ --- --- --- --------- +LIST pods core 156 2 12.0ms 8.1ms 45.3ms 1s ago +WATCH ingresses networking.k8s.io 12 0 2.3s 1.2s 5.0s 2s ago +GET configmaps core 89 0 5.2ms 3.1ms 22.0ms 3s ago +GET ingressclasses networking.k8s.io 45 0 4.8ms 2.9ms 18.7ms 5s ago +``` + +#### JSON response example + +```json +{ + "uptime": "5m32s", + "uptime_seconds": 332, + "total_calls": 1234, + "calls": [ + { + "verb": "LIST", + "resource": "pods", + "group": "core", + "count": 156, + "errors": 2, + "total_ms": 1872.5, + "avg_ms": 12.0, + "min_ms": 8.1, + "max_ms": 45.3, + "last_call": "2026-06-05T10:30:15Z" + } + ] +} +``` + +### Isolating API calls for a specific action + +Reset counters, trigger an action, then see exactly what API calls it caused: + +```shell +# Clear all counters +curl -X POST http://localhost:6060/debug/api-stats/reset + +# Trigger the action you want to measure +kubectl apply -f my-virtualserver.yaml +sleep 5 + +# See what API calls NIC made in response +curl http://localhost:6060/debug/api-stats?format=text +``` + +### Verb classification + +The tracker classifies HTTP methods into Kubernetes-style verbs: + +| HTTP method | K8s verb | Condition | +| --- | --- | --- | +| GET | `LIST` | No resource name in URL path | +| GET | `GET` | Resource name present in URL path | +| GET | `WATCH` | `?watch=true` query parameter | +| POST | `POST` | Always | +| PUT | `PUT` | Always | +| PATCH | `PATCH` | Always | +| DELETE | `DELETE` | Always | + +### What is tracked + +The transport wrapper intercepts **all** K8s API calls made by NIC, including those from: + +- `kubeClient` (core Kubernetes API: pods, services, secrets, configmaps, namespaces, events) +- `confClient` (CRD API: VirtualServers, VirtualServerRoutes, TransportServers, Policies, GlobalConfiguration) +- `dynClient` (dynamic client: AppProtect, AppProtectDos, IngressLink) + +The wrapper sits on the `rest.Config` transport, so every client created from that config is automatically instrumented. + +### Implementation + +The tracking is implemented in `cmd/nginx-ingress/debug_transport.go` (only compiled with `-tags debug`). It: + +1. Wraps `rest.Config.WrapTransport` with a custom `http.RoundTripper` before any clients are created +2. Records verb, resource, API group, latency, and error status for each request +3. Aggregates stats in a concurrency-safe collector +4. Registers HTTP handlers on `http.DefaultServeMux` (shared with pprof on `:6060`) + +In release builds, `wrapTransportWithDebugTracking()` is a no-op (see `debug_transport_release.go`). + +## Collecting profiles + +All examples below assume pprof is accessible at `localhost:6060` (via port-forward or otherwise). + +### Function call frequency (CPU profile) + +CPU profiles show how much time is spent in each function. Functions that appear most often are being called most frequently. This is the primary tool for answering "what functions do we spend the most time in?" + +```shell +# Collect a 30-second CPU profile and open the interactive pprof shell +go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30 + +# Inside the pprof shell: +# top 20 -- top 20 functions by self CPU time +# top -cum 20 -- top 20 by cumulative time (includes time spent in callees) +# list -- show annotated source with per-line CPU time +# web -- open a call graph in the browser +``` + +To focus specifically on K8s client-go calls, use the web UI with filtering: + +```shell +# Open profile in browser with flame graph +go tool pprof -http=:8080 http://localhost:6060/debug/pprof/profile?seconds=30 +# In the web UI: use the "Search" box to filter by "client-go" or "k8s.io" +# The flame graph view shows the full call chain from NIC code into K8s API calls +``` + +To compare before and after a change: + +```shell +# Save a baseline profile +curl -o before.prof http://localhost:6060/debug/pprof/profile?seconds=30 + +# ... make a code or config change, redeploy ... + +# Save a second profile +curl -o after.prof http://localhost:6060/debug/pprof/profile?seconds=30 + +# Diff them to see what got slower or faster +go tool pprof -diff_base=before.prof after.prof +# top 20 -- shows delta: functions that got slower (+) or faster (-) +``` + +### Goroutine analysis + +Goroutine dumps show what every goroutine is doing right now. Useful for seeing how many concurrent K8s API calls or watches are in-flight, and identifying goroutine leaks. + +```shell +# Full goroutine stacks -- every goroutine individually +# Look for goroutines blocked in: +# k8s.io/client-go/tools/cache.(*Reflector).ListAndWatch -- active watches +# net/http.(*Transport).roundTrip -- in-flight API calls +# internal/k8s.(*LoadBalancerController).sync -- sync loop processing +curl http://localhost:6060/debug/pprof/goroutine?debug=2 + +# Summary grouped by stack -- shows how many goroutines share the same call stack +# Useful for spotting goroutine leaks (e.g., 500 goroutines stuck in the same place) +curl http://localhost:6060/debug/pprof/goroutine?debug=1 + +# Analyze in pprof (top goroutine creation sites) +go tool pprof http://localhost:6060/debug/pprof/goroutine +# top 20 -- functions that created the most goroutines +# traces -- full stack traces grouped by count +``` + +### Execution trace + +Execution traces capture goroutine scheduling, syscalls, GC events, and network I/O over a time window. This gives the most detailed view of K8s API call timing and concurrency, but produces large files. Keep the capture short (5-10 seconds). + +```shell +# Capture a 5-second trace and open the trace viewer +curl -o trace.out http://localhost:6060/debug/pprof/trace?seconds=5 +go tool trace trace.out + +# In the trace viewer: +# "Goroutine analysis" -- time each goroutine spent running/waiting/blocked +# "Network blocking profile" -- time spent waiting on network I/O (K8s API calls) +# "Synchronization blocking profile" -- lock contention between goroutines +``` + +### Heap (memory) profile + +Shows which functions allocate the most memory. Useful for identifying objects retained by K8s informer caches and API response parsing. + +```shell +# Current live allocations (what's in memory right now) +go tool pprof http://localhost:6060/debug/pprof/heap +# top 20 -- functions holding the most memory +# top -cum 20 -- cumulative (includes memory held by callees) + +# All allocations since start (total bytes allocated, even if already GC'd) +# Useful for finding functions that allocate frequently, causing GC pressure +go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap +# top 20 -- highest total allocation volume + +# Count of allocated objects instead of bytes +# Useful for finding high-frequency small allocations +go tool pprof -alloc_objects http://localhost:6060/debug/pprof/heap +# top 20 -- functions creating the most objects +``` + +### All available profiles + +Browse the full index: + +```shell +curl http://localhost:6060/debug/pprof/ +``` + +This includes: `allocs`, `block`, `cmdline`, `goroutine`, `heap`, `mutex`, `profile`, `threadcreate`, and `trace`. + +## Continuous profiling with an external tool + +If you are building an external tool to continuously monitor NIC, both the pprof and API stats endpoints are available on `:6060`. Poll them programmatically: + +```go +import "net/http" + +// Fetch K8s API call stats (JSON) +resp, err := http.Get("http://localhost:6060/debug/api-stats") + +// Fetch a heap profile +resp, err := http.Get("http://localhost:6060/debug/pprof/heap") + +// Fetch a CPU profile (blocks for the specified duration) +resp, err := http.Get("http://localhost:6060/debug/pprof/profile?seconds=10") +``` + +### Endpoint summary + +| Endpoint | What it reveals | +| --- | --- | +| `/debug/api-stats` | Per-verb, per-resource K8s API call counts, error rates, and latencies | +| `/debug/api-stats/reset` | Reset all API call counters (POST) | +| `/debug/pprof/profile?seconds=N` | CPU time per function -- shows time spent in client-go, reflector, informer, and API call paths | +| `/debug/pprof/trace?seconds=N` | Execution trace -- goroutine scheduling, shows API call concurrency and latency | +| `/debug/pprof/goroutine?debug=2` | All goroutine stacks -- shows in-flight API calls, blocked watchers, pending list/watch | +| `/debug/pprof/heap` | Memory allocations -- identifies objects retained by API caches and informer stores | +| `/debug/pprof/block` | Blocking profile -- shows where goroutines block on channels/mutexes (enable with `runtime.SetBlockProfileRate`) | +| `/debug/pprof/mutex` | Mutex contention -- shows lock contention hotspots (enable with `runtime.SetMutexProfileFraction`) | + +## Interactive debugging with Delve + +The profiling image includes [Delve](https://github.com/go-delve/delve) at `/dlv`. You can attach to the running NIC process for interactive debugging alongside pprof: + +```shell +# Get the pod name +POD=$(kubectl get pod -n nginx-ingress -l app=nginx-ingress -o jsonpath='{.items[0].metadata.name}') + +# Attach Delve to the NIC process (PID 1) +kubectl exec -it -n nginx-ingress "$POD" -- /dlv attach 1 --headless --listen=:2345 --api-version=2 --accept-multiclient & + +# Forward the Delve port +kubectl port-forward -n nginx-ingress "$POD" 2345:2345 +``` + +Then connect your IDE to `localhost:2345`. See the [Debugging guide](./debugging.md) for IDE configuration details. + +## Make targets reference + +| Target | Description | +| --- | --- | +| `make build-debug` | Build the NIC binary with `-tags debug`, debug symbols, and no optimizations. pprof server on `:6060`. | +| `make debian-image-profiling TAG=` | Build a Debian-based Docker image using the `profiling` Dockerfile stage. Depends on `build-debug`. | +| `make build TARGET=debug` | Equivalent to `build-debug`, used by the `build` dispatcher. | +| `make debian-image TARGET=debug TAG=` | Build the Delve-based debug image (entrypoint `/dlv`, also includes pprof). | From b9d0db8ecd38e58a5c9fbfbe14ad9706dd1f9b45 Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Fri, 5 Jun 2026 16:32:06 +0100 Subject: [PATCH 2/6] add more benchmarks, profiling script --- Makefile | 3 + docs/developer/profiling.md | 6 + hack/profile.sh | 146 ++++++++ internal/configs/configurator_bench_test.go | 391 +++++++++++++++++++- 4 files changed, 545 insertions(+), 1 deletion(-) create mode 100755 hack/profile.sh diff --git a/Makefile b/Makefile index 9220096625..8a89a185f1 100644 --- a/Makefile +++ b/Makefile @@ -109,6 +109,9 @@ govulncheck: ## Run govulncheck linter test: ## Run GoLang tests go test -tags=aws,helmunit -shuffle=on ./... +test-profile: ## Run GoLang tests with profiling + PROF_BENCH_ONLY=0 hack/profile.sh + .PHONY: test-update-snaps test-update-snaps: UPDATE_SNAPS=always go test -tags=aws,helmunit -shuffle=on ./... diff --git a/docs/developer/profiling.md b/docs/developer/profiling.md index 27de31a1b8..e4a8ecef62 100644 --- a/docs/developer/profiling.md +++ b/docs/developer/profiling.md @@ -190,6 +190,12 @@ Served on the same `:6060` port at `/debug/api-stats`. ### Viewing stats +```shell +# Launch the pprof web UI on port 8088 (may take some time to come up, depends on cluster size and activity) +> go tool pprof -http=:8088 "http://localhost:6060" +Fetching profile over HTTP from http://localhost:6060/debug/pprof/profile +``` + ```shell # Human-readable table: per-verb, per-resource call counts, error rates, and latencies # Shows e.g.: LIST pods (156 calls, avg 12ms), WATCH ingresses (12 calls), etc. diff --git a/hack/profile.sh b/hack/profile.sh new file mode 100755 index 0000000000..edb3ed5c74 --- /dev/null +++ b/hack/profile.sh @@ -0,0 +1,146 @@ +#!/usr/bin/env bash +set -euo pipefail + +# Profile every test and benchmark function individually. +# +# Each test gets its own CPU and memory profile file, numbered for easy +# ordering and named after the test function: +# +# profiles/ +# internal_configs/ +# 001_TestGetMapKeyAsBool_cpu.prof +# 001_TestGetMapKeyAsBool_mem.prof +# 002_TestGetMapKeyAsInt_cpu.prof +# ... +# +# Usage: +# ./hack/profile.sh # all internal/ packages, tests + benchmarks +# PROF_DIR=/tmp/prof ./hack/profile.sh # custom output directory +# PROF_PATTERN="TestParse" ./hack/profile.sh # only tests matching a pattern +# PROF_BENCH_ONLY=1 ./hack/profile.sh # only benchmark functions +# PROF_TEST_ONLY=1 ./hack/profile.sh # only test functions +# PROF_PKG="./internal/configs/..." ./hack/profile.sh # specific package(s) + +PROF_DIR="${PROF_DIR:-./profiles}" +PROF_PATTERN="${PROF_PATTERN:-}" +PROF_BENCH_ONLY="${PROF_BENCH_ONLY:-}" +PROF_TEST_ONLY="${PROF_TEST_ONLY:-}" +PROF_PKG="${PROF_PKG:-}" + +GOTEST_BASE_FLAGS=(-tags=aws,helmunit -count=1 -benchmem) + +total_tests=0 +total_failed=0 + +# Run a single test/benchmark function with its own profile files. +# $1 = package import path +# $2 = test number (zero-padded) +# $3 = function name +# $4 = package output directory +# $5 = "test" or "bench" +run_one() { + local pkg=$1 num=$2 func=$3 pkg_dir=$4 kind=$5 + + local cpu_prof="${pkg_dir}/${num}_${func}_cpu.prof" + local mem_prof="${pkg_dir}/${num}_${func}_mem.prof" + + local run_flags=() + if [[ "${kind}" == "bench" ]]; then + # Run only this benchmark; -run=^$ ensures no test functions run. + run_flags=(-run='^$' -bench="^${func}$") + else + run_flags=(-run="^${func}$") + fi + + printf " %s %-50s " "${num}" "${func}" + + if go test "${GOTEST_BASE_FLAGS[@]}" "${run_flags[@]}" \ + -cpuprofile "${cpu_prof}" \ + -memprofile "${mem_prof}" \ + "${pkg}" > "${pkg_dir}/${num}_${func}.log" 2>&1; then + echo "ok" + else + echo "FAIL (see ${pkg_dir}/${num}_${func}.log)" + ((total_failed++)) || true + fi + ((total_tests++)) || true +} + +# List test or benchmark function names in a package. +# $1 = package import path +# $2 = "Test" or "Benchmark" +list_funcs() { + local pkg=$1 prefix=$2 + local pattern=".*" + if [[ -n "${PROF_PATTERN}" ]]; then + pattern="${PROF_PATTERN}" + fi + # -list prints matching test names to stdout, one per line. + # It may also print "ok " on the last line -- filter that out. + go test -tags=aws,helmunit -list "${prefix}${pattern}" "${pkg}" 2>/dev/null \ + | grep "^${prefix}" || true +} + +# Process one package: enumerate functions, run each with its own profiles. +profile_package() { + local pkg=$1 + + # Derive a directory name: .../internal/configs/version2 -> internal_configs_version2 + local dir_name + dir_name=$(echo "${pkg}" | sed 's|.*/internal/|internal/|; s|/|_|g') + local pkg_dir="${PROF_DIR}/${dir_name}" + + # Collect function names. + local funcs=() + if [[ -z "${PROF_BENCH_ONLY}" ]]; then + while IFS= read -r f; do + [[ -n "$f" ]] && funcs+=("test:${f}") + done < <(list_funcs "${pkg}" "Test") + fi + if [[ -z "${PROF_TEST_ONLY}" ]]; then + while IFS= read -r f; do + [[ -n "$f" ]] && funcs+=("bench:${f}") + done < <(list_funcs "${pkg}" "Benchmark") + fi + + if [[ ${#funcs[@]} -eq 0 ]]; then + return + fi + + mkdir -p "${pkg_dir}" + echo "--- ${pkg} (${#funcs[@]} functions)" + + local i=1 + for entry in "${funcs[@]}"; do + local kind="${entry%%:*}" + local func="${entry#*:}" + local num + num=$(printf "%03d" "${i}") + run_one "${pkg}" "${num}" "${func}" "${pkg_dir}" "${kind}" + ((i++)) + done + echo "" +} + +## Main + +echo "Saving per-test profiles to ${PROF_DIR}/" +echo "" + +if [[ -n "${PROF_PKG}" ]]; then + packages=$(go list -tags=aws,helmunit ${PROF_PKG} | sort -u) +else + packages=$(go list -tags=aws,helmunit ./... | sort -u | grep "/internal/") +fi + +for pkg in ${packages}; do + profile_package "${pkg}" +done + +echo "========================================" +echo "Total: ${total_tests} functions profiled, ${total_failed} failed" +echo "Profiles: ${PROF_DIR}/" +echo "" +echo "Analyze a profile:" +echo " go tool pprof ${PROF_DIR}//__cpu.prof" +echo " go tool pprof -http=:8080 ${PROF_DIR}//__cpu.prof" diff --git a/internal/configs/configurator_bench_test.go b/internal/configs/configurator_bench_test.go index a78f3b2c1c..789484e7e9 100644 --- a/internal/configs/configurator_bench_test.go +++ b/internal/configs/configurator_bench_test.go @@ -74,7 +74,7 @@ func BenchmarkAddOrUpdateMergeableIngress(b *testing.B) { } } -func BenchUpdateEndpoints(b *testing.B) { +func BenchmarkUpdateEndpoints(b *testing.B) { cnf, err := createTestConfiguratorBench() if err != nil { b.Fatal(err) @@ -234,3 +234,392 @@ func BenchmarkAddTransportServerMetricsLabels(b *testing.B) { cnf.updateTransportServerMetricsLabels(tsEx, streamUpstreams) } } + +// vsExWithEndpoints returns the standard cafe VirtualServerEx with populated endpoints. +func vsExWithEndpoints() VirtualServerEx { + vs := vsEx() + vs.Endpoints = map[string][]string{ + "default/tea-svc:80": { + "10.0.0.20:80", + }, + "default/tea-svc_version=v1:80": { + "10.0.0.30:80", + }, + "default/coffee-svc:80": { + "10.0.0.40:80", + }, + "default/sub-tea-svc_version=v1:80": { + "10.0.0.50:80", + }, + } + return vs +} + +// vsExWithSplits returns a VirtualServerEx that uses split routing (weight-based traffic splitting). +func vsExWithSplits() VirtualServerEx { + return VirtualServerEx{ + VirtualServer: &conf_v1.VirtualServer{ + ObjectMeta: meta_v1.ObjectMeta{ + Name: "cafe", + Namespace: "default", + }, + Spec: conf_v1.VirtualServerSpec{ + Host: "cafe.example.com", + Upstreams: []conf_v1.Upstream{ + { + Name: "tea-v1", + Service: "tea-svc-v1", + Port: 80, + }, + { + Name: "tea-v2", + Service: "tea-svc-v2", + Port: 80, + }, + }, + Routes: []conf_v1.Route{ + { + Path: "/tea", + Splits: []conf_v1.Split{ + { + Weight: 90, + Action: &conf_v1.Action{ + Pass: "tea-v1", + }, + }, + { + Weight: 10, + Action: &conf_v1.Action{ + Pass: "tea-v2", + }, + }, + }, + }, + { + Path: "/coffee", + Route: "default/coffee", + }, + }, + }, + }, + Endpoints: map[string][]string{ + "default/tea-svc-v1:80": { + "10.0.0.20:80", + }, + "default/tea-svc-v2:80": { + "10.0.0.21:80", + }, + "default/coffee-svc-v1:80": { + "10.0.0.30:80", + }, + "default/coffee-svc-v2:80": { + "10.0.0.31:80", + }, + }, + VirtualServerRoutes: []*conf_v1.VirtualServerRoute{ + { + ObjectMeta: meta_v1.ObjectMeta{ + Name: "coffee", + Namespace: "default", + }, + Spec: conf_v1.VirtualServerRouteSpec{ + Host: "cafe.example.com", + Upstreams: []conf_v1.Upstream{ + { + Name: "coffee-v1", + Service: "coffee-svc-v1", + Port: 80, + }, + { + Name: "coffee-v2", + Service: "coffee-svc-v2", + Port: 80, + }, + }, + Subroutes: []conf_v1.Route{ + { + Path: "/coffee", + Splits: []conf_v1.Split{ + { + Weight: 40, + Action: &conf_v1.Action{ + Pass: "coffee-v1", + }, + }, + { + Weight: 60, + Action: &conf_v1.Action{ + Pass: "coffee-v2", + }, + }, + }, + }, + }, + }, + }, + }, + } +} + +// vsExWithMatches returns a VirtualServerEx that uses match routing (header/arg conditions). +func vsExWithMatches() VirtualServerEx { + return VirtualServerEx{ + VirtualServer: &conf_v1.VirtualServer{ + ObjectMeta: meta_v1.ObjectMeta{ + Name: "cafe", + Namespace: "default", + }, + Spec: conf_v1.VirtualServerSpec{ + Host: "cafe.example.com", + Upstreams: []conf_v1.Upstream{ + { + Name: "tea-v1", + Service: "tea-svc-v1", + Port: 80, + }, + { + Name: "tea-v2", + Service: "tea-svc-v2", + Port: 80, + }, + }, + Routes: []conf_v1.Route{ + { + Path: "/tea", + Matches: []conf_v1.Match{ + { + Conditions: []conf_v1.Condition{ + { + Header: "x-version", + Value: "v2", + }, + }, + Action: &conf_v1.Action{ + Pass: "tea-v2", + }, + }, + }, + Action: &conf_v1.Action{ + Pass: "tea-v1", + }, + }, + { + Path: "/coffee", + Route: "default/coffee", + }, + }, + }, + }, + Endpoints: map[string][]string{ + "default/tea-svc-v1:80": { + "10.0.0.20:80", + }, + "default/tea-svc-v2:80": { + "10.0.0.21:80", + }, + "default/coffee-svc-v1:80": { + "10.0.0.30:80", + }, + "default/coffee-svc-v2:80": { + "10.0.0.31:80", + }, + }, + VirtualServerRoutes: []*conf_v1.VirtualServerRoute{ + { + ObjectMeta: meta_v1.ObjectMeta{ + Name: "coffee", + Namespace: "default", + }, + Spec: conf_v1.VirtualServerRouteSpec{ + Host: "cafe.example.com", + Upstreams: []conf_v1.Upstream{ + { + Name: "coffee-v1", + Service: "coffee-svc-v1", + Port: 80, + }, + { + Name: "coffee-v2", + Service: "coffee-svc-v2", + Port: 80, + }, + }, + Subroutes: []conf_v1.Route{ + { + Path: "/coffee", + Matches: []conf_v1.Match{ + { + Conditions: []conf_v1.Condition{ + { + Argument: "version", + Value: "v2", + }, + }, + Action: &conf_v1.Action{ + Pass: "coffee-v2", + }, + }, + }, + Action: &conf_v1.Action{ + Pass: "coffee-v1", + }, + }, + }, + }, + }, + }, + } +} + +func BenchmarkAddOrUpdateVirtualServer(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + virtualServerEx := vsExWithEndpoints() + + b.ResetTimer() + for range b.N { + _, err := cnf.AddOrUpdateVirtualServer(&virtualServerEx) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkAddOrUpdateVirtualServerWithSplits(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + virtualServerEx := vsExWithSplits() + + b.ResetTimer() + for range b.N { + _, err := cnf.AddOrUpdateVirtualServer(&virtualServerEx) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkAddOrUpdateVirtualServerWithMatches(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + virtualServerEx := vsExWithMatches() + + b.ResetTimer() + for range b.N { + _, err := cnf.AddOrUpdateVirtualServer(&virtualServerEx) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkAddOrUpdateTransportServer(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + transportServerEx := tsEx() + transportServerEx.ListenerPort = 2020 + transportServerEx.Endpoints = map[string][]string{ + "default/tcp-app-svc:5001": { + "10.0.0.20:5001", + }, + } + + b.ResetTimer() + for range b.N { + _, err := cnf.AddOrUpdateTransportServer(&transportServerEx) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkGenerateVirtualServerConfig(b *testing.B) { + virtualServerEx := vsExWithEndpoints() + cfgParams := &ConfigParams{ + Context: context.Background(), + } + staticParams := &StaticConfigParams{} + vsc := newVirtualServerConfigurator(cfgParams, false, false, staticParams, false, nil) + + b.ResetTimer() + for range b.N { + vsc.GenerateVirtualServerConfig(&virtualServerEx, nil, nil) + } +} + +func BenchmarkGenerateVirtualServerConfigWithSplits(b *testing.B) { + virtualServerEx := vsExWithSplits() + cfgParams := &ConfigParams{ + Context: context.Background(), + } + staticParams := &StaticConfigParams{} + vsc := newVirtualServerConfigurator(cfgParams, false, false, staticParams, false, nil) + + b.ResetTimer() + for range b.N { + vsc.GenerateVirtualServerConfig(&virtualServerEx, nil, nil) + } +} + +func BenchmarkGenerateVirtualServerConfigWithMatches(b *testing.B) { + virtualServerEx := vsExWithMatches() + cfgParams := &ConfigParams{ + Context: context.Background(), + } + staticParams := &StaticConfigParams{} + vsc := newVirtualServerConfigurator(cfgParams, false, false, staticParams, false, nil) + + b.ResetTimer() + for range b.N { + vsc.GenerateVirtualServerConfig(&virtualServerEx, nil, nil) + } +} + +func BenchmarkGenerateTransportServerConfig(b *testing.B) { + transportServerEx := tsEx() + transportServerEx.ListenerPort = 2020 + transportServerEx.Endpoints = map[string][]string{ + "default/tcp-app-svc:5001": { + "10.0.0.20:5001", + }, + } + params := transportServerConfigParams{ + transportServerEx: &transportServerEx, + listenerPort: transportServerEx.ListenerPort, + isPlus: false, + } + + b.ResetTimer() + for range b.N { + generateTransportServerConfig(params) + } +} + +func BenchmarkUpdateEndpointsForVirtualServers(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + virtualServerEx := vsExWithEndpoints() + + // Initial add so the VS exists for endpoint updates. + if _, err := cnf.AddOrUpdateVirtualServer(&virtualServerEx); err != nil { + b.Fatal(err) + } + + b.ResetTimer() + for range b.N { + _, err := cnf.UpdateEndpointsForVirtualServers([]*VirtualServerEx{&virtualServerEx}) + if err != nil { + b.Fatal(err) + } + } +} From 4a466bd441a8b46825a68d44b21d92db99fdacc9 Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Fri, 19 Jun 2026 17:47:22 +0100 Subject: [PATCH 3/6] add missing doc --- .../profiling/nginx-ingress-profiling.yaml | 124 ++++++++++++++++++ 1 file changed, 124 insertions(+) create mode 100644 deployments/profiling/nginx-ingress-profiling.yaml diff --git a/deployments/profiling/nginx-ingress-profiling.yaml b/deployments/profiling/nginx-ingress-profiling.yaml new file mode 100644 index 0000000000..f1da412f92 --- /dev/null +++ b/deployments/profiling/nginx-ingress-profiling.yaml @@ -0,0 +1,124 @@ +################################################################################################## +# Profiling deployment for NGINX Ingress Controller +# +# Deploys NIC built with the `debug` build tag, which starts a pprof HTTP server on :6060. +# Delve is also available at /dlv for interactive debugging via kubectl exec. +# +# Usage: +# make build-debug +# make debian-image-profiling TAG=profiling +# kind load docker-image nginx/nginx-ingress:profiling # or minikube image load +# kubectl apply -f deploy/crds.yaml +# kubectl apply -f deployments/common/ns-and-sa.yaml +# kubectl apply -f deployments/rbac/rbac.yaml +# kubectl apply -f deployments/common/nginx-config.yaml +# kubectl apply -f deployments/common/ingress-class.yaml +# kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml +# +# Access pprof: +# kubectl port-forward -n nginx-ingress deploy/nginx-ingress 6060:6060 +# go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30 +# go tool pprof http://localhost:6060/debug/pprof/heap +# curl http://localhost:6060/debug/pprof/goroutine?debug=2 +################################################################################################## +apiVersion: apps/v1 +kind: Deployment +metadata: + name: nginx-ingress + namespace: nginx-ingress +spec: + replicas: 1 + selector: + matchLabels: + app: nginx-ingress + template: + metadata: + labels: + app: nginx-ingress + app.kubernetes.io/name: nginx-ingress + spec: + serviceAccountName: nginx-ingress + automountServiceAccountToken: true + securityContext: + seccompProfile: + type: RuntimeDefault + containers: + - image: nginx/nginx-ingress:profiling + imagePullPolicy: IfNotPresent + name: nginx-ingress + ports: + - name: http + containerPort: 80 + - name: https + containerPort: 443 + - name: readiness-port + containerPort: 8081 + - name: prometheus + containerPort: 9113 + - name: pprof + containerPort: 6060 + readinessProbe: + httpGet: + path: /nginx-ready + port: readiness-port + periodSeconds: 1 + resources: + requests: + cpu: "100m" + memory: "128Mi" + securityContext: + allowPrivilegeEscalation: false + runAsUser: 101 #nginx + runAsNonRoot: true + capabilities: + drop: + - ALL + add: + - NET_BIND_SERVICE + env: + - name: POD_NAMESPACE + valueFrom: + fieldRef: + fieldPath: metadata.namespace + - name: POD_NAME + valueFrom: + fieldRef: + fieldPath: metadata.name + args: + - -nginx-configmaps=$(POD_NAMESPACE)/nginx-config + - -report-ingress-status + - -external-service=nginx-ingress +--- +apiVersion: v1 +kind: Service +metadata: + name: nginx-ingress-pprof + namespace: nginx-ingress +spec: + type: NodePort + ports: + - port: 6060 + targetPort: 6060 + protocol: TCP + name: pprof + selector: + app: nginx-ingress +--- +apiVersion: v1 +kind: Service +metadata: + name: nginx-ingress + namespace: nginx-ingress +spec: + type: NodePort + ports: + - port: 80 + targetPort: 80 + protocol: TCP + name: http + - port: 443 + targetPort: 443 + protocol: TCP + name: https + selector: + app: nginx-ingress From 531221478a7c9da770af34cb4915e4da80d82976 Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Fri, 19 Jun 2026 18:05:11 +0100 Subject: [PATCH 4/6] update references --- deployments/profiling/nginx-ingress-profiling.yaml | 2 +- docs/developer/profiling.md | 6 +++--- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/deployments/profiling/nginx-ingress-profiling.yaml b/deployments/profiling/nginx-ingress-profiling.yaml index f1da412f92..cd9408cdf0 100644 --- a/deployments/profiling/nginx-ingress-profiling.yaml +++ b/deployments/profiling/nginx-ingress-profiling.yaml @@ -13,7 +13,7 @@ # kubectl apply -f deployments/rbac/rbac.yaml # kubectl apply -f deployments/common/nginx-config.yaml # kubectl apply -f deployments/common/ingress-class.yaml -# kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml +# kubectl apply -f deployments/profiling/nginx-ingress-profiling.yaml # # Access pprof: # kubectl port-forward -n nginx-ingress deploy/nginx-ingress 6060:6060 diff --git a/docs/developer/profiling.md b/docs/developer/profiling.md index e4a8ecef62..da99a3db21 100644 --- a/docs/developer/profiling.md +++ b/docs/developer/profiling.md @@ -63,7 +63,7 @@ kubectl apply -f deployments/common/nginx-config.yaml kubectl apply -f deployments/common/ingress-class.yaml # 6. Deploy NIC with pprof exposed -kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml +kubectl apply -f deployments/profiling/nginx-ingress-profiling.yaml # 7. Forward the pprof port kubectl port-forward -n nginx-ingress deploy/nginx-ingress 6060:6060 @@ -107,7 +107,7 @@ Note: this image uses `/dlv` as its entrypoint (Delve debugger), not `/nginx-ing ### Using the provided manifest -A ready-to-use manifest is provided at `deployments/debug/nginx-ingress-profiling.yaml`. It contains: +A ready-to-use manifest is provided at `deployments/profiling/nginx-ingress-profiling.yaml`. It contains: - A **Deployment** identical to the standard one, with an additional `pprof` container port (6060) - A **NodePort Service** (`nginx-ingress-pprof`) exposing port 6060 for pprof @@ -122,7 +122,7 @@ kubectl apply -f deployments/common/nginx-config.yaml kubectl apply -f deployments/common/ingress-class.yaml # Deploy the profiling variant -kubectl apply -f deployments/debug/nginx-ingress-profiling.yaml +kubectl apply -f deployments/profiling/nginx-ingress-profiling.yaml ``` Verify the pod is running and pprof is active: From fa00124e2aea6e2fd77dff1c4c0b9e2b4c1b522e Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Tue, 11 Aug 2026 11:02:26 +0100 Subject: [PATCH 5/6] improve benchmark coverage --- .../profiling/nginx-ingress-profiling.yaml | 2 +- docs/developer/profiling.md | 254 +++++++++++- .../configs/configurator_bench_peak_test.go | 377 ++++++++++++++++++ .../configs/version2/templates_bench_test.go | 51 +++ 4 files changed, 682 insertions(+), 2 deletions(-) create mode 100644 internal/configs/configurator_bench_peak_test.go create mode 100644 internal/configs/version2/templates_bench_test.go diff --git a/deployments/profiling/nginx-ingress-profiling.yaml b/deployments/profiling/nginx-ingress-profiling.yaml index cd9408cdf0..8780a04fbc 100644 --- a/deployments/profiling/nginx-ingress-profiling.yaml +++ b/deployments/profiling/nginx-ingress-profiling.yaml @@ -43,7 +43,7 @@ spec: seccompProfile: type: RuntimeDefault containers: - - image: nginx/nginx-ingress:profiling + - image: localhost:5000/local/nic:profiling imagePullPolicy: IfNotPresent name: nginx-ingress ports: diff --git a/docs/developer/profiling.md b/docs/developer/profiling.md index da99a3db21..a6e608f4a0 100644 --- a/docs/developer/profiling.md +++ b/docs/developer/profiling.md @@ -19,6 +19,14 @@ This guide covers how to build, deploy, and profile NGINX Ingress Controller usi - [Verb classification](#verb-classification) - [What is tracked](#what-is-tracked) - [Implementation](#implementation) +- [Benchmarking](#benchmarking) + - [Benchmark coverage](#benchmark-coverage) + - [Running benchmarks](#running-benchmarks) + - [Per-test profiling with hack/profile.sh](#per-test-profiling-with-hackprofilesh) + - [Tracking memory and CPU spikes](#tracking-memory-and-cpu-spikes) + - [Scaled benchmarks](#scaled-benchmarks) + - [Burst simulation](#burst-simulation) + - [Regression tracking with benchstat](#regression-tracking-with-benchstat) - [Collecting profiles](#collecting-profiles) - [Function call frequency (CPU profile)](#function-call-frequency-cpu-profile) - [Goroutine analysis](#goroutine-analysis) @@ -184,7 +192,7 @@ Access pprof at `http://:/debug/pprof/`. ## K8s API call tracking -The debug build includes a custom HTTP transport wrapper that records **every Kubernetes API call** NIC makes. It tracks per-verb, per-resource call counts, error counts, and latency statistics. This is the most direct way to answer "how often are we calling the K8s API, and for what?" +The debug build includes a custom HTTP transport wrapper that records **every Kubernetes API call** NIC makes. It tracks per-verb, per-resource call counts, error counts, and latency statistics. Served on the same `:6060` port at `/debug/api-stats`. @@ -294,6 +302,250 @@ The tracking is implemented in `cmd/nginx-ingress/debug_transport.go` (only comp In release builds, `wrapTransportWithDebugTracking()` is a no-op (see `debug_transport_release.go`). +## Benchmarking + +Go benchmarks measure config generation performance and track allocation regressions. They live in +`*_bench_test.go` files alongside the unit tests and run with the standard `go test -bench` tooling. + +### Benchmark coverage + +| File | What it benchmarks | +| --- | --- | +| `internal/configs/configurator_bench_test.go` | **Full-path** (config struct + template + file write): Ingress, mergeable Ingress, VirtualServer (base/splits/matches), TransportServer, endpoint updates. **Config-struct-only**: `GenerateVirtualServerConfig` (base/splits/matches), `GenerateTransportServerConfig`. **Other**: annotation parsing, metrics label computation. | +| `internal/configs/version2/templates_bench_test.go` | **Template execution only** (no config generation): VirtualServer Plus, VirtualServer OSS, TransportServer. Isolates `text/template` rendering cost from config struct generation. | +| `internal/configs/configurator_bench_peak_test.go` | **Scaled benchmarks**: config generation and full-path at varying sizes (3-500 upstreams/routes). **Burst simulation**: loading 10-100 VirtualServer configs in sequence (reconciliation storm). All benchmarks report **peak per-iteration** allocation alongside the average via `memTracker`. | + +### Running benchmarks + +```shell +# Run all benchmarks in the configs packages with memory stats +go test -tags=aws,helmunit -bench=. -benchmem -count=1 -run='^$' \ + ./internal/configs/ ./internal/configs/version2/ + +# Run only VirtualServer-related benchmarks +go test -tags=aws,helmunit -bench='VirtualServer' -benchmem -count=1 -run='^$' \ + ./internal/configs/ + +# Run with multiple iterations for statistical significance (required for benchstat) +go test -tags=aws,helmunit -bench='BenchmarkAddOrUpdateVirtualServer$' \ + -benchmem -count=10 -run='^$' ./internal/configs/ + +# Run scaled benchmarks to see how performance changes with config size +go test -tags=aws,helmunit -bench='_Scale' -benchmem -count=1 -run='^$' \ + ./internal/configs/ + +# Run burst simulation +go test -tags=aws,helmunit -bench='Burst' -benchmem -count=1 -run='^$' \ + ./internal/configs/ +``` + +Key flags: + +| Flag | Purpose | +| --- | --- | +| `-bench=` | Run benchmarks matching the pattern (`-bench=.` for all) | +| `-benchmem` | Report B/op and allocs/op alongside ns/op | +| `-count=N` | Repeat each benchmark N times (use 10+ for `benchstat`) | +| `-run='^$'` | Skip unit tests, run only benchmarks | +| `-benchtime=2s` | Run each benchmark for at least 2 seconds (more samples) | +| `-cpuprofile=cpu.prof` | Write CPU profile (only meaningful for single-benchmark runs) | +| `-memprofile=mem.prof` | Write memory profile | + +### Per-test profiling with hack/profile.sh + +The `hack/profile.sh` script runs each benchmark function individually and saves per-function CPU +and memory profile files. This is useful for drilling into a specific benchmark with `go tool pprof`. + +```shell +# Run all benchmarks, save profiles to ./profiles/ +./hack/profile.sh + +# Custom output directory +PROF_DIR=/tmp/profiles ./hack/profile.sh + +# Only benchmark functions (skip Test* functions) +PROF_BENCH_ONLY=1 ./hack/profile.sh + +# Only functions matching a pattern +PROF_PATTERN="VirtualServer" PROF_BENCH_ONLY=1 ./hack/profile.sh + +# Specific package only +PROF_PKG="./internal/configs/..." PROF_BENCH_ONLY=1 ./hack/profile.sh +``` + +There is also a Makefile target: + +```shell +make test-profile +``` + +Output structure: + +``` +profiles/ + internal_configs/ + 001_BenchmarkAddOrUpdateIngress_cpu.prof + 001_BenchmarkAddOrUpdateIngress_mem.prof + 001_BenchmarkAddOrUpdateIngress.log + 002_BenchmarkAddOrUpdateMergeableIngress_cpu.prof + ... + internal_configs_version2/ + 001_BenchmarkExecuteVirtualServerTemplate_cpu.prof + ... +``` + +Analyse a profile: + +```shell +# Interactive pprof shell +go tool pprof profiles/internal_configs/001_BenchmarkAddOrUpdateIngress_cpu.prof + +# Web UI with flame graph +go tool pprof -http=:8080 profiles/internal_configs/001_BenchmarkAddOrUpdateIngress_cpu.prof + +# Show only application code (filter out runtime) +go tool pprof -text profiles/internal_configs/001_BenchmarkAddOrUpdateIngress_cpu.prof \ + | grep 'configs\.\|fmt\.\|version2\.' + +# Memory allocations by function +go tool pprof -alloc_space -text profiles/internal_configs/001_BenchmarkAddOrUpdateIngress_mem.prof \ + | grep 'configs\.' | sort -k5 -rn | head -20 +``` + +### Tracking memory and CPU spikes + +Standard benchmarks report **averages** (`B/op`, `allocs/op`), which smooth out exactly the spikes +you care about during burst config loading. The benchmarks in `configurator_bench_peak_test.go` use +a `memTracker` helper that records `runtime.MemStats` per iteration and reports peak values via +`b.ReportMetric`: + +``` +BenchmarkGenerateVirtualServerConfig_Scale/up=100/rt=200 + 919us 665,968 B/op 4,341 allocs/op # standard (averages) + 668,248 peak-B/op 4,353 peak-allocs/op # worst single iteration + 7.180 peak-heap-MB # process heap high-water mark +``` + +How to interpret: + +- **`peak-B/op` vs `avg-B/op`**: A large gap means some iterations allocate significantly more + than others. This indicates spiky allocation patterns that can trigger GC pauses at + unpredictable times. +- **`peak-allocs/op` vs `avg-allocs/op`**: Same for allocation count. High peak alloc counts + cause more GC mark work. +- **`peak-heap-MB`**: Process-wide heap high-water mark during the benchmark. Shows the maximum + memory footprint reached. Compare across config sizes to see if large configs cause + disproportionate heap growth. + +The `memTracker` adds ~1-5% overhead from `runtime.ReadMemStats` per iteration, which is acceptable +for operations taking >50us. It should not be used on micro-benchmarks (<10us/op) where the +overhead would dominate. + +### Scaled benchmarks + +Benchmarks with the `_Scale` suffix run the same operation at multiple config sizes to reveal +scaling characteristics. This answers: "does a 100-upstream VirtualServer cost 33x more than a +3-upstream one, or is there super-linear growth?" + +```shell +go test -tags=aws,helmunit -bench='_Scale' -benchmem -count=1 -run='^$' ./internal/configs/ +``` + +Example output for `BenchmarkGenerateVirtualServerConfig_Scale`: + +| Scale | ns/op | B/op | allocs/op | peak-B/op | peak-heap-MB | +| --- | ---: | ---: | ---: | ---: | ---: | +| up=3/rt=6 | 106K | 19.5K | 149 | 21.6K | 5.8 | +| up=10/rt=20 | 189K | 76.6K | 457 | 78.8K | 6.1 | +| up=50/rt=100 | 539K | 331K | 2,186 | 334K | 6.4 | +| up=100/rt=200 | 919K | 666K | 4,341 | 668K | 7.2 | +| up=500/rt=500 | 1.86M | 1.73M | 14,551 | 1.73M | 7.5 | + +What to look for: + +- **Linear scaling**: B/op and allocs/op should grow roughly proportionally with upstream/route + count. The table above shows ~linear growth (good). +- **Super-linear spikes**: If B/op grows faster than the config size, there may be quadratic + loops or unbounded slice growth in the generation code. +- **Peak-heap divergence**: If `peak-heap-MB` grows much faster than `B/op`, memory is being + retained across iterations (possible leak or cache growth). + +### Burst simulation + +`BenchmarkVirtualServerBurst` simulates a reconciliation storm: N distinct VirtualServer configs +are generated and written in rapid sequence, as happens during controller startup or a large batch +`kubectl apply`. It reports per-burst aggregate metrics: + +```shell +go test -tags=aws,helmunit -bench='Burst' -benchmem -count=1 -run='^$' ./internal/configs/ +``` + +Example output: + +| Burst size | Time | burst-avg-B/vs | burst-heap-delta-MB | burst-gc-cycles | +| --- | ---: | ---: | ---: | ---: | +| 10 | 1.8ms | 27.4K | 0.1 | 0 | +| 50 | 5.9ms | 27.2K | 1.0 | 0 | +| 100 | 8.3ms | 27.2K | 2.2 | 0 | + +How to interpret: + +- **`burst-avg-B/vs`**: Average bytes allocated per VirtualServer within the burst. Should be + stable regardless of burst size. If it grows with burst size, there is amplification (e.g., + a shared data structure growing with each config added). +- **`burst-heap-delta-MB`**: Heap growth during the burst. Shows how much memory the burst + consumes before GC can reclaim it. Use this to size memory requests for pods that handle + large numbers of VirtualServers. +- **`burst-gc-cycles`**: Number of GC cycles triggered during the burst. A value > 0 means + the burst is generating enough garbage to trigger GC mid-reconcile, which adds latency. + Watch this metric after code changes -- a regression that increases per-VS allocation + can push a previously GC-free burst over the threshold. + +### Regression tracking with benchstat + +To detect performance regressions between code changes, use +[`benchstat`](https://pkg.go.dev/golang.org/x/perf/cmd/benchstat) to compare benchmark runs with +statistical confidence: + +```shell +# Install benchstat (one time) +go install golang.org/x/perf/cmd/benchstat@latest + +# Capture baseline (10 runs for statistical significance) +go test -tags=aws,helmunit \ + -bench='BenchmarkAddOrUpdateVirtualServer$|BenchmarkGenerateVirtualServerConfig$' \ + -benchmem -count=10 -run='^$' \ + ./internal/configs/ > before.txt + +# ... make code changes ... + +# Capture after +go test -tags=aws,helmunit \ + -bench='BenchmarkAddOrUpdateVirtualServer$|BenchmarkGenerateVirtualServerConfig$' \ + -benchmem -count=10 -run='^$' \ + ./internal/configs/ > after.txt + +# Compare +benchstat before.txt after.txt +``` + +Example `benchstat` output: + +``` + │ before.txt │ after.txt │ + │ sec/op │ sec/op vs base │ +AddOrUpdateVirtualServer-12 222.0u ± 3% 211.5u ± 2% -4.73% (p=0.001) +GenerateVirtualServerConfig-12 23.40u ± 2% 17.90u ± 1% -23.5% (p=0.000) + + │ before.txt │ after.txt │ + │ B/op │ B/op vs base │ +AddOrUpdateVirtualServer-12 93.64Ki ± 0% 66.15Ki ± 0% -27.7% (p=0.000) +GenerateVirtualServerConfig-12 24.86Ki ± 0% 21.93Ki ± 0% -11.8% (p=0.000) +``` + +A regression is any row where `vs base` shows a statistically significant increase (p < 0.05). +Pay most attention to `B/op` and `allocs/op` -- these directly affect GC pressure under load. + ## Collecting profiles All examples below assume pprof is accessible at `localhost:6060` (via port-forward or otherwise). diff --git a/internal/configs/configurator_bench_peak_test.go b/internal/configs/configurator_bench_peak_test.go new file mode 100644 index 0000000000..d130e4ffa4 --- /dev/null +++ b/internal/configs/configurator_bench_peak_test.go @@ -0,0 +1,377 @@ +package configs + +import ( + "context" + "fmt" + "runtime" + "testing" + + meta_v1 "k8s.io/apimachinery/pkg/apis/meta/v1" + + "github.com/nginx/kubernetes-ingress/internal/configs/version2" + conf_v1 "github.com/nginx/kubernetes-ingress/pkg/apis/configuration/v1" +) + +// --------------------------------------------------------------------------- +// memTracker -- per-iteration peak memory tracking for benchmarks +// --------------------------------------------------------------------------- + +// memTracker records per-iteration allocation deltas via runtime.MemStats and +// reports peak/p99/mean values through b.ReportMetric. It adds ~1-5% overhead +// per iteration from ReadMemStats, which is acceptable for operations >50us. +// +// Usage: +// +// mt := newMemTracker() +// b.ResetTimer() +// for range b.N { +// mt.before() +// // ... operation under test ... +// mt.after() +// } +// b.StopTimer() +// mt.report(b) +type memTracker struct { + iterAllocs []uint64 // bytes allocated per iteration + iterObjs []uint64 // objects allocated per iteration + peakHeap uint64 // max HeapInuse observed + snap runtime.MemStats +} + +func newMemTracker() *memTracker { + return &memTracker{ + iterAllocs: make([]uint64, 0, 1024), + iterObjs: make([]uint64, 0, 1024), + } +} + +func (mt *memTracker) before() { + runtime.ReadMemStats(&mt.snap) +} + +func (mt *memTracker) after() { + var after runtime.MemStats + runtime.ReadMemStats(&after) + + mt.iterAllocs = append(mt.iterAllocs, after.TotalAlloc-mt.snap.TotalAlloc) + mt.iterObjs = append(mt.iterObjs, after.Mallocs-mt.snap.Mallocs) + + if after.HeapInuse > mt.peakHeap { + mt.peakHeap = after.HeapInuse + } +} + +func (mt *memTracker) report(b *testing.B) { + b.Helper() + if len(mt.iterAllocs) == 0 { + return + } + + var maxAlloc, sumAlloc uint64 + var maxObjs, sumObjs uint64 + for i, a := range mt.iterAllocs { + sumAlloc += a + if a > maxAlloc { + maxAlloc = a + } + o := mt.iterObjs[i] + sumObjs += o + if o > maxObjs { + maxObjs = o + } + } + + n := uint64(len(mt.iterAllocs)) + b.ReportMetric(float64(maxAlloc), "peak-B/op") + b.ReportMetric(float64(sumAlloc/n), "avg-B/op") + b.ReportMetric(float64(maxObjs), "peak-allocs/op") + b.ReportMetric(float64(sumObjs/n), "avg-allocs/op") + b.ReportMetric(float64(mt.peakHeap)/(1024*1024), "peak-heap-MB") +} + +// --------------------------------------------------------------------------- +// Scaled VS fixture generator +// --------------------------------------------------------------------------- + +// vsExWithScale creates a VirtualServerEx with the given number of upstreams +// and routes, each with populated endpoints. This simulates configs of varying +// complexity to reveal scaling characteristics. +func vsExWithScale(numUpstreams, numRoutes int) VirtualServerEx { + upstreams := make([]conf_v1.Upstream, 0, numUpstreams) + endpoints := make(map[string][]string, numUpstreams) + + for i := range numUpstreams { + name := fmt.Sprintf("svc-%d", i) + upstreams = append(upstreams, conf_v1.Upstream{ + Name: name, + Service: name + "-svc", + Port: 80, + }) + endpoints[fmt.Sprintf("default/%s-svc:80", name)] = []string{ + fmt.Sprintf("10.0.%d.%d:80", i/256, i%256), + } + } + + routes := make([]conf_v1.Route, 0, numRoutes) + for i := range numRoutes { + upIdx := i % numUpstreams + routes = append(routes, conf_v1.Route{ + Path: fmt.Sprintf("/path-%d", i), + Action: &conf_v1.Action{ + Pass: upstreams[upIdx].Name, + }, + }) + } + + return VirtualServerEx{ + VirtualServer: &conf_v1.VirtualServer{ + ObjectMeta: meta_v1.ObjectMeta{ + Name: "scale-test", + Namespace: "default", + }, + Spec: conf_v1.VirtualServerSpec{ + Host: "scale.example.com", + Upstreams: upstreams, + Routes: routes, + }, + }, + Endpoints: endpoints, + } +} + +// --------------------------------------------------------------------------- +// Scaled benchmarks -- config generation at varying sizes +// --------------------------------------------------------------------------- + +func BenchmarkGenerateVirtualServerConfig_Scale(b *testing.B) { + scales := []struct { + upstreams int + routes int + }{ + {3, 6}, // small (typical) + {10, 20}, // medium + {50, 100}, // large + {100, 200}, // very large + {500, 500}, // extreme + } + + for _, s := range scales { + name := fmt.Sprintf("up=%d/rt=%d", s.upstreams, s.routes) + vsEx := vsExWithScale(s.upstreams, s.routes) + cfgParams := &ConfigParams{Context: context.Background()} + staticParams := &StaticConfigParams{} + + b.Run(name, func(b *testing.B) { + vsc := newVirtualServerConfigurator(cfgParams, false, false, staticParams, false, nil) + mt := newMemTracker() + b.ResetTimer() + for range b.N { + mt.before() + vsc.GenerateVirtualServerConfig(&vsEx, nil, nil) + mt.after() + } + b.StopTimer() + mt.report(b) + }) + } +} + +// --------------------------------------------------------------------------- +// Scaled benchmarks -- full path (config gen + template + file write) +// --------------------------------------------------------------------------- + +func BenchmarkAddOrUpdateVirtualServer_Scale(b *testing.B) { + scales := []struct { + upstreams int + routes int + }{ + {3, 6}, // small (typical) + {10, 20}, // medium + {50, 100}, // large + {100, 200}, // very large + } + + for _, s := range scales { + name := fmt.Sprintf("up=%d/rt=%d", s.upstreams, s.routes) + vsEx := vsExWithScale(s.upstreams, s.routes) + + b.Run(name, func(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + mt := newMemTracker() + b.ResetTimer() + for range b.N { + mt.before() + _, err := cnf.AddOrUpdateVirtualServer(&vsEx) + if err != nil { + b.Fatal(err) + } + mt.after() + } + b.StopTimer() + mt.report(b) + }) + } +} + +// --------------------------------------------------------------------------- +// Burst simulation -- many VS configs loaded in rapid succession +// --------------------------------------------------------------------------- + +// BenchmarkVirtualServerBurst simulates a reconciliation storm: N VirtualServer +// configs are generated and written in sequence (as happens during controller +// startup or a large batch apply). Reports peak heap and per-config allocation +// spikes across the entire burst. +func BenchmarkVirtualServerBurst(b *testing.B) { + burstSizes := []int{10, 50, 100} + + for _, burstSize := range burstSizes { + // Pre-generate distinct VS fixtures. + fixtures := make([]VirtualServerEx, burstSize) + for i := range burstSize { + fixtures[i] = VirtualServerEx{ + VirtualServer: &conf_v1.VirtualServer{ + ObjectMeta: meta_v1.ObjectMeta{ + Name: fmt.Sprintf("vs-%d", i), + Namespace: "default", + }, + Spec: conf_v1.VirtualServerSpec{ + Host: fmt.Sprintf("vs-%d.example.com", i), + Upstreams: []conf_v1.Upstream{ + {Name: "tea", Service: "tea-svc", Port: 80}, + {Name: "coffee", Service: "coffee-svc", Port: 80}, + }, + Routes: []conf_v1.Route{ + {Path: "/tea", Action: &conf_v1.Action{Pass: "tea"}}, + {Path: "/coffee", Action: &conf_v1.Action{Pass: "coffee"}}, + }, + }, + }, + Endpoints: map[string][]string{ + "default/tea-svc:80": {"10.0.0.1:80"}, + "default/coffee-svc:80": {"10.0.0.2:80"}, + }, + } + } + + b.Run(fmt.Sprintf("burst=%d", burstSize), func(b *testing.B) { + cnf, err := createTestConfiguratorBench() + if err != nil { + b.Fatal(err) + } + + b.ResetTimer() + for range b.N { + // Force GC before each burst to get a clean heap baseline. + runtime.GC() + var baseline, peak runtime.MemStats + runtime.ReadMemStats(&baseline) + + // Simulate the burst: load all VS configs in sequence. + for j := range fixtures { + if _, err := cnf.AddOrUpdateVirtualServer(&fixtures[j]); err != nil { + b.Fatal(err) + } + } + + runtime.ReadMemStats(&peak) + b.ReportMetric(float64(peak.TotalAlloc-baseline.TotalAlloc)/float64(burstSize), "burst-avg-B/vs") + b.ReportMetric(float64(peak.HeapInuse-baseline.HeapInuse)/(1024*1024), "burst-heap-delta-MB") + b.ReportMetric(float64(peak.NumGC-baseline.NumGC), "burst-gc-cycles") + } + }) + } +} + +// --------------------------------------------------------------------------- +// Template execution at scale +// --------------------------------------------------------------------------- + +func BenchmarkExecuteVirtualServerTemplate_Scale(b *testing.B) { + scales := []struct { + upstreams int + locations int + }{ + {3, 6}, + {10, 20}, + {50, 100}, + {100, 200}, + } + + for _, s := range scales { + name := fmt.Sprintf("up=%d/loc=%d", s.upstreams, s.locations) + + // Build a version2.VirtualServerConfig directly at the desired scale. + cfg := buildScaledVSConfig(s.upstreams, s.locations) + + b.Run(name, func(b *testing.B) { + executor, err := version2.NewTemplateExecutor( + "version2/nginx-plus.virtualserver.tmpl", + "version2/nginx-plus.transportserver.tmpl", + "version2/oidc.tmpl", + ) + if err != nil { + b.Fatal(err) + } + mt := newMemTracker() + b.ResetTimer() + for range b.N { + mt.before() + _, err := executor.ExecuteVirtualServerTemplate(cfg) + if err != nil { + b.Fatal(err) + } + mt.after() + } + b.StopTimer() + mt.report(b) + }) + } +} + +// buildScaledVSConfig creates a version2.VirtualServerConfig with the given +// number of upstreams and locations for template execution benchmarks. +func buildScaledVSConfig(numUpstreams, numLocations int) *version2.VirtualServerConfig { + upstreams := make([]version2.Upstream, 0, numUpstreams) + for i := range numUpstreams { + upstreams = append(upstreams, version2.Upstream{ + Name: fmt.Sprintf("vs_default_scale_%s", fmt.Sprintf("svc-%d", i)), + Servers: []version2.UpstreamServer{ + {Address: fmt.Sprintf("10.0.%d.%d:80", i/256, i%256)}, + }, + UpstreamLabels: version2.UpstreamLabels{ + Service: fmt.Sprintf("svc-%d", i), + ResourceType: "virtualserver", + ResourceName: "scale-test", + ResourceNamespace: "default", + }, + }) + } + + locations := make([]version2.Location, 0, numLocations) + for i := range numLocations { + upIdx := i % numUpstreams + locations = append(locations, version2.Location{ + Path: fmt.Sprintf("/path-%d", i), + ProxyPass: fmt.Sprintf("http://%s", upstreams[upIdx].Name), + ProxyConnectTimeout: "60s", + ProxyReadTimeout: "60s", + ProxySendTimeout: "60s", + ClientMaxBodySize: "1m", + ProxyNextUpstream: "error timeout", + ProxyNextUpstreamTimeout: "0s", + ProxyPassRequestHeaders: true, + }) + } + + return &version2.VirtualServerConfig{ + Upstreams: upstreams, + Server: version2.Server{ + ServerName: "scale.example.com", + StatusZone: "scale.example.com", + Locations: locations, + }, + } +} diff --git a/internal/configs/version2/templates_bench_test.go b/internal/configs/version2/templates_bench_test.go new file mode 100644 index 0000000000..566be145ae --- /dev/null +++ b/internal/configs/version2/templates_bench_test.go @@ -0,0 +1,51 @@ +package version2 + +import "testing" + +func BenchmarkExecuteVirtualServerTemplate(b *testing.B) { + executor, err := NewTemplateExecutor("nginx-plus.virtualserver.tmpl", "nginx-plus.transportserver.tmpl", "oidc.tmpl") + if err != nil { + b.Fatal(err) + } + cfg := vsConfig() + + b.ResetTimer() + for range b.N { + _, err := executor.ExecuteVirtualServerTemplate(&cfg) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkExecuteVirtualServerTemplateOSS(b *testing.B) { + executor, err := NewTemplateExecutor("nginx.virtualserver.tmpl", "nginx.transportserver.tmpl", "") + if err != nil { + b.Fatal(err) + } + cfg := vsConfig() + + b.ResetTimer() + for range b.N { + _, err := executor.ExecuteVirtualServerTemplate(&cfg) + if err != nil { + b.Fatal(err) + } + } +} + +func BenchmarkExecuteTransportServerTemplate(b *testing.B) { + executor, err := NewTemplateExecutor("nginx-plus.virtualserver.tmpl", "nginx-plus.transportserver.tmpl", "oidc.tmpl") + if err != nil { + b.Fatal(err) + } + cfg := tsConfig() + + b.ResetTimer() + for range b.N { + _, err := executor.ExecuteTransportServerTemplate(&cfg) + if err != nil { + b.Fatal(err) + } + } +} From 3148669137f61229662a458b4c5e4721b71f3b24 Mon Sep 17 00:00:00 2001 From: Sean Breen Date: Wed, 12 Aug 2026 16:37:21 +0100 Subject: [PATCH 6/6] fix(profiling): add nil check in transport wrapper and .PHONY for test-profile --- Makefile | 1 + cmd/nginx-ingress/debug_transport.go | 3 +++ 2 files changed, 4 insertions(+) diff --git a/Makefile b/Makefile index 95581019c1..92a1f47929 100644 --- a/Makefile +++ b/Makefile @@ -110,6 +110,7 @@ govulncheck: ## Run govulncheck linter test: ## Run GoLang tests go test -tags=aws,helmunit -shuffle=on ./... +.PHONY: test-profile test-profile: ## Run GoLang tests with profiling PROF_BENCH_ONLY=0 hack/profile.sh diff --git a/cmd/nginx-ingress/debug_transport.go b/cmd/nginx-ingress/debug_transport.go index 8d510ffed1..c65ac940fc 100644 --- a/cmd/nginx-ingress/debug_transport.go +++ b/cmd/nginx-ingress/debug_transport.go @@ -31,6 +31,9 @@ func init() { // record per-verb, per-resource API call counts and latencies. // In release builds this is a no-op (see debug_transport_release.go). func wrapTransportWithDebugTracking(config *rest.Config) { + if config == nil { + return + } existing := config.WrapTransport config.WrapTransport = func(rt http.RoundTripper) http.RoundTripper { if existing != nil {