Profiling Go com pprof: encontre gargalos de CPU, memória e goroutine

1. Visão geral

Quando um serviço Go fica lento ou consome muita RAM, adivinhar geralmente leva tempo e é propenso a erros. Go tem a ferramenta pprof na biblioteca padrão. Essa ferramenta te diz exatamente qual função está comendo CPU, onde a memória está sendo alocada e qual goroutine está travada.

Depois de ler este artigo, você vai saber como ativar pprof para um serviço HTTP, coletar profiles de benchmarks e programas CLI, ler resultados com go tool pprof, e comparar dois profiles para validar uma otimização.

2. O que é pprof e quais tipos de profile existem

pprof é composto por duas partes:

  • Lado da coleta: o package runtime/pprof e net/http/pprof na biblioteca padrão. Eles gravam profiles no formato protobuf.
  • Lado da análise: o comando go tool pprof. Este comando lê um arquivo ou URL de profile e exibe os resultados em forma de tabela, código-fonte ou interface web.

Tipos de profile mais comuns:

Profile O que mede Habilitado por padrão?
profile (CPU) Tempo de CPU por função, amostragem 100 vezes/segundo Sim, quando solicitado
heap Memória viva e total alocada Sim
allocs Igual a heap, mas mostra alocações totais por padrão Sim
goroutine Stack trace de todas as goroutines ativas Sim
block Tempo de espera em channels, select, sync.Cond Não
mutex Contenção em sync.Mutex/RWMutex Não
trace Rastreamento de eventos detalhado (use go tool trace) Sim, quando solicitado

3. Ativar pprof para serviço HTTP

A forma mais rápida é fazer import de net/http/pprof pelo efeito colateral. Este package registra handlers /debug/pprof/* no http.DefaultServeMux.

package main

import (
	"log"
	"net/http"
	_ "net/http/pprof" // registra /debug/pprof/* no DefaultServeMux
)

func main() {
	// Servidor pprof separado, escuta apenas em localhost
	go func() {
		log.Println(http.ListenAndServe("localhost:6060", nil))
	}()

	// Servidor da aplicação usa seu próprio mux, não expõe pprof
	appMux := http.NewServeMux()
	appMux.HandleFunc("GET /invoice", invoiceHandler)
	log.Fatal(http.ListenAndServe(":8080", appMux))
}

Alguns pontos a notar:

  • A linha _ "net/http/pprof" apenas registra handlers, você não chama nenhuma função neste package.
  • O servidor pprof passa nil como handler, ou seja, usa DefaultServeMux, que contém os routes pprof.
  • A aplicação principal usa appMux separado, então a porta 8080 não tem /debug/pprof.

Verificação rápida:

curl -s http://localhost:6060/debug/pprof/ | head -n 20

Aviso: Nunca exponha /debug/pprof para a Internet. Este endpoint expõe stack traces e estrutura do código. Atacantes podem até usar isso para sobrecarregar o serviço (profile de CPU de 30 segundos consome recursos). Ligue a localhost, ou coloque atrás de uma rede interna e autenticação.

4. Coletar e ler CPU profile

Suponha que o serviço tenha uma função para gerar notas fiscais assim:

type Item struct {
	SKU   string
	Price float64
	Qty   int
}

type Order struct {
	ID    int
	Items []Item
}

func BuildInvoice(o Order) string {
	s := ""
	for _, it := range o.Items {
		s += fmt.Sprintf("%s x%d = %.2f\n", it.SKU, it.Qty, it.Price*float64(it.Qty))
	}
	return s
}

A cada iteração do loop, s += ... cria uma nova string e copia todo o conteúdo antigo para ela. Com pedidos com muitas linhas, o custo cresce em O(n²).

Enquanto o serviço está recebendo carga (por exemplo, você usa hey ou wrk para enviar requisições para /invoice), colete o CPU profile por 30 segundos:

go tool pprof "http://localhost:6060/debug/pprof/profile?seconds=30"

Após a coleta, você entra no modo interativo. Digite top:

(pprof) top 8
Showing nodes accounting for 2.41s, 85.46% of 2.82s total
      flat  flat%   sum%        cum   cum%
     0.92s 32.62% 32.62%      0.92s 32.62%  runtime.memmove
     0.41s 14.54% 47.16%      1.38s 48.94%  runtime.concatstrings
     0.33s 11.70% 58.87%      0.33s 11.70%  runtime.memclrNoHeapPointers
     0.27s  9.57% 68.44%      0.71s 25.18%  runtime.mallocgc
     0.18s  6.38% 74.82%      0.52s 18.44%  fmt.(*pp).doPrintf
     0.13s  4.61% 79.43%      0.13s  4.61%  strconv.fmtF
     0.10s  3.55% 82.98%      2.47s 87.59%  main.BuildInvoice
     0.07s  2.48% 85.46%      0.21s  7.45%  runtime.scanobject

Como ler as duas colunas mais importantes:

  • flat: tempo de CPU que fica diretamente dentro desta função.
  • cum (cumulativo): tempo desta função mais todas as funções que ela chama.

Aqui main.BuildInvoice tem flat pequeno mas cum perto de 88%. A maioria do tempo vai para memmove e concatstrings, ou seja, concatenação de strings. Para ver detalhes linha por linha, use list:

(pprof) list BuildInvoice
ROUTINE ======================== main.BuildInvoice in /app/invoice.go
     100ms      2.47s (flat, cum) 87.59% of Total
         .          .     18:func BuildInvoice(o Order) string {
         .          .     19:	s := ""
      10ms       10ms     20:	for _, it := range o.Items {
      90ms      2.46s     21:		s += fmt.Sprintf("%s x%d = %.2f\n", ...)
         .          .     22:	}

A linha 21 é a culpada. Se quiser ver um flame graph, abra a interface web:

go tool pprof -http=:8081 "http://localhost:6060/debug/pprof/profile?seconds=30"

O navegador abrirá views de Top, Graph, Flame Graph e Source. No flame graph, quanto mais largo o bloco, mais CPU ele consome.

A versão corrigida usa strings.Builder e fmt.Fprintf:

func BuildInvoiceFast(o Order) string {
	var b strings.Builder
	b.Grow(len(o.Items) * 32) // estime o tamanho antes, evite crescimentos múltiplos
	for _, it := range o.Items {
		fmt.Fprintf(&b, "%s x%d = %.2f\n", it.SKU, it.Qty, it.Price*float64(it.Qty))
	}
	return b.String()
}

5. Heap profile: quem está segurando a memória?

go tool pprof http://localhost:6060/debug/pprof/heap

Um heap profile contém quatro “índices de amostra”. Você escolhe o índice com a flag -sample_index:

  • inuse_space (padrão): número de bytes vivos no momento do último GC. Use para encontrar memory leaks.
  • inuse_objects: número de objetos vivos.
  • alloc_space: total de bytes alocados desde que o programa começou. Use para encontrar o que pressiona mais o GC.
  • alloc_objects: número total de objetos alocados.
go tool pprof -sample_index=alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top 3
      flat  flat%   sum%        cum   cum%
    1.84GB 91.20% 91.20%     1.84GB 91.20%  main.BuildInvoice
    0.12GB  5.95% 97.15%     0.12GB  5.95%  fmt.Sprintf
    0.03GB  1.49% 98.64%     0.03GB  1.49%  encoding/json.Marshal

O resultado mostra que BuildInvoice alocou 1.84GB no total, embora a quantidade viva possa ser bem menor. Isso é um sinal de que o GC tem muito trabalho. Essa situação combina com a quantidade de runtime.mallocgc e runtime.scanobject que você viu no CPU profile da seção 4.

Aviso: Heap profile também é uma amostragem (por padrão cerca de 1 amostra a cada 512KB alocados), então os números são estimativas. Não compare byte por byte, olhe para as proporções.

6. Goroutine profile: detecte vazamento de goroutine

Se o número de goroutines continua crescendo, você pode verificar rapidamente pelo navegador ou curl sem precisar de go tool pprof:

curl -s "http://localhost:6060/debug/pprof/goroutine?debug=1" | head -n 15
goroutine profile: total 10432
10398 @ 0x43a5d6 0x4071c5 0x406d78 0x6b2f45 0x46c0e1
#	0x6b2f44	main.(*PaymentService).notify+0x64	/app/payment.go:57

Há 10.398 goroutines travadas no mesmo lugar em payment.go:57. Isso é praticamente certo que é um vazamento. O código problemático geralmente se parece assim:

func (s *PaymentService) notify(ctx context.Context, p Payment) {
	result := make(chan error) // unbuffered
	go func() {
		result <- s.gateway.Send(p) // travará para sempre se ninguém receber
	}()
	select {
	case err := <-result:
		log.Println(err)
	case <-ctx.Done():
		return // a goroutine interna é abandonada
	}
}

Quando ctx expira primeiro, ninguém mais lê result, então a goroutine interna fica travada eternamente no envio. A correção simples é usar make(chan error, 1) para que o envio nunca bloqueie.

Com debug=2, o endpoint imprime o stack trace completo de cada goroutine, incluindo o tempo de espera (por exemplo, [chan send, 42 minutes]). Essa informação é muito útil ao investigar deadlocks.

7. Block e mutex profiles

Esses dois profiles estão desabilitados por padrão porque têm custo. Você os habilita no main:

import "runtime"

func init() {
	// Registre em média 1 evento de contenção mutex a cada 5
	runtime.SetMutexProfileFraction(5)
	// Amostra 1 evento de block a cada 10µs de bloqueio
	runtime.SetBlockProfileRate(10_000)
}

Depois colete profiles normalmente:

go tool pprof http://localhost:6060/debug/pprof/mutex
go tool pprof http://localhost:6060/debug/pprof/block

O perfil mutex mostra qual lock faz as goroutines esperar umas pelas outras, por exemplo um sync.Mutex protegendo um cache map[int]Customer compartilhado. O perfil block mostra onde as goroutines passam muito tempo esperando em channels ou select.

Aviso: SetBlockProfileRate(1) registra todo evento de block. Este nível é apropriado apenas para debug local. Em produção, use uma taxa maior, ou habilite apenas temporariamente.

8. Profiling de benchmarks

Para uma função específica, a forma mais limpa é escrever um benchmark e deixar go test gerar profiles. O código abaixo usa b.Loop(), então precisa de Go 1.24 ou superior.

package main

import (
	"fmt"
	"testing"
)

func sampleOrder(n int) Order {
	items := make([]Item, n)
	for i := range items {
		items[i] = Item{SKU: fmt.Sprintf("SKU-%04d", i), Price: 19.99, Qty: i%5 + 1}
	}
	return Order{ID: 1, Items: items}
}

func TestBuildInvoiceFastMatchesOriginal(t *testing.T) {
	order := sampleOrder(200)
	if got, want := BuildInvoiceFast(order), BuildInvoice(order); got != want {
		t.Fatalf("saída é diferente:\n got=%q\nwant=%q", got, want)
	}
}

func BenchmarkBuildInvoice(b *testing.B) {
	order := sampleOrder(500)
	b.ReportAllocs()
	for b.Loop() {
		BuildInvoice(order)
	}
}

func BenchmarkBuildInvoiceFast(b *testing.B) {
	order := sampleOrder(500)
	b.ReportAllocs()
	for b.Loop() {
		BuildInvoiceFast(order)
	}
}

O teste TestBuildInvoiceFastMatchesOriginal garante que a versão otimizada produza exatamente o mesmo resultado da versão original. Não pule este passo: otimizar para dar resultado errado é inútil. Execute o benchmark com profiles:

go test -run='^$' -bench=BuildInvoice -cpuprofile=cpu.out -memprofile=mem.out
BenchmarkBuildInvoice-8        1543    772410 ns/op   6342817 B/op    1002 allocs/op
BenchmarkBuildInvoiceFast-8   19821     60318 ns/op     36472 B/op     504 allocs/op

A versão com strings.Builder é cerca de 12 vezes mais rápida e aloca cerca de 170 vezes menos. A flag -run='^$' pula testes normais para rodar apenas benchmarks. Os arquivos cpu.out e mem.out são abertos com:

go tool pprof -http=:8081 cpu.out

9. Profiling de programas CLI com runtime/pprof

Para ferramentas que rodam uma vez e saem, como um job de importação de pedidos, você usa runtime/pprof diretamente:

package main

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

func main() {
	cpuFile, err := os.Create("cpu.out")
	if err != nil {
		log.Fatal(err)
	}
	defer cpuFile.Close()

	if err := pprof.StartCPUProfile(cpuFile); err != nil {
		log.Fatal(err)
	}
	defer pprof.StopCPUProfile()

	importOrders("orders.csv") // trabalho principal

	memFile, err := os.Create("mem.out")
	if err != nil {
		log.Fatal(err)
	}
	defer memFile.Close()
	runtime.GC() // atualize os dados inuse antes de escrever
	if err := pprof.WriteHeapProfile(memFile); err != nil {
		log.Fatal(err)
	}
}

Dois erros comuns aqui:

  • Chamar log.Fatal ou os.Exit após StartCPUProfile pulará os defer. Nesse caso StopCPUProfile não roda e o arquivo profile fica vazio ou corrompido.
  • Esquecer runtime.GC() antes de WriteHeapProfile. Os dados inuse_* são atualizados apenas após cada coleta de lixo, então o profile pode refletir um estado antigo.

10. Comparando dois profiles

Depois de otimizar, você deve medir novamente em vez de confiar na intuição. A flag -diff_base subtrai o profile antigo do profile novo:

go tool pprof -diff_base=cpu_before.out cpu_after.out
(pprof) top 3
      flat  flat%   sum%        cum   cum%
    -0.89s 31.56% 31.56%     -0.89s 31.56%  runtime.memmove
    -0.40s 14.18% 45.74%     -1.35s 47.87%  runtime.concatstrings
    -0.25s  8.87% 54.61%     -0.66s 23.40%  runtime.mallocgc

Valores negativos significam que o tempo diminuiu. Para que os resultados sejam significativos, os dois profiles devem ser coletados nas mesmas condições: mesma carga, mesma duração, mesma máquina.

Além disso, desde Go 1.21, o CPU profile também serve para Profile-Guided Optimization (PGO). Você coleta um profile de CPU representativo da produção, o nomeia default.pgo na pasta do package main, e go build usará automaticamente esse profile para fazer inlining e otimizar as linhas de código quentes. A melhoria típica está em alguns pontos percentuais, e você não precisa alterar nenhuma linha de código.

11. Erros comuns e quando não usar

  • Profile muito curto ou sem carga. CPU profile faz amostragem a 100Hz. Se você coletar apenas 2 segundos enquanto o serviço está ocioso, você verá apenas runtime e ruído.
  • Confundir flat com cum. Uma função com cum alto não é necessariamente a culpada, ela pode estar apenas chamando a culpada.
  • Confundir inuse_space com alloc_space. Para encontrar vazamentos, veja inuse. Para reduzir pressão do GC, veja alloc.
  • Medir I/O com CPU profile. O tempo que uma goroutine passa esperando banco de dados ou HTTP não consome CPU, então não aparece no profile de CPU. Use block profile, go tool trace, ou rastreamento distribuído.
  • Deixar pprof público na porta da aplicação. Veja a seção 3 novamente.

Aviso: pprof responde “o que está consumindo”, não “devemos otimizar isso”. Se um endpoint já atende ao SLA e uma função consome apenas 2% da CPU, reescrevê-la para algo mais complexo geralmente não compensa.

12. Conclusão

Neste artigo, você:

  • habilitou net/http/pprof com segurança em um servidor separado em localhost;
  • leu CPU profiles com top e list, e distinguiu flat de cum;
  • usou heap profile com inuse_space e alloc_space;
  • detectou vazamentos de goroutine via debug=1 e debug=2;
  • habilitou block e mutex profiles;
  • gerou profiles de benchmarks e programas CLI;
  • comparou antes/depois com -diff_base.

O fluxo mais eficaz ainda é: medir → encontrar o ponto quente → corrigir → escrever teste para preservar o comportamento → medir novamente. Com pprof disponível na biblioteca padrão, você não precisa instalar nada para começar.

golangpprofperformanceprofiling