Profiling Go avec pprof : trouver les points chauds CPU, mémoire et goroutine

1. Vue d’ensemble

Quand un service Go s’exécute lentement ou consomme beaucoup de RAM, deviner au hasard coûte du temps et se trompe souvent. Go possède un outil pprof dans la bibliothèque standard. Cet outil vous dit exactement quelle fonction consomme du CPU, où la mémoire est allouée et quelle goroutine est bloquée.

Après avoir lu cet article, vous saurez comment activer pprof pour un service HTTP, collecter des profils à partir d’un benchmark et d’un programme CLI, lire les résultats avec go tool pprof, et comparer deux profils pour vérifier une optimisation.

2. Qu’est-ce que pprof et quels sont les types de profils

pprof se compose de deux parties :

• Côté collecte : les packages runtime/pprof et net/http/pprof dans la bibliothèque standard. Ils enregistrent les profils au format protobuf.
• Côté analyse : la commande go tool pprof. Cette commande lit un fichier de profil ou une URL, puis affiche les résultats sous forme de tableau, de code source ou d’interface web.

Les types de profils couramment utilisés :

Profil	Mesure quoi	Activé par défaut ?
profile (CPU)	Temps CPU par fonction, échantillonné 100 fois/sec	Oui, à la demande
heap	Mémoire vivante et total alloué	Oui
allocs	Comme heap, mais affiche par défaut l’allocation totale	Oui
goroutine	Stack trace de toutes les goroutines actuelles	Oui
block	Temps d’attente sur canal, select, sync.Cond	Non
mutex	Contention sur sync.Mutex/RWMutex	Non
trace	Trace d’événements détaillée (utilise go tool trace)	Oui, à la demande

3. Activer pprof pour un service HTTP

Le moyen le plus rapide est d’importer net/http/pprof pour obtenir l’effet de bord. Ce package enregistre les gestionnaires /debug/pprof/* auprès de http.DefaultServeMux.

package main

import (
	"log"
	"net/http"
	_ "net/http/pprof" // enregistre /debug/pprof/* auprès de DefaultServeMux
)

func main() {
	// Serveur pprof séparé, écoute seulement sur localhost
	go func() {
		log.Println(http.ListenAndServe("localhost:6060", nil))
	}()

	// Serveur d'application avec mux séparé, n'expose pas pprof
	appMux := http.NewServeMux()
	appMux.HandleFunc("GET /invoice", invoiceHandler)
	log.Fatal(http.ListenAndServe(":8080", appMux))
}

Quelques points à noter :

• La ligne _ "net/http/pprof" enregistre seulement les gestionnaires, vous n’appelez aucune fonction de ce package.
• Le serveur pprof passe nil comme gestionnaire, c’est-à-dire utilise DefaultServeMux, où se trouvent les routes pprof.
• L’application principale utilise appMux séparément, donc le port 8080 n’a pas /debug/pprof.

Vérification rapide :

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

Attention : N’exposez jamais /debug/pprof sur Internet. Cet endpoint révèle les stack traces et la structure du code. Un attaquant peut même l’utiliser pour surcharger le service (un profil CPU de 30 secondes consomme des ressources). Bindez sur localhost, ou placez-le derrière un réseau interne et une couche d’authentification.

4. Collecter et analyser un profil CPU

Supposons que le service ait une fonction pour générer des factures :

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
}

À chaque itération, s += ... crée une nouvelle chaîne et copie tout le contenu précédent. Avec une commande de plusieurs lignes, le coût augmente en O(n²).

Pendant que le service reçoit de la charge (par exemple vous envoyez des requêtes avec hey ou wrk vers /invoice), collectez un profil CPU pendant 30 secondes :

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

Une fois la collecte terminée, vous entrez en mode interactif. Tapez 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

Comment lire les deux colonnes les plus importantes :

• flat : le temps CPU passé directement dans cette fonction.
• cum (cumulative) : le temps de cette fonction plus toutes les fonctions qu’elle appelle.

Ici main.BuildInvoice a un flat faible mais un cum proche de 88%. La plupart du temps provient de memmove et concatstrings, c’est-à-dire la concaténation de chaînes. Pour voir les détails ligne par ligne, utilisez 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:	}

La ligne 21 est le coupable. Si vous voulez voir un flame graph, ouvrez l’interface web :

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

Votre navigateur ouvrira les vues Top, Graph, Flame Graph et Source. Dans le flame graph, plus un bloc est large, plus il consomme de CPU.

La version corrigée utilisant strings.Builder et fmt.Fprintf :

func BuildInvoiceFast(o Order) string {
	var b strings.Builder
	b.Grow(len(o.Items) * 32) // estimez à l'avance, évitez les croissances répétées
	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. Profil heap : qui retient la mémoire ?

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

Un profil heap contient quatre “index d’échantillon”. Vous sélectionnez l’index avec le drapeau -sample_index :

• inuse_space (par défaut) : nombre d’octets en vie au moment du GC précédent. Utilisez ceci pour trouver les fuites mémoire.
• inuse_objects : nombre d’objets en vie.
• alloc_space : nombre total d’octets alloués depuis le démarrage du programme. Utilisez ceci pour réduire la pression sur le GC.
• alloc_objects : nombre total d’objets alloués.

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

Le résultat montre que BuildInvoice a alloué au total 1.84GB, bien que la quantité en vie peut être très faible. C’est le signe que le GC doit travailler dur. Cette situation correspond à la quantité de runtime.mallocgc et runtime.scanobject que vous avez vue dans le profil CPU à la section 4.

Remarque : Le profil heap est aussi un échantillon (par défaut environ 1 échantillon pour 512KB alloués), donc les chiffres sont une estimation. Ne comparez pas chaque octet, regardez les proportions.

6. Profil goroutine : détecter les fuites de goroutine

Si le nombre de goroutines augmente constamment, vous pouvez vérifier rapidement via le navigateur ou curl sans avoir besoin 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

Il y a 10.398 goroutines bloquées au même endroit dans payment.go:57. C’est quasi certainement une fuite. Le code fautif ressemble généralement à :

func (s *PaymentService) notify(ctx context.Context, p Payment) {
	result := make(chan error) // non bufferisé
	go func() {
		result <- s.gateway.Send(p) // se bloque indéfiniment si personne ne lit
	}()
	select {
	case err := <-result:
		log.Println(err)
	case <-ctx.Done():
		return // la goroutine interne est orpheline
	}
}

Quand ctx expire en premier, personne n’attend plus sur result, donc la goroutine interne reste bloquée indéfiniment sur l’envoi. Le correctif simple est d’utiliser make(chan error, 1) pour que l’envoi ne soit jamais bloquant.

Avec debug=2, l’endpoint affiche les stack traces complètes de chaque goroutine, avec les temps d’attente (par exemple [chan send, 42 minutes]). Cette information est très utile lors d’une enquête sur un deadlock.

7. Profils block et mutex

Ces deux profils sont désactivés par défaut car ils ont un coût. Vous les activez dans main :

import "runtime"

func init() {
	// Enregistrez environ 1 événement de contention mutex sur 5
	runtime.SetMutexProfileFraction(5)
	// Échantillonnez 1 événement de blocage pour tous les 10µs bloqués
	runtime.SetBlockProfileRate(10_000)
}

Ensuite, collectez les profils comme d’habitude :

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

Le profil mutex vous dit quel lock force les goroutines à attendre les unes après les autres, par exemple un sync.Mutex protégeant un cache map[int]Customer partagé. Le profil block vous dit où les goroutines attendent longtemps sur un canal ou un select.

Remarque : SetBlockProfileRate(1) enregistre chaque événement de blocage. Ce niveau n’est approprié que pour debuguer localement. En production, utilisez un taux plus élevé, ou activez-le seulement temporairement.

8. Profiling à partir d’un benchmark

Pour une fonction spécifique, la manière la plus simple est d’écrire un benchmark puis de laisser go test générer un profil. Le code ci-dessous utilise b.Loop() donc il faut Go 1.24 ou plus récent.

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("résultats différents:\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)
	}
}

Le test TestBuildInvoiceFastMatchesOriginal assure que la version optimisée produit exactement le même résultat que l’ancienne. Ne sautez pas cette étape : optimiser en se trompant n’a aucun sens. Exécutez le benchmark avec profil :

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

La version utilisant strings.Builder est environ 12 fois plus rapide et alloue environ 170 fois moins. Le drapeau -run='^$' ignore les tests ordinaires pour ne lancer que les benchmarks. Les fichiers cpu.out et mem.out s’ouvrent avec :

go tool pprof -http=:8081 cpu.out

9. Profiling d’un programme CLI avec runtime/pprof

Pour un outil qui s’exécute une fois puis s’arrête, par exemple un job d’import de commandes, utilisez directement runtime/pprof :

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") // travail principal

	memFile, err := os.Create("mem.out")
	if err != nil {
		log.Fatal(err)
	}
	defer memFile.Close()
	runtime.GC() // mettez à jour les statistiques inuse avant d'écrire
	if err := pprof.WriteHeapProfile(memFile); err != nil {
		log.Fatal(err)
	}
}

Deux erreurs courantes ici :

• Appeler log.Fatal ou os.Exit après StartCPUProfile contourne les defer. Dans ce cas StopCPUProfile ne s’exécute pas et le fichier profile est vide ou corrompu.
• Oublier runtime.GC() avant WriteHeapProfile. Les statistiques inuse_* ne sont mises à jour qu’après chaque GC, donc le profil peut refléter un état ancien.

10. Comparer deux profils

Après optimisation, vous devez mesurer à nouveau plutôt que de vous fier à vos impressions. Le drapeau -diff_base soustrait l’ancien profil du nouveau :

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

Les valeurs négatives signifient que le temps a diminué. Pour que les résultats aient du sens, les deux profils doivent être collectés dans les mêmes conditions : même charge, même durée, même machine.

De plus, depuis Go 1.21, le profil CPU sert aussi pour Profile-Guided Optimization (PGO). Vous collectez un profil CPU représentatif de la production, le nommez default.pgo dans le répertoire du package main, puis go build l’utilisera automatiquement pour inliner et optimiser les chemins de code chauds. L’amélioration est généralement de quelques pourcents, et vous n’avez à modifier aucune ligne de code.

11. Erreurs courantes et quand ne pas utiliser

• Profil trop court ou sans charge. Le profil CPU échantillonne à 100Hz. Si vous collectez seulement 2 secondes quand le service est au repos, vous ne verrez que runtime et du bruit.
• Confondre flat et cum. Une fonction avec un cum élevé n’est pas forcément le coupable, elle peut simplement appeler le coupable.
• Confondre inuse_space et alloc_space. Pour trouver une fuite, consultez inuse. Pour réduire la pression sur le GC, consultez alloc.
• Mesurer l’I/O avec le profil CPU. Le temps où une goroutine attend une base de données ou HTTP ne consomme pas de CPU donc n’apparaît pas dans le profil CPU. Utilisez le profil block, go tool trace, ou un tracing distribué.
• Exposer pprof publiquement sur le port de l’application. Revoyez la section 3.

Remarque : pprof répond à la question “où ça coûte”, pas “faut-il optimiser”. Si un endpoint atteint déjà son SLA et une fonction consomme seulement 2% du CPU, la réécrire plus complexe n’en vaut généralement pas la peine.

12. Conclusion

Dans cet article, vous avez :

• activé net/http/pprof de manière sécurisée sur un serveur séparé sur localhost ;
• lu un profil CPU avec top et list, et distingué flat de cum ;
• utilisé un profil heap avec inuse_space et alloc_space ;
• détecté les fuites de goroutine via debug=1 et debug=2 ;
• activé les profils block et mutex ;
• généré des profils à partir d’un benchmark et d’un programme CLI ;
• comparé avant/après avec -diff_base.

Le processus le plus efficace reste : mesurer → trouver les points chauds → corriger → écrire un test pour préserver le comportement → mesurer à nouveau. Avec pprof fourni dans la bibliothèque standard, vous n’avez rien à installer pour commencer.