Golang - pprof

In Go, profiling works through sampling and execution tracing built directly into the runtime. Rather than modifying your compiled code or imposing heavy slowdowns like dynamic instrumentation profilers (e.g., Valgrind), the Go runtime periodically pauses to capture call stacks or monitors internal allocator and lock counters.

Go provides profiling data primarily through two standard library packages and their command-line tool:

• runtime/pprof: Writes execution profiles in the standard pprof protocol format (a protocol buffer).
• net/http/pprof: Exposes runtime profiling data over HTTP endpoints for running services.
• go tool pprof: The CLI and web UI tool used to inspect, visualize, and analyze profile outputs.

Key Profile Types in Go

Go collects several distinct types of performance profiles:

Profile Type	Collection Mechanism	What It Measures
CPU (cpu)	Sampling (100 Hz signal)	Interrupts the program 100 times/sec to inspect execution call stacks and identify hotspots.
Heap / Memory (heap)	Sampling (default: 1 in 512 KB)	Samples memory allocations over time to track active live objects (inuse) or total allocated memory (alloc).
Goroutine (goroutine)	Snapshot (On-demand stack dump)	Scans all active goroutines and aggregates their current execution stacks.
Block (block)	Event Counter	Measures time goroutines spend waiting to send/receive on channels or acquire un-contended locks.
Mutex (mutex)	Event Counter	Measures time goroutines spend waiting on contended sync.Mutex or sync.RWMutex locks.

How Each Mechanism Operates Under the Hood

CPU Profiling (Signal-Based Sampling)

When CPU profiling is enabled via pprof.StartCPUProfile():

1. The Go runtime configures an operating system timer interrupt (using setitimer on Unix systems) that fires 100 times per second (every 10ms).
2. When the OS delivers the signal (SIGPROF), the running thread pauses execution momentarily.
3. The signal handler reads the program counter (PC) of the current thread and unwinds the hardware call stack.
4. It writes this stack trace into an internal ring buffer.
5. A background profile collector goroutine periodically flushes these stacks into the target .pprof output stream.

Memory / Heap Profiling (Sampling Allocator)

Instead of tracking every single allocation (which would cripple runtime performance), Go uses pseudo-random sampling:

• Every time memory is allocated via runtime.mallocgc, an internal allocation counter is updated.
• By default, every time 512 KB of memory is allocated across the application, the allocator captures the stack trace of the allocation site.
• It tracks two dimensions:
  • In-Use Space/Objects: Memory currently held on the heap (useful for finding memory leaks).
  • Allocated Space/Objects: Cumulative memory allocated since startup (useful for finding garbage collection pressure).

Goroutine Profiling (Stop-the-World / Stack Scans)

When you request a goroutine profile, the runtime takes a snapshot of all goroutine stack frames. While modern Go runtimes minimize pause times, obtaining an accurate goroutine profile requires iterating over the runtime's internal global slice of all g (goroutine) structs to inspect their status (e.g., _Grunning, _Gwaiting, _Gsyscall).

Block & Mutex Profiling

Unlike CPU profiling (which uses timer interrupts) or Heap profiling (which samples allocation bytes), Block and Mutex profiling rely on event-based runtime hooks. Both are disabled by default (rates set to 0) because tracking every single lock and wait event adds runtime overhead.

  Block Profile  --> Measures WHAT is waiting (Channel send/recv, select, sync.WaitGroup)
  Mutex Profile  --> Measures WHO is causing the wait (Contention on sync.Mutex / RWMutex)

Block Profiling (Event Duration Sampling)

Block profiling measures how much time goroutines spend waiting for synchronization events to finish.

• Triggers: Channel sends/receives, select statements, sync.WaitGroup, sync.Cond, and lock acquisition waits.
• Collection Mechanism:
  • When a goroutine enters a blocked state (e.g., waiting on an empty channel), the runtime records the start timestamp (nanotime()).
  • When the event unblocks the goroutine, the runtime calculates the elapsed block duration.
  • The runtime compares this duration against the sampling rate set by runtime.SetBlockProfileRate(rate).
  • If the delay duration passes the sampling threshold, the runtime unwinds the goroutine's stack trace and records the blocked time and stack in an internal hash table.
• Key Focus: It shows you the callers that are spending time sitting idle waiting on resources.

Mutex Profiling (Contention Event Sampling)

Mutex profiling specifically targets **lock contention on sync.Mutex and sync.RWMutex**. While the Block profile measures what was waiting, the Mutex profile measures which code held the lock and caused others to wait.

• Triggers: Unlock() operations on contested sync.Mutex or sync.RWMutex primitives.
• Collection Mechanism:
  • When a goroutine attempts to acquire a lock via Lock() and finds it already held, the runtime increments a internal contention counter and logs the wait time.
  • When the lock owner finally calls Unlock(), the runtime calculates the total delay caused to the waiting goroutines.
  • Based on the fraction configured with runtime.SetMutexProfileFraction(rate) (e.g., 1 out of every N contention events), the runtime randomly samples the event.
  • It records the stack trace of the goroutine unlocking the mutex alongside the total wait duration it inflicted on other goroutines.
• Key Focus: It pinpoints hot locks and critical sections in your application that are limiting concurrency and throughput.

In Practice

Here is how to configure and start enablement in code for all 5 profile types (CPU, Heap/Memory, Goroutine, Block, and Mutex) using either standard library instrumentation or HTTP endpoints.

Option 1: Global HTTP Endpoints (net/http/pprof)

The easiest way to enable all 5 profile types across a running application or microservice is to import net/http/pprof. This automatically exposes endpoints under /debug/pprof/ for CPU, Heap, Goroutine, Block, and Mutex data:

package main

import (
	"log"
	"net/http"
	_ "net/http/pprof" // Registers pprof HTTP handlers under /debug/pprof/
	"runtime"
)

func main() {
	// Enable Block profiling (samples wait events longer than 10µs)
	runtime.SetBlockProfileRate(10000)

	// Enable Mutex profiling (samples 1 in every 5 lock contention events)
	runtime.SetMutexProfileFraction(5)

	// Launch dedicated HTTP profiling server on port 6060
	go func() {
		log.Println(http.ListenAndServe("localhost:6060", nil))
	}()

	// Application logic...
	select {}
}

Fetching all 5 profile types over HTTP:

# 1. CPU: 30-second sampling profile
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30

# 2. Heap (Memory): Live object memory profile
go tool pprof http://localhost:6060/debug/pprof/heap

# 3. Goroutine: Active goroutine stack trace dump
go tool pprof http://localhost:6060/debug/pprof/goroutine

# 4. Block: Blocking/wait event profile
go tool pprof http://localhost:6060/debug/pprof/block

# 5. Mutex: Lock contention profile
go tool pprof http://localhost:6060/debug/pprof/mutex

Option 2: Direct Code Instrumentation (runtime/pprof)

If you are building a batch script, CLI tool, or benchmark without an HTTP server, you can manually trigger and write all 5 profile types directly to disk using runtime/pprof and runtime:

package main

import (
	"os"
	"runtime"
	"runtime/pprof"
)

func main() {
	// ------------------------------------------------------------------
	// Setup Sampling Rates (Before runtime operations)
	// ------------------------------------------------------------------
	// Heap: Sample 1 out of every 1MB allocated (default: 512KB)
	runtime.MemProfileRate = 1024 * 1024

	// Block: Log blocking events delayed over 10 microseconds
	runtime.SetBlockProfileRate(10000)

	// Mutex: Sample 20% (1/5) of all mutex contention events
	runtime.SetMutexProfileFraction(5)

	// ------------------------------------------------------------------
	// 1. Start CPU Profiling
	// ------------------------------------------------------------------
	cpuFile, _ := os.Create("cpu.pprof")
	pprof.StartCPUProfile(cpuFile)
	defer pprof.StopCPUProfile() // Flushes buffer and stops timer on exit

	// ... Execute application logic here ...

	// ------------------------------------------------------------------
	// 2. Write Heap (Memory) Profile
	// ------------------------------------------------------------------
	heapFile, _ := os.Create("heap.pprof")
	defer heapFile.Close()
	runtime.GC() // Optional: Force garbage collection to isolate live memory
	pprof.WriteHeapProfile(heapFile)

	// ------------------------------------------------------------------
	// 3. Write Goroutine Profile
	// ------------------------------------------------------------------
	goroutineFile, _ := os.Create("goroutine.pprof")
	defer goroutineFile.Close()
	pprof.Lookup("goroutine").WriteTo(goroutineFile, 0)

	// ------------------------------------------------------------------
	// 4. Write Block Profile
	// ------------------------------------------------------------------
	blockFile, _ := os.Create("block.pprof")
	defer blockFile.Close()
	pprof.Lookup("block").WriteTo(blockFile, 0)

	// ------------------------------------------------------------------
	// 5. Write Mutex Profile
	// ------------------------------------------------------------------
	mutexFile, _ := os.Create("mutex.pprof")
	defer mutexFile.Close()
	pprof.Lookup("mutex").WriteTo(mutexFile, 0)
}

Summary of Enablement Configuration Flags

Profile Type	Runtime Enablement Function	Default Rate	Custom Rate Example
CPU	Managed automatically via pprof.StartCPUProfile()	100 Hz (10ms signal)	Built into StartCPUProfile
Heap	runtime.MemProfileRate	1 sample / 512 KB	runtime.MemProfileRate = 1024 * 1024 (1MB)
Goroutine	None (Snapshot on demand via pprof.Lookup("goroutine"))	N/A	On-demand stack dump
Block	runtime.SetBlockProfileRate(rate)	0 (Disabled)	runtime.SetBlockProfileRate(10000) (10µs threshold)
Mutex	runtime.SetMutexProfileFraction(rate)	0 (Disabled)	runtime.SetMutexProfileFraction(5) (1 in 5 events)

Visualizing and Analyzing Profiles

Once you generate a profile file (e.g., cpu.pprof), you analyze it using go tool pprof:

# Launch interactive web UI with flame graphs and call trees
go tool pprof -http=:8080 cpu.pprof

Key Views in pprof:

• Top: Displays functions consuming the highest cumulative CPU time or memory allocations.
• Flame Graph: A visual chart where horizontal width represents resource consumption and vertical depth shows stack hierarchy.
• Graph View: A directed graph showing function call relationships with node sizes scaled to resource consumption.

 [ main.Worker ] ---> ( 20ms ) ---> [ crypto/sha256.block ]  (Large Box = Hotspot)

Go Profiling (pprof) vs. Execution Tracing (go tool trace)

• Primary Purpose
  • pprof: Measures aggregate resource consumption to identify where your application spends time or allocates memory.
  • go tool trace: Captures microsecond-level runtime events to explain why goroutines are delayed, blocked, or not executing.
• Data Collection Method
  • pprof: Uses statistical sampling (e.g., interrupting the program 100 times per second for CPU profiling or sampling every 512 KB of heap allocations).
  • go tool trace: Uses event recording, logging every significant runtime event (goroutine creation, network I/O, garbage collection, and scheduler events) as it happens.
• Performance & Runtime Overhead
  • pprof: Very lightweight with low overhead (~1–2% for CPU profiles), making it safe for continuous production monitoring.
  • go tool trace: Generates high overhead (15–30% in high-concurrency workloads) and creates massive data files quickly, making it best suited for brief diagnostic bursts.
• Core Metrics & Profile Types
  • pprof: Provides CPU usage, heap memory allocations (live vs. total), goroutine stack dumps, block delays, and mutex contention.
  • go tool trace: Provides timelines of OS thread utilization, scheduler latency, GC pauses, and goroutine state transitions (running, runnable, waiting).
• Primary Visualizations
  • pprof: Analyzed via flame graphs, top-function lists, and call-graph directed trees.
  • go tool trace: Analyzed via an interactive timeline viewer (showing parallel CPU core lanes and goroutine state bars).
• Best Use Cases
  • Use pprof when: High CPU usage occurs, memory leaks or high garbage collection pressure exist, or overall memory allocations need reduction.
  • Use go tool trace when: Latency spikes occur despite low CPU usage, goroutines stall or suffer from scheduler delays, or garbage collection pause timing needs investigation.