pprof is a profiling tool used to analyze performance data for Go programs, helping developers pinpoint CPU, memory, and other bottlenecks. This article provides a detailed step-by-step guide to analyzing a .pprof file, including setup, generating the file, and interpreting the results.

Step 1: Install Necessary Tools

To analyze .pprof files, ensure you have the following tools installed:

1. Go Programming Language:

• Install Go from the official website.
• Verify installation

go version

2. pprof Tool:

• pprof is included with the Go standard library.
• Validate by running:

go tool pprof

3. Graph Visualization Tools (Optional):

• For visualizations, install graphviz:

sudo apt install graphviz   # Ubuntu/Debian
brew install graphviz       # macOS

Step 2: Generate a pprof File

To analyze program performance, you need a .pprof file. If you don’t have it handy for analyzing below is a way to generate generate it:

1. Enable Profiling in Your Code: Add an HTTP server to collect profiling data:

import (
    "net/http"
    _ "net/http/pprof"
)

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()
    // Your application code here
}

This opens profiling at http://localhost:6060.

Or Create a Go Program with Profiling

Save the following Go code to a file named main.go:

package main

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

func simulateWorkload() {
 for i := 0; i < 1000; i++ {
  time.Sleep(10 * time.Millisecond) // Intentional delay
  for j := 0; j < 1000; j++ {
   _ = i * j // Simulated computation
  }
 }
}

func main() {
 // Create a file to store the CPU profile
 cpuFile, err := os.Create("cpu.pprof")
 if err != nil {
  panic(err)
 }
 defer cpuFile.Close()

 // Start CPU profiling
 if err := pprof.StartCPUProfile(cpuFile); err != nil {
  panic(err)
 }
 defer pprof.StopCPUProfile()

 // Simulate workload
 simulateWorkload()
}

2. Run Your Program: Execute the Go application:

go run main.go

3. Collect Profiling Data: Use tools like curl or a browser to download profiling data:

CPU profile (default 30s):

curl -o cpu.pprof http://localhost:6060/debug/pprof/profile

Heap profile

curl -o heap.pprof http://localhost:6060/debug/pprof/heap

Step 3: Analyze the pprof File

Now that you have a .pprof file, analyze it using the pprof tool.

Basic Analysis in CLI

1. Launch pprof:

go tool pprof cpu.pprof

Interactive Commands:

• Top Functions: Display top CPU consumers:

go tool pprof cpu.pprof        
File: main
Type: cpu
Time: Nov 21, 2024 at 7:27pm (IST)
Duration: 10.96s, Total samples = 60ms ( 0.55%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 60ms, 100% of 60ms total
Showing top 10 nodes out of 17
      flat  flat%   sum%        cum   cum%
      30ms 50.00% 50.00%       30ms 50.00%  runtime.pthread_cond_signal
      20ms 33.33% 83.33%       20ms 33.33%  runtime.pthread_cond_wait
      10ms 16.67%   100%       10ms 16.67%  runtime.kevent
         0     0%   100%       30ms 50.00%  runtime.findRunnable
         0     0%   100%       20ms 33.33%  runtime.mPark (inline)
         0     0%   100%       60ms   100%  runtime.mcall
         0     0%   100%       10ms 16.67%  runtime.netpoll
         0     0%   100%       20ms 33.33%  runtime.notesleep
         0     0%   100%       30ms 50.00%  runtime.notewakeup
         0     0%   100%       60ms   100%  runtime.park_m
(pprof) 

Other Options

(pprof) help
  Commands:
    callgrind        Outputs a graph in callgrind format
    comments         Output all profile comments
    disasm           Output assembly listings annotated with samples
    dot              Outputs a graph in DOT format
    eog              Visualize graph through eog
    evince           Visualize graph through evince
    gif              Outputs a graph image in GIF format
    gv               Visualize graph through gv
    kcachegrind      Visualize report in KCachegrind
    list             Output annotated source for functions matching regexp
    pdf              Outputs a graph in PDF format
    peek             Output callers/callees of functions matching regexp
    png              Outputs a graph image in PNG format
    proto            Outputs the profile in compressed protobuf format
    ps               Outputs a graph in PS format
    raw              Outputs a text representation of the raw profile
    svg              Outputs a graph in SVG format
    tags             Outputs all tags in the profile
    text             Outputs top entries in text form
    top              Outputs top entries in text form
    topproto         Outputs top entries in compressed protobuf format
    traces           Outputs all profile samples in text form
    tree             Outputs a text rendering of call graph
    web              Visualize graph through web browser
    weblist          Display annotated source in a web browser
    o/options        List options and their current values
    q/quit/exit/^D   Exit pprof

  Options:
    call_tree        Create a context-sensitive call tree
    compact_labels   Show minimal headers
    divide_by        Ratio to divide all samples before visualization
    drop_negative    Ignore negative differences
    edgefraction     Hide edges below <f>*total
    focus            Restricts to samples going through a node matching regexp
    hide             Skips nodes matching regexp
    ignore           Skips paths going through any nodes matching regexp
    intel_syntax     Show assembly in Intel syntax
    mean             Average sample value over first value (count)
    nodecount        Max number of nodes to show
    nodefraction     Hide nodes below <f>*total
    noinlines        Ignore inlines.
    normalize        Scales profile based on the base profile.
    output           Output filename for file-based outputs
    prune_from       Drops any functions below the matched frame.
    relative_percentages Show percentages relative to focused subgraph
    sample_index     Sample value to report (0-based index or name)
    show             Only show nodes matching regexp
    show_from        Drops functions above the highest matched frame.
    showcolumns      Show column numbers at the source code line level.
    source_path      Search path for source files
    tagfocus         Restricts to samples with tags in range or matched by regexp
    taghide          Skip tags matching this regexp
    tagignore        Discard samples with tags in range or matched by regexp
    tagleaf          Adds pseudo stack frames for labels key/value pairs at the callstack leaf.
    tagroot          Adds pseudo stack frames for labels key/value pairs at the callstack root.
    tagshow          Only consider tags matching this regexp
    trim             Honor nodefraction/edgefraction/nodecount defaults
    trim_path        Path to trim from source paths before search
    unit             Measurement units to display

  Option groups (only set one per group):
    granularity      
      functions        Aggregate at the function level.
      filefunctions    Aggregate at the function level.
      files            Aggregate at the file level.
      lines            Aggregate at the source code line level.
      addresses        Aggregate at the address level.
    sort             
      cum              Sort entries based on cumulative weight
      flat             Sort entries based on own weight
  :   Clear focus/ignore/hide/tagfocus/tagignore

  type "help <cmd|option>" for more information
(pprof) web
(pprof) 

You can use commands in the interactive interface:

• list <function_name>: Displays detailed information about a specific function.
• callgraph: Show relationships between functions
• Generate Report: Export reports to files for further inspection:

go tool pprof -pdf cpu.pprof > cpu_report.pdf

For visualization:

go tool pprof -svg cpu.pprof > cpu.svg
open cpu.svg

Web Interface: Start a web server to interactively explore profiles

go tool pprof -http=:8080 cpu.pprof

Open http://localhost:8080 in a browser.

Analyze in Flame Graph Format

go tool pprof -svg cpu.pprof > cpu_flamegraph.svg
open cpu_flamegraph.svg

Step 4: Interpreting Results

Key Metrics to Look For:

1. CPU Hotspots:

• Functions consuming the most CPU time are listed at the top of top output.
• Focus on optimizing these functions.

2. Memory Usage:

• In heap profiles, check which functions allocate the most memory.
• Look for unnecessary memory allocations or potential leaks.

3. I/O Operations:

• Investigate profiles for disk or network bottlenecks if applicable.

More Troubleshooting Tips

1. top: View Top Resource Consumers

• Displays a list of functions sorted by CPU time (or other metrics, like memory if analyzing heap profiles).

Showing top 10 nodes out of 17
      flat  flat%   sum%        cum   cum%
      30ms 50.00% 50.00%       30ms 50.00%  runtime.pthread_cond_signal
      20ms 33.33% 83.33%       20ms 33.33%  runtime.pthread_cond_wait
      10ms 16.67%   100%       10ms 16.67%  runtime.kevent
         0     0%   100%       30ms 50.00%  runtime.findRunnable
         0     0%   100%       20ms 33.33%  runtime.mPark (inline)
         0     0%   100%       60ms   100%  runtime.mcall
         0     0%   100%       10ms 16.67%  runtime.netpoll
         0     0%   100%       20ms 33.33%  runtime.notesleep
         0     0%   100%       30ms 50.00%  runtime.notewakeup
         0     0%   100%       60ms   100%  runtime.park_m

• Flat%: Time spent directly in the function.
• Cum%: Cumulative time, including time spent in child calls.

2. Identify a function name that looks related to your workload.

(pprof) list runtime.pthread_cond_signal
Total: 60ms
ROUTINE ======================== runtime.pthread_cond_signal in /opt/homebrew/Cellar/go/1.23.0/libexec/src/runtime/sys_darwin.go
      30ms       30ms (flat, cum) 50.00% of Total
         .          .    567:func pthread_cond_signal(c *pthreadcond) int32 {
      30ms       30ms    568:   ret := libcCall(unsafe.Pointer(abi.FuncPCABI0(pthread_cond_signal_trampoline)), unsafe.Pointer(&c))
         .          .    569:   KeepAlive(c)
         .          .    570:   return ret
         .          .    571:}
         .          .    572:func pthread_cond_signal_trampoline()
         .          .    573:
(pprof) 

3. Quit the Interface: Exit pprof anytime by typing: quit

Interpret the Data

Identify Hotspots

• Functions with high Flat% values are hotspots.
• Investigate and optimize these to reduce CPU usage.

Find Inefficient Loops or Operations

Use list to pinpoint specific lines in a function that contribute to high CPU usage.

Look for:

• Inefficient loops.
• Unnecessary allocations.
• Blocking operations like time.Sleep.

Understand Call Relationships

• Use the call graph or flame graph to see how functions interact.
• Optimize parent functions to reduce the cumulative time spent with children.

When analyzing a cpu.pprof file using go tool pprof, Key Parameters to Check

1. Flat vs. Cumulative Time

• Flat Time: Time spent in a specific function (exclusive of child calls).
• Cumulative Time: Total time spent in the function and its children.

Use top and list to compare these metrics and identify:

• Hotspots with high Flat Time: Optimize those functions directly.
• Functions with high Cumulative Time but low Flat Time: Investigate child functions or nested calls.

2. Function Call Hierarchies

• Use callgraph to see how functions interact. Functions higher in the hierarchy with high Cumulative Time may be causing inefficiencies downstream.

3. Garbage Collection (GC) Impact

• Look for runtime.mallocgc or runtime.gcAssistAlloc in the output.
• High time spent here indicates frequent memory allocation and deallocation.
• Solution: Optimize memory usage or reuse objects.

4. Blocking Operations

• Check for functions like time.Sleep, sync.Mutex.Lock, or I/O operations.
• If blocking operations dominate, consider:
• Asynchronous I/O.
• Fine-grained locking or using channels.

Useful Flags for Advanced Profiling

When running go tool pprof, you can use these flags to customize the analysis:

1. Set Sampling Frequency

• Increase sampling granularity for detailed profiles:

go tool pprof -seconds=60 cpu.pprof

2. Filter Results by Threshold

Display only functions consuming more than a certain percentage of CPU:

go tool pprof -nodefraction=0.05 cpu.pprof

3. Compare Profiles

Compare two profiles to identify changes

go tool pprof -diff_base=base.pprof cpu.pprof

4. Focus on Specific Functions

• Highlight paths leading to a specific function

go tool pprof -focus=<function_name> cpu.pprof

5. Exclude Specific Functions

• Exclude low-level runtime functions from analysis:

go tool pprof -ignore=<runtime> cpu.pprof

Step 5: Continuous Profiling for Complex Systems

For ongoing analysis in production, consider tools like:

• Elastic APM: Monitors distributed applications and integrates with pprof.
• Parca: An open-source, continuous profiling solution.

Conclusion

Analyzing files is essential for those who aim to optimize performance. You can effectively pinpoint bottlenecks and enhance application efficiency by using CLI tools, graphical visualizations, and continuous profiling.

Feel Free to Reach Out at Linkedin:

#Elasticsearch #Performance #APM #Go

Related Article : Elastic Universal Profiling (eBPF)