Advanced Profiling Techniques

Beyond basic CPU and memory profiling, Go offers several specialized profiling tools for specific performance issues.

Goroutine Profiling

Goroutine profiling helps identify concurrency issues and goroutine leaks:

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
	"runtime"
	"sync"
	"time"
)

// Global WaitGroup that we'll intentionally never finish
var wg sync.WaitGroup

// Function that leaks goroutines
func leakGoroutines() {
	fmt.Println("Starting to leak goroutines...")
	
	// Leak goroutines by never calling wg.Done()
	for i := 0; i < 10000; i++ {
		wg.Add(1)
		go func(id int) {
			// This goroutine will never exit because we never call wg.Done()
			fmt.Printf("Goroutine %d is leaked\n", id)
			time.Sleep(1 * time.Hour) // Sleep for a long time
			// wg.Done() is never called
		}(i)
		
		// Print stats every 1000 goroutines
		if i > 0 && i%1000 == 0 {
			fmt.Printf("Created %d goroutines, total: %d\n", i, runtime.NumGoroutine())
			time.Sleep(100 * time.Millisecond)
		}
	}
}

// Function that demonstrates proper goroutine management
func properGoroutineManagement() {
	fmt.Println("Demonstrating proper goroutine management...")
	
	var localWg sync.WaitGroup
	
	// Create goroutines with proper cleanup
	for i := 0; i < 10000; i++ {
		localWg.Add(1)
		go func(id int) {
			defer localWg.Done() // Ensure we always mark as done
			
			// Do some work
			time.Sleep(10 * time.Millisecond)
		}(i)
		
		// Print stats every 1000 goroutines
		if i > 0 && i%1000 == 0 {
			fmt.Printf("Created %d goroutines, total: %d\n", i, runtime.NumGoroutine())
		}
	}
	
	// Wait for all goroutines to finish
	fmt.Println("Waiting for all goroutines to finish...")
	localWg.Wait()
	fmt.Printf("All goroutines finished, remaining: %d\n", runtime.NumGoroutine())
}

// Function that demonstrates goroutine blocking
func demonstrateGoroutineBlocking() {
	fmt.Println("Demonstrating goroutine blocking...")
	
	// Create a channel without a buffer
	ch := make(chan int)
	
	// Start goroutines that will block on the channel
	for i := 0; i < 100; i++ {
		go func(id int) {
			fmt.Printf("Goroutine %d waiting to send...\n", id)
			ch <- id // This will block until someone receives
			fmt.Printf("Goroutine %d sent value\n", id)
		}(i)
	}
	
	// Let goroutines block for a while
	time.Sleep(1 * time.Second)
	fmt.Printf("After blocking: %d goroutines\n", runtime.NumGoroutine())
	
	// Receive from some goroutines to unblock them
	for i := 0; i < 10; i++ {
		fmt.Printf("Received: %d\n", <-ch)
	}
	
	fmt.Printf("After receiving 10 values: %d goroutines\n", runtime.NumGoroutine())
}

func main() {
	// Start pprof server
	go func() {
		fmt.Println("Starting pprof server on :8080")
		http.ListenAndServe(":8080", nil)
	}()
	
	// Wait for pprof server to start
	time.Sleep(100 * time.Millisecond)
	
	// Print initial goroutine count
	fmt.Printf("Initial goroutine count: %d\n", runtime.NumGoroutine())
	
	// Demonstrate proper goroutine management
	properGoroutineManagement()
	
	// Demonstrate goroutine blocking
	demonstrateGoroutineBlocking()
	
	// Leak goroutines (comment out to avoid actual leaking)
	// leakGoroutines()
	
	fmt.Println("\nTo analyze goroutines:")
	fmt.Println("1. View goroutine profile: go tool pprof http://localhost:8080/debug/pprof/goroutine")
	fmt.Println("2. Get text listing: curl http://localhost:8080/debug/pprof/goroutine?debug=1")
	fmt.Println("3. View full goroutine stack traces: curl http://localhost:8080/debug/pprof/goroutine?debug=2")
	
	// Keep the program running to allow pprof access
	fmt.Println("\nPress Ctrl+C to exit")
	select {}
}

Mutex Profiling

Mutex profiling helps identify lock contention issues:

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
	"runtime"
	"sync"
	"time"
)

// Global mutex for demonstration
var globalMutex sync.Mutex

// Counter protected by mutex
var counter int

// Function with high mutex contention
func highContentionFunction() {
	var wg sync.WaitGroup
	
	// Enable mutex profiling
	runtime.SetMutexProfileFraction(5) // 1/5 of mutex events are sampled
	
	fmt.Println("Running high contention scenario...")
	
	// Create many goroutines that all try to access the same mutex
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func() {
			defer wg.Done()
			
			// Each goroutine acquires and releases the mutex 1000 times
			for j := 0; j < 1000; j++ {
				globalMutex.Lock()
				counter++
				globalMutex.Unlock()
			}
		}()
	}
	
	wg.Wait()
	fmt.Printf("High contention counter: %d\n", counter)
}

// Function with optimized locking strategy
func lowContentionFunction() {
	var wg sync.WaitGroup
	counter = 0
	
	fmt.Println("Running low contention scenario...")
	
	// Create many goroutines with local counters
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func() {
			defer wg.Done()
			
			// Each goroutine maintains its own counter
			localCounter := 0
			for j := 0; j < 1000; j++ {
				localCounter++
			}
			
			// Only lock once at the end to update the global counter
			globalMutex.Lock()
			counter += localCounter
			globalMutex.Unlock()
		}()
	}
	
	wg.Wait()
	fmt.Printf("Low contention counter: %d\n", counter)
}

// Function demonstrating read-write mutex
func readWriteMutexDemo() {
	var rwMutex sync.RWMutex
	var data = make(map[int]int)
	counter = 0
	
	var wg sync.WaitGroup
	
	fmt.Println("Running read-write mutex scenario...")
	
	// Start writer goroutines (fewer)
	for i := 0; i < 5; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			
			// Writers need exclusive access
			for j := 0; j < 100; j++ {
				rwMutex.Lock()
				data[j] = id
				rwMutex.Unlock()
				
				// Simulate some processing time
				time.Sleep(1 * time.Millisecond)
			}
		}(i)
	}
	
	// Start reader goroutines (many more)
	for i := 0; i < 100; i++ {
		wg.Add(1)
		go func() {
			defer wg.Done()
			
			// Readers can access concurrently
			for j := 0; j < 1000; j++ {
				rwMutex.RLock()
				_ = data[j%100]
				rwMutex.RUnlock()
				
				// Count reads
				globalMutex.Lock()
				counter++
				globalMutex.Unlock()
			}
		}()
	}
	
	wg.Wait()
	fmt.Printf("Read-write mutex: %d reads performed\n", counter)
}

func main() {
	// Start pprof server
	go func() {
		fmt.Println("Starting pprof server on :8080")
		http.ListenAndServe(":8080", nil)
	}()
	
	// Wait for pprof server to start
	time.Sleep(100 * time.Millisecond)
	
	// Run high contention scenario
	highContentionFunction()
	
	// Run low contention scenario
	lowContentionFunction()
	
	// Run read-write mutex scenario
	readWriteMutexDemo()
	
	fmt.Println("\nTo analyze mutex contention:")
	fmt.Println("1. View mutex profile: go tool pprof http://localhost:8080/debug/pprof/mutex")
	fmt.Println("2. Get text listing: curl http://localhost:8080/debug/pprof/mutex?debug=1")
	
	// Keep the program running to allow pprof access
	fmt.Println("\nPress Ctrl+C to exit")
	select {}
}

Block Profiling

Block profiling helps identify where goroutines spend time waiting:

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
	"os"
	"runtime"
	"runtime/pprof"
	"sync"
	"time"
)

// Function demonstrating channel blocking
func channelBlockingDemo() {
	fmt.Println("Running channel blocking demo...")
	
	// Create a channel with small buffer
	ch := make(chan int, 5)
	
	var wg sync.WaitGroup
	
	// Producer goroutines
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			
			for j := 0; j < 100; j++ {
				// This will block when the channel is full
				ch <- id*1000 + j
				time.Sleep(1 * time.Millisecond)
			}
		}(i)
	}
	
	// Consumer goroutine - intentionally slow
	wg.Add(1)
	go func() {
		defer wg.Done()
		
		for i := 0; i < 1000; i++ {
			val := <-ch
			fmt.Printf("Received: %d\n", val)
			time.Sleep(5 * time.Millisecond) // Slower than producers
		}
	}()
	
	wg.Wait()
}

// Function demonstrating I/O blocking
func ioBlockingDemo() {
	fmt.Println("Running I/O blocking demo...")
	
	var wg sync.WaitGroup
	
	// Create temporary files
	tempFiles := make([]*os.File, 5)
	for i := range tempFiles {
		file, err := os.CreateTemp("", "block-profile-demo")
		if err != nil {
			fmt.Printf("Error creating temp file: %v\n", err)
			continue
		}
		defer os.Remove(file.Name())
		defer file.Close()
		tempFiles[i] = file
	}
	
	// Goroutines performing file I/O
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			
			// Choose a file
			fileIndex := id % len(tempFiles)
			file := tempFiles[fileIndex]
			
			// Write data to file (may block)
			data := make([]byte, 1024*1024) // 1MB
			for j := range data {
				data[j] = byte(id)
			}
			
			for j := 0; j < 10; j++ {
				_, err := file.Write(data)
				if err != nil {
					fmt.Printf("Error writing to file: %v\n", err)
				}
				
				// Sync to disk (will block)
				file.Sync()
			}
		}(i)
	}
	
	wg.Wait()
}

// Function demonstrating mutex blocking
func mutexBlockingDemo() {
	fmt.Println("Running mutex blocking demo...")
	
	var mu sync.Mutex
	var wg sync.WaitGroup
	
	// Goroutine that holds the lock for a long time
	wg.Add(1)
	go func() {
		defer wg.Done()
		
		for i := 0; i < 5; i++ {
			mu.Lock()
			fmt.Println("Long operation has the lock")
			time.Sleep(100 * time.Millisecond) // Hold lock for a long time
			mu.Unlock()
			
			// Give other goroutines a chance
			time.Sleep(10 * time.Millisecond)
		}
	}()
	
	// Goroutines that need the lock frequently
	for i := 0; i < 10; i++ {
		wg.Add(1)
		go func(id int) {
			defer wg.Done()
			
			for j := 0; j < 10; j++ {
				mu.Lock() // Will block waiting for the long operation
				fmt.Printf("Goroutine %d got the lock\n", id)
				time.Sleep(1 * time.Millisecond) // Short operation
				mu.Unlock()
				
				// Do some work without the lock
				time.Sleep(5 * time.Millisecond)
			}
		}(i)
	}
	
	wg.Wait()
}

func main() {
	// Enable block profiling
	runtime.SetBlockProfileRate(1) // Sample every blocking event
	
	// Start pprof server
	go func() {
		fmt.Println("Starting pprof server on :8080")
		http.ListenAndServe(":8080", nil)
	}()
	
	// Wait for pprof server to start
	time.Sleep(100 * time.Millisecond)
	
	// Run demos
	channelBlockingDemo()
	ioBlockingDemo()
	mutexBlockingDemo()
	
	// Save block profile
	f, err := os.Create("block.prof")
	if err != nil {
		fmt.Printf("Error creating profile file: %v\n", err)
	} else {
		pprof.Lookup("block").WriteTo(f, 0)
		f.Close()
		fmt.Println("Block profile written to block.prof")
	}
	
	fmt.Println("\nTo analyze blocking:")
	fmt.Println("1. View block profile: go tool pprof http://localhost:8080/debug/pprof/block")
	fmt.Println("2. Analyze saved profile: go tool pprof -http=:8081 block.prof")
	
	// Keep the program running to allow pprof access
	fmt.Println("\nPress Ctrl+C to exit")
	select {}
}