Skip to content

Profiling #81

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Sachinxmpl merged 4 commits into from
Aug 24, 2026
Merged

Profiling #81

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
7fe2300
http server mounting Go's pprof handlers
Sachinxmpl Aug 24, 2026
8167dcd
wite debug server to server.go
Sachinxmpl Aug 24, 2026
848e9c4
profiling script
Sachinxmpl Aug 24, 2026
ba2284d
docs(profiling): 3 major profiling output + docs
Sachinxmpl Aug 24, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .gitignore
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ bin/
coverage.html
*.prof
coverage.out
!docs/profiles/*.prof

test.go

Expand Down
22 changes: 22 additions & 0 deletions cmd/gobalancer/serve.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ import (

"github.com/Sachinxmpl/gobalancer/internal/balancer"
"github.com/Sachinxmpl/gobalancer/internal/config"
"github.com/Sachinxmpl/gobalancer/internal/debug"
"github.com/Sachinxmpl/gobalancer/internal/health"
"github.com/Sachinxmpl/gobalancer/internal/listener"
"github.com/Sachinxmpl/gobalancer/internal/metrics"
Expand All @@ -34,6 +35,12 @@ func Serve(args []string) error {
"metrics server address",
)

debugAddr := fs.String(
"debug-addr",
"",
"pprof debug server address, e.g. 127.0.0.1:6060 (empty = disabled)",
)

if err := fs.Parse(args); err != nil {
return err
}
Expand Down Expand Up @@ -62,6 +69,15 @@ func Serve(args []string) error {
return err
}

var debugSrv *debug.Server
if *debugAddr != "" {
debugSrv = debug.NewServer(*debugAddr, log)
if err := debugSrv.Start(); err != nil {
log.Error("failed to start debug server", "addr", *debugAddr, "err", err)
return err
}
}

balancer, err := balancer.New(cfg.Balancer, registry)
if err != nil {
log.Error("failed to create balancer", "algorithm", cfg.Balancer, "err", err)
Expand Down Expand Up @@ -138,6 +154,12 @@ func Serve(args []string) error {
log.Warn("Failed to shutdown metrics server", "err", err)
}

if debugSrv != nil {
if err := debugSrv.ShutDown(shutdownCtx); err != nil {
log.Warn("failed to shutdown debug server", "err", err)
}
}

log.Info("stopped")
return nil
}
37 changes: 33 additions & 4 deletions configl7.example.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,10 +1,39 @@
# example configuration file

mode: l7
listen: "127.0.0.1:8080"
listen: "0.0.0.0:8080"

balancer: round_robin

timeouts:
dial: 300ms
read: 30s
write: 30s
idle: 60s
request: 30s
drain: 15s

health:
active:
interval: 2s
timeout: 500ms
rise: 2
passive:
fall: 3
cooldown: 10s

rate_limit:
global_rps: 0
per_client_rps: 0

routes:
- match: { path_prefix: "/" }
pool: default
- match:
path_prefix: "/"
pool: web

pools:
default:
web:
- addr: "127.0.0.1:9001"
weight: 1
- addr: "127.0.0.1:9002"
weight: 1
4 changes: 4 additions & 0 deletions docs/benchmark.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -135,6 +135,10 @@ Both served every request successfully at ~965/s.

**What it proves.** With one sick backend and round-robin balancing, enabling the passive path reduces mean latency from 106 ms to 8.3 ms and p90 from 307 ms to 6.7 ms. With the passive path disabled, round-robin sends approximately one-third of requests to the sick backend; each times out after 300 ms and is retried, so a third of all requests are slow for the entire run. With the passive path enabled, the sick backend is evicted after 3 failures and traffic goes only to the healthy backends. In GoBalancer the passive path is the only mechanism that evicts a backend — the active prober only readmits — so active-only means no eviction at all. The passive+active p999 of 308 ms reflects brief flapping: the active prober's TCP-only probe succeeds against the sick backend (it accepts connections), readmitting it momentarily before the passive path evicts it again.

## Profiling

Where the CPU and memory actually go under load — CPU, heap, and goroutine profiles captured with pprof — is written up separately in [profiling.md](profiling.md). In short: the proxy spends its CPU on network syscalls and scheduling, holds under 4 MB of live memory, and runs the load on less than one core.

## Limitations

All traffic runs on a single machine over loopback. This measures GoBalancer's own overhead — CPU and memory — not real-world network behaviour. On a real network the round-trip time between machines dwarfs the sub-millisecond cost measured here. Read these as "how much does the balancer add," not "how fast is a request in production."
213 changes: 213 additions & 0 deletions docs/profiles/cpu-top.txt
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,213 @@
File: gobalancer
Build ID: 5a6a7a4d1855a0a9b02d6e6cfbb5336c091cea4a
Type: cpu
Time: 2026-08-24 18:48:58 +0545
Duration: 30s, Total samples = 25.77s (85.90%)
Showing nodes accounting for 17.89s, 69.42% of 25.77s total
Dropped 590 nodes (cum <= 0.13s)
flat flat% sum% cum cum%
6.19s 24.02% 24.02% 6.19s 24.02% internal/runtime/syscall/linux.Syscall6
2.44s 9.47% 33.49% 2.44s 9.47% runtime.futex
0.52s 2.02% 35.51% 1.56s 6.05% runtime.stealWork
0.41s 1.59% 37.10% 0.41s 1.59% runtime.nextFreeFast (inline)
0.36s 1.40% 38.49% 0.36s 1.40% runtime.usleep
0.33s 1.28% 39.77% 0.41s 1.59% runtime.lock2
0.31s 1.20% 40.98% 0.31s 1.20% runtime.nanotime (inline)
0.30s 1.16% 42.14% 6.21s 24.10% runtime.findRunnable
0.26s 1.01% 43.15% 0.27s 1.05% runtime.(*mspan).writeHeapBitsSmall
0.23s 0.89% 44.04% 0.23s 0.89% runtime.memclrNoHeapPointers
0.22s 0.85% 44.90% 0.33s 1.28% net/textproto.CanonicalMIMEHeaderKey
0.21s 0.81% 45.71% 0.79s 3.07% runtime.selectgo
0.21s 0.81% 46.53% 0.24s 0.93% runtime.unlock2
0.19s 0.74% 47.26% 0.20s 0.78% runtime.(*timers).wakeTime (inline)
0.19s 0.74% 48.00% 1.71s 6.64% runtime.netpoll
0.16s 0.62% 48.62% 0.16s 0.62% runtime.memmove
0.15s 0.58% 49.20% 0.52s 2.02% runtime.runqgrab
0.15s 0.58% 49.79% 0.15s 0.58% time.runtimeNow
0.14s 0.54% 50.33% 0.14s 0.54% aeshashbody
0.14s 0.54% 50.87% 0.14s 0.54% indexbytebody
0.13s 0.5% 51.38% 1.85s 7.18% runtime.mallocgc
0.12s 0.47% 51.84% 0.13s 0.5% internal/sync.(*Mutex).Lock (inline)
0.12s 0.47% 52.31% 1.10s 4.27% runtime.newobject
0.11s 0.43% 52.74% 0.19s 0.74% internal/runtime/maps.(*Map).getWithoutKeySmallFastStr
0.11s 0.43% 53.16% 1.52s 5.90% runtime.notesleep
0.11s 0.43% 53.59% 0.18s 0.7% runtime.scanObjectsSmall
0.10s 0.39% 53.98% 0.19s 0.74% context.(*cancelCtx).Done
0.10s 0.39% 54.37% 0.22s 0.85% runtime.tryDeferToSpanScan
0.09s 0.35% 54.71% 0.15s 0.58% runtime.casgstatus
0.09s 0.35% 55.06% 0.17s 0.66% runtime.ifaceeq
0.09s 0.35% 55.41% 0.16s 0.62% sync.(*Pool).Get
0.08s 0.31% 55.72% 4.23s 16.41% github.com/Sachinxmpl/gobalancer/internal/proxy/l7.(*Server).forwardOnce
0.08s 0.31% 56.03% 2.37s 9.20% net/http.(*conn).readRequest
0.08s 0.31% 56.34% 0.24s 0.93% runtime.(*timer).modify
0.08s 0.31% 56.66% 1.41s 5.47% runtime.mallocgcSmallScanNoHeader
0.08s 0.31% 56.97% 0.33s 1.28% runtime.mapaccess1_faststr
0.07s 0.27% 57.24% 1.81s 7.02% internal/poll.(*FD).Read
0.07s 0.27% 57.51% 1.74s 6.75% net/http.(*Transport).roundTrip
0.07s 0.27% 57.78% 1.38s 5.36% net/http.readRequest
0.07s 0.27% 58.05% 0.24s 0.93% net/textproto.canonicalMIMEHeaderKey
0.07s 0.27% 58.32% 0.17s 0.66% runtime.pidleget
0.07s 0.27% 58.60% 0.21s 0.81% runtime.scanblock
0.06s 0.23% 58.83% 1.82s 7.06% bufio.(*Reader).Peek
0.06s 0.23% 59.06% 0.60s 2.33% internal/poll.runtime_pollSetDeadline
0.06s 0.23% 59.29% 1.06s 4.11% net/textproto.readMIMEHeader
0.06s 0.23% 59.53% 0.46s 1.79% runtime.mapassign_faststr
0.05s 0.19% 59.72% 0.64s 2.48% io.copyBuffer
0.05s 0.19% 59.91% 0.30s 1.16% net/http.(*Transport).queueForIdleConn
0.05s 0.19% 60.11% 11.76s 45.63% net/http.(*conn).serve
0.05s 0.19% 60.30% 2.53s 9.82% net/http.(*persistConn).readLoop
0.05s 0.19% 60.50% 0.30s 1.16% net/http.(*persistConn).readLoop.func4
0.05s 0.19% 60.69% 0.75s 2.91% net/http.(*persistConn).roundTrip
0.05s 0.19% 60.88% 0.14s 0.54% net/http.Header.sortedKeyValues
0.05s 0.19% 61.08% 0.33s 1.28% net/http.Header.writeSubset
0.05s 0.19% 61.27% 1.44s 5.59% runtime.futexsleep
0.05s 0.19% 61.47% 0.19s 0.74% runtime.makechan
0.05s 0.19% 61.66% 0.19s 0.74% runtime.makeslice
0.05s 0.19% 61.85% 6.68s 25.92% runtime.park_m
0.05s 0.19% 62.05% 0.13s 0.5% runtime.scanObject
0.05s 0.19% 62.24% 6.60s 25.61% runtime.schedule
0.04s 0.16% 62.40% 1.76s 6.83% bufio.(*Reader).fill
0.04s 0.16% 62.55% 0.23s 0.89% context.(*cancelCtx).cancel
0.04s 0.16% 62.71% 0.42s 1.63% context.WithDeadlineCause
0.04s 0.16% 62.86% 0.13s 0.5% context.parentCancelCtx
0.04s 0.16% 63.02% 0.16s 0.62% fmt.(*pp).doPrintf
0.04s 0.16% 63.17% 4.48s 17.38% github.com/Sachinxmpl/gobalancer/internal/proxy/l7.(*Server).ServeHTTP
0.04s 0.16% 63.33% 0.39s 1.51% io.(*LimitedReader).Read
0.04s 0.16% 63.48% 1.90s 7.37% net.(*conn).Read
0.04s 0.16% 63.64% 2.98s 11.56% net/http.(*persistConn).writeLoop
0.04s 0.16% 63.80% 0.21s 0.81% net/http.readTransfer
0.04s 0.16% 63.95% 0.42s 1.63% runtime.(*timers).check
0.04s 0.16% 64.11% 0.38s 1.47% runtime.markroot
0.04s 0.16% 64.26% 0.56s 2.17% runtime.runqsteal
0.03s 0.12% 64.38% 4.41s 17.11% bufio.(*Writer).Flush
0.03s 0.12% 64.49% 0.22s 0.85% github.com/Sachinxmpl/gobalancer/internal/proxy/l7.copyHeader
0.03s 0.12% 64.61% 0.13s 0.5% internal/poll.(*pollDesc).wait
0.03s 0.12% 64.73% 0.23s 0.89% internal/runtime/maps.(*Map).Delete
0.03s 0.12% 64.84% 1.45s 5.63% internal/runtime/syscall/linux.EpollWait
0.03s 0.12% 64.96% 0.23s 0.89% net/http.(*Request).Clone
0.03s 0.12% 65.08% 2.86s 11.10% net/http.(*response).finishRequest
0.03s 0.12% 65.19% 0.28s 1.09% net/http.Header.Clone (inline)
0.03s 0.12% 65.31% 2.03s 7.88% net/http.checkConnErrorWriter.Write
0.03s 0.12% 65.42% 0.30s 1.16% net/textproto.MIMEHeader.Del (inline)
0.03s 0.12% 65.54% 0.18s 0.7% runtime.mapassign
0.03s 0.12% 65.66% 6.82s 26.46% runtime.mcall
0.03s 0.12% 65.77% 0.20s 0.78% runtime.newproc1
0.03s 0.12% 65.89% 1.61s 6.25% runtime.stopm
0.02s 0.078% 65.97% 0.36s 1.40% context.(*cancelCtx).propagateCancel
0.02s 0.078% 66.05% 0.25s 0.97% github.com/Sachinxmpl/gobalancer/internal/metrics.(*Metrics).RequestObserved
0.02s 0.078% 66.12% 0.13s 0.5% github.com/prometheus/client_golang/prometheus.(*MetricVec).GetMetricWithLabelValues
0.02s 0.078% 66.20% 0.35s 1.36% internal/runtime/maps.(*Map).growToSmall
0.02s 0.078% 66.28% 3.93s 15.25% net.(*netFD).Write
0.02s 0.078% 66.36% 0.24s 0.93% net/http.(*Transport).tryPutIdleConn
0.02s 0.078% 66.43% 0.36s 1.40% net/http.(*bodyEOFSignal).Read
0.02s 0.078% 66.51% 1.05s 4.07% net/http.(*connReader).Read
0.02s 0.078% 66.59% 0.37s 1.44% net/http.(*connReader).backgroundRead
0.02s 0.078% 66.67% 0.57s 2.21% net/http.(*response).ReadFrom
0.02s 0.078% 66.74% 0.76s 2.95% net/http.ReadResponse
0.02s 0.078% 66.82% 1.95s 7.57% net/http.persistConnWriter.Write
0.02s 0.078% 66.90% 0.14s 0.54% net/textproto.(*Reader).readLineSlice
0.02s 0.078% 66.98% 0.40s 1.55% runtime.(*mcache).nextFree
0.02s 0.078% 67.05% 0.44s 1.71% runtime.chansend
0.02s 0.078% 67.13% 0.43s 1.67% runtime.lockWithRank (inline)
0.02s 0.078% 67.21% 0.14s 0.54% runtime.mapIterStart
0.02s 0.078% 67.29% 0.13s 0.5% runtime.mapdelete_faststr
0.02s 0.078% 67.37% 0.32s 1.24% runtime.reentersyscall
0.02s 0.078% 67.44% 0.23s 0.89% runtime.slicebytetostring
0.02s 0.078% 67.52% 0.90s 3.49% runtime.startm
0.02s 0.078% 67.60% 0.14s 0.54% runtime.sweepone
0.02s 0.078% 67.68% 2.70s 10.48% runtime.systemstack
0.02s 0.078% 67.75% 0.26s 1.01% runtime.unlockWithRank (inline)
0.02s 0.078% 67.83% 1.43s 5.55% syscall.Read (inline)
0.02s 0.078% 67.91% 5.22s 20.26% syscall.Syscall
0.02s 0.078% 67.99% 3.84s 14.90% syscall.write
0.01s 0.039% 68.02% 0.13s 0.5% context.WithCancelCause.func1
0.01s 0.039% 68.06% 0.16s 0.62% context.removeChild
0.01s 0.039% 68.10% 0.25s 0.97% context.withCancel (inline)
0.01s 0.039% 68.14% 0.27s 1.05% fmt.Fprintf
0.01s 0.039% 68.18% 0.31s 1.20% github.com/Sachinxmpl/gobalancer/internal/proxy/l7.stripHopByHop
0.01s 0.039% 68.22% 0.13s 0.5% github.com/prometheus/client_golang/prometheus.(*CounterVec).GetMetricWithLabelValues (inline)
0.01s 0.039% 68.26% 0.14s 0.54% github.com/prometheus/client_golang/prometheus.(*CounterVec).WithLabelValues
0.01s 0.039% 68.30% 5.38s 20.88% internal/poll.ignoringEINTRIO (inline)
0.01s 0.039% 68.34% 0.79s 3.07% internal/poll.setDeadlineImpl
0.01s 0.039% 68.37% 0.33s 1.28% internal/runtime/maps.newGroups (inline)
0.01s 0.039% 68.41% 0.32s 1.24% internal/runtime/maps.newarray
0.01s 0.039% 68.45% 1.83s 7.10% net.(*netFD).Read
0.01s 0.039% 68.49% 0.86s 3.34% net/http.(*Request).write
0.01s 0.039% 68.53% 0.47s 1.82% net/http.(*Transport).getConn
0.01s 0.039% 68.57% 0.16s 0.62% net/http.(*Transport).prepareTransportCancel.func1
0.01s 0.039% 68.61% 0.40s 1.55% net/http.(*chunkWriter).writeHeader
0.01s 0.039% 68.65% 0.33s 1.28% net/http.(*connReader).abortPendingRead
0.01s 0.039% 68.68% 0.67s 2.60% net/http.(*persistConn).Read
0.01s 0.039% 68.72% 0.25s 0.97% net/http.(*persistConn).readLoop.func2
0.01s 0.039% 68.76% 4.49s 17.42% net/http.serverHandler.ServeHTTP
0.01s 0.039% 68.80% 1.07s 4.15% net/textproto.(*Reader).ReadMIMEHeader (inline)
0.01s 0.039% 68.84% 0.13s 0.5% net/url.ParseRequestURI
0.01s 0.039% 68.88% 0.35s 1.36% runtime.(*mcache).refill
0.01s 0.039% 68.92% 0.35s 1.36% runtime.entersyscall
0.01s 0.039% 68.96% 0.25s 0.97% runtime.entersyscallWakeSysmon
0.01s 0.039% 68.99% 0.13s 0.5% runtime.funcname (inline)
0.01s 0.039% 69.03% 1.06s 4.11% runtime.futexwakeup
0.01s 0.039% 69.07% 0.73s 2.83% runtime.goready (inline)
0.01s 0.039% 69.11% 0.31s 1.20% runtime.newarray
0.01s 0.039% 69.15% 1.07s 4.15% runtime.notewakeup
0.01s 0.039% 69.19% 0.70s 2.72% runtime.ready
0.01s 0.039% 69.23% 0.55s 2.13% runtime.send.goready.func1
0.01s 0.039% 69.27% 1.05s 4.07% runtime.wakep
0.01s 0.039% 69.31% 4.78s 18.55% syscall.RawSyscall6
0.01s 0.039% 69.34% 1.41s 5.47% syscall.read
0.01s 0.039% 69.38% 0.16s 0.62% time.Now
0.01s 0.039% 69.42% 0.17s 0.66% time.Until
0 0% 69.42% 0.22s 0.85% context.WithCancel
0 0% 69.42% 0.42s 1.63% context.WithDeadline (inline)
0 0% 69.42% 0.42s 1.63% context.WithTimeout
0 0% 69.42% 0.62s 2.41% internal/poll.(*FD).SetReadDeadline (inline)
0 0% 69.42% 0.17s 0.66% internal/poll.(*FD).SetWriteDeadline (inline)
0 0% 69.42% 3.91s 15.17% internal/poll.(*FD).Write
0 0% 69.42% 0.13s 0.5% internal/poll.(*pollDesc).waitRead (inline)
0 0% 69.42% 0.59s 2.29% io.Copy (inline)
0 0% 69.42% 0.52s 2.02% io.CopyBuffer
0 0% 69.42% 0.62s 2.41% net.(*conn).SetReadDeadline
0 0% 69.42% 0.17s 0.66% net.(*conn).SetWriteDeadline
0 0% 69.42% 3.93s 15.25% net.(*conn).Write
0 0% 69.42% 0.62s 2.41% net.(*netFD).SetReadDeadline (inline)
0 0% 69.42% 0.17s 0.66% net.(*netFD).SetWriteDeadline (inline)
0 0% 69.42% 1.74s 6.75% net/http.(*Transport).RoundTrip (inline)
0 0% 69.42% 0.30s 1.16% net/http.(*bodyEOFSignal).condfn (inline)
0 0% 69.42% 0.40s 1.55% net/http.(*chunkWriter).Write
0 0% 69.42% 0.15s 0.58% net/http.(*conn).readRequest.func1
0 0% 69.42% 0.13s 0.5% net/http.(*connLRU).remove (inline)
0 0% 69.42% 0.45s 1.75% net/http.(*connReader).startBackgroundRead
0 0% 69.42% 0.76s 2.95% net/http.(*persistConn).readResponse
0 0% 69.42% 0.15s 0.58% net/http.(*response).WriteHeader
0 0% 69.42% 0.16s 0.62% net/http.Header.Add (inline)
0 0% 69.42% 0.30s 1.16% net/http.Header.Del (inline)
0 0% 69.42% 0.18s 0.7% net/http.Header.WriteSubset (inline)
0 0% 69.42% 0.17s 0.66% net/textproto.(*Reader).ReadLine (inline)
0 0% 69.42% 0.16s 0.62% net/textproto.MIMEHeader.Add (inline)
0 0% 69.42% 0.24s 0.93% runtime.(*mcentral).cacheSpan
0 0% 69.42% 0.17s 0.66% runtime.(*mcentral).grow
0 0% 69.42% 0.13s 0.5% runtime.(*timer).maybeAdd
0 0% 69.42% 0.17s 0.66% runtime.bgsweep
0 0% 69.42% 0.44s 1.71% runtime.chansend1
0 0% 69.42% 0.95s 3.69% runtime.gcBgMarkWorker
0 0% 69.42% 0.83s 3.22% runtime.gcBgMarkWorker.func2
0 0% 69.42% 0.83s 3.22% runtime.gcDrain
0 0% 69.42% 0.48s 1.86% runtime.gcDrainMarkWorkerDedicated (inline)
0 0% 69.42% 0.35s 1.36% runtime.gcDrainMarkWorkerIdle (inline)
0 0% 69.42% 0.27s 1.05% runtime.heapSetTypeNoHeader (inline)
0 0% 69.42% 0.14s 0.54% runtime.isSystemGoroutine
0 0% 69.42% 0.43s 1.67% runtime.lock (inline)
0 0% 69.42% 1.52s 5.90% runtime.mPark (inline)
0 0% 69.42% 0.22s 0.85% runtime.markroot.func1
0 0% 69.42% 0.15s 0.58% runtime.netpollgoready
0 0% 69.42% 0.15s 0.58% runtime.netpollgoready.goready.func1
0 0% 69.42% 0.40s 1.55% runtime.newproc
0 0% 69.42% 0.40s 1.55% runtime.newproc.func1
0 0% 69.42% 0.23s 0.89% runtime.resetspinning
0 0% 69.42% 0.25s 0.97% runtime.scanSpan
0 0% 69.42% 0.13s 0.5% runtime.scanframeworker
0 0% 69.42% 0.20s 0.78% runtime.scanstack
0 0% 69.42% 0.56s 2.17% runtime.send
0 0% 69.42% 0.26s 1.01% runtime.unlock (inline)
0 0% 69.42% 0.13s 0.5% sync.(*Mutex).Lock (inline)
0 0% 69.42% 3.84s 14.90% syscall.Write (inline)
Binary file added docs/profiles/cpu.prof
View file
Open in desktop
Binary file not shown.
Loading
Loading