95/100 Dias de Golang - Métricas com Prometheus e Tracing com OpenTelemetry

2025-12-12

/posts/golang/095-golang/ map[name:Victor Stein]

#Golang

Table of Contents

# Métricas com Prometheus e Tracing com OpenTelemetry

No post anterior vimos logging estruturado. Logs são ótimos para entender o que aconteceu em um evento específico, mas não respondem bem a algumas perguntas:

Quantas requisições por segundo a API está recebendo agora? Quantas estão dando erro?
O tempo de resposta piorou depois do último deploy?
Essa requisição demorou 2 segundos. Onde foi gasto esse tempo: no banco, numa API externa, no nosso código?

Para isso existem os outros dois “pilares” da observabilidade:

Métricas: números agregados ao longo do tempo (total de requisições, uso de memória, latência). São baratas de guardar e ótimas para dashboards e alertas;
Traces: o caminho completo de uma requisição pelo sistema, com o tempo gasto em cada etapa.

Hoje vamos instrumentar uma API com os dois: métricas com Prometheus e traces com OpenTelemetry, visualizados no Jaeger.

# Prometheus

O Prometheus é o banco de dados de métricas mais usado hoje. Ele funciona no modelo pull: a aplicação expõe as métricas num endpoint HTTP (normalmente /metrics), e o Prometheus vai lá buscá-las de tempos em tempos (o scrape).

A biblioteca oficial para Go é a client_golang:

go get github.com/prometheus/client_golang@v1.23.2

## Tipos de métricas

Os três tipos mais usados são:

Counter: um contador que só aumenta (ou volta a zero quando a aplicação reinicia). Ex.: total de requisições, total de erros;
Gauge: um valor que sobe e desce. Ex.: requisições em andamento, tamanho de uma fila, memória em uso;
Histogram: distribui as observações em faixas (buckets). É o que usamos para medir latência e calcular percentis.

## Instrumentando a API

Vamos criar uma API com um endpoint /pedidos que demora um tempo aleatório e falha em 10% das vezes, e um middleware que coleta as três métricas:

package main

import (
	"log"
	"math/rand/v2"
	"net/http"
	"strconv"
	"time"

	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promauto"
	"github.com/prometheus/client_golang/prometheus/promhttp"
)

var (
	requisicoes = promauto.NewCounterVec(
		prometheus.CounterOpts{
			Name: "http_requests_total",
			Help: "Total de requisições HTTP recebidas",
		},
		[]string{"metodo", "rota", "status"},
	)

	duracao = promauto.NewHistogramVec(
		prometheus.HistogramOpts{
			Name:    "http_request_duration_seconds",
			Help:    "Duração das requisições HTTP em segundos",
			Buckets: []float64{0.01, 0.05, 0.1, 0.25, 0.5, 1},
		},
		[]string{"rota"},
	)

	emAndamento = promauto.NewGauge(
		prometheus.GaugeOpts{
			Name: "http_requests_in_flight",
			Help: "Requisições sendo processadas neste momento",
		},
	)
)

// statusRecorder guarda o status code escrito pelo handler
type statusRecorder struct {
	http.ResponseWriter
	status int
}

func (r *statusRecorder) WriteHeader(status int) {
	r.status = status
	r.ResponseWriter.WriteHeader(status)
}

func metricasMiddleware(rota string, next http.HandlerFunc) http.HandlerFunc {
	return func(w http.ResponseWriter, r *http.Request) {
		emAndamento.Inc()
		defer emAndamento.Dec()

		inicio := time.Now()
		rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK}

		next(rec, r)

		duracao.WithLabelValues(rota).Observe(time.Since(inicio).Seconds())
		requisicoes.WithLabelValues(r.Method, rota, strconv.Itoa(rec.status)).Inc()
	}
}

func pedidosHandler(w http.ResponseWriter, r *http.Request) {
	time.Sleep(time.Duration(rand.IntN(300)) * time.Millisecond) // simulando trabalho

	if rand.IntN(10) == 0 { // 10% das requisições falham
		http.Error(w, "erro interno", http.StatusInternalServerError)
		return
	}
	w.Write([]byte("pedido criado\n"))
}

func main() {
	http.HandleFunc("/pedidos", metricasMiddleware("/pedidos", pedidosHandler))
	http.Handle("/metrics", promhttp.Handler())

	log.Println("servidor rodando em :8095")
	log.Fatal(http.ListenAndServe(":8095", nil))
}

Os pontos principais:

promauto cria a métrica e já registra no registro padrão do Prometheus. Sem ele, teríamos que chamar prometheus.MustRegister para cada métrica.
Labels (metodo, rota, status) dividem uma métrica em várias séries. Com elas conseguimos perguntar “quantos erros 500 na rota /pedidos?”.
O statusRecorder existe porque o http.ResponseWriter não tem um jeito de perguntar qual status foi enviado. Então “embrulhamos” o writer original e guardamos o status quando o handler chama WriteHeader. Se o handler nunca chamar, o padrão é 200.
promhttp.Handler() é o endpoint que o Prometheus vai consultar.

## O endpoint /metrics

Depois de fazer 200 requisições para /pedidos, o /metrics mostra:

curl localhost:8095/metrics

# HELP http_request_duration_seconds Duração das requisições HTTP em segundos
# TYPE http_request_duration_seconds histogram
http_request_duration_seconds_bucket{rota="/pedidos",le="0.01"} 3
http_request_duration_seconds_bucket{rota="/pedidos",le="0.05"} 29
http_request_duration_seconds_bucket{rota="/pedidos",le="0.1"} 71
http_request_duration_seconds_bucket{rota="/pedidos",le="0.25"} 175
http_request_duration_seconds_bucket{rota="/pedidos",le="0.5"} 200
http_request_duration_seconds_bucket{rota="/pedidos",le="1"} 200
http_request_duration_seconds_bucket{rota="/pedidos",le="+Inf"} 200
http_request_duration_seconds_sum{rota="/pedidos"} 28.69084848
http_request_duration_seconds_count{rota="/pedidos"} 200
# HELP http_requests_in_flight Requisições sendo processadas neste momento
# TYPE http_requests_in_flight gauge
http_requests_in_flight 0
# HELP http_requests_total Total de requisições HTTP recebidas
# TYPE http_requests_total counter
http_requests_total{metodo="GET",rota="/pedidos",status="200"} 189
http_requests_total{metodo="GET",rota="/pedidos",status="500"} 11

É um formato de texto simples. No histograma, cada bucket conta quantas requisições demoraram até aquele valor (le = less or equal): 3 levaram até 10ms, 29 até 50ms, 175 até 250ms, e todas as 200 até 500ms.

Além das nossas métricas, o endpoint traz mais de 40 métricas do runtime do Go (go_goroutines, go_memstats_heap_alloc_bytes, go_gc_duration_seconds…) e do processo (process_cpu_seconds_total…). Ou seja, de graça já temos no dashboard muito do que vimos nos posts sobre pprof e GC.

## Rodando o Prometheus

Para o Prometheus coletar as métricas, criamos um prometheus.yml:

global:
  scrape_interval: 5s

scrape_configs:
  - job_name: "api-pedidos"
    static_configs:
      - targets: ["localhost:8095"]

E subimos com Docker:

docker run --rm --network host \
  -v $(pwd)/prometheus.yml:/etc/prometheus/prometheus.yml \
  prom/prometheus:v3.5.0

O --network host faz o container usar a rede da máquina, para que o localhost:8095 aponte para a nossa API. Isso funciona no Linux; no Mac e no Windows use host.docker.internal:8095 como target.

A interface fica em http://localhost:9090. Lá podemos fazer consultas com a linguagem do Prometheus, o PromQL. Com a API recebendo tráfego, essas são as consultas mais úteis (os valores são da minha execução):

# requisições por segundo, por status, no último minuto
rate(http_requests_total[1m])
# status="200" → 7.23   status="500" → 0.72

# taxa de erro: requisições 5xx / total
sum(rate(http_requests_total{status=~"5.."}[1m])) / sum(rate(http_requests_total[1m]))
# → 0.09 (9%, bem perto dos 10% que simulamos)

# percentil 95 da latência
histogram_quantile(0.95, sum by (le) (rate(http_request_duration_seconds_bucket[1m])))
# → 0.43

O rate é a função mais importante do PromQL: um counter sozinho (189 requisições) não diz muita coisa, mas a taxa de crescimento dele (7 requisições por segundo) diz.

Repare no percentil 95: o PromQL respondeu 0,43s, mas nosso handler demora no máximo 300ms! O p95 real é de uns 285ms. Isso acontece porque o histograma não guarda os valores exatos, só a contagem por bucket. O Prometheus sabe que o p95 está entre 0,25 e 0,5 e faz uma interpolação linear dentro desse intervalo. Por isso os buckets devem ser escolhidos de acordo com a latência esperada: se tivéssemos buckets em 0,2, 0,25 e 0,3, o resultado seria muito mais preciso.

Para dashboards bonitos, o próximo passo é o Grafana, que usa o Prometheus como fonte de dados.

## Cuidado com a cardinalidade

Cada combinação diferente de valores de labels gera uma série temporal nova no Prometheus. metodo × rota × status dá algumas dezenas de séries, tudo bem. Mas se colocássemos um label usuario_id, com 1 milhão de usuários teríamos milhões de séries, e o Prometheus começaria a usar memória demais.

Nunca use como label valores ilimitados: IDs de usuário, e-mails, URLs com parâmetros (/pedidos/123), mensagens de erro. Por isso o middleware recebe a rota como parâmetro ("/pedidos") em vez de usar o r.URL.Path. Para investigar uma requisição específica, o lugar certo são os logs e os traces.

# Tracing com OpenTelemetry

Agora a outra pergunta: onde o tempo de uma requisição está sendo gasto?

Um trace representa o caminho de uma requisição e é formado por spans. Cada span é uma operação com início e fim (uma chamada HTTP, uma query no banco, uma função importante), e os spans formam uma árvore: um span pode ter filhos.

O OpenTelemetry (ou OTel) é o padrão aberto para gerar traces, métricas e logs. A vantagem é que instrumentamos o código uma vez e podemos mandar os dados para qualquer ferramenta compatível: Jaeger, Grafana Tempo, Datadog, Honeycomb…

go get go.opentelemetry.io/otel@v1.39.0 \
  go.opentelemetry.io/otel/sdk@v1.39.0 \
  go.opentelemetry.io/otel/exporters/stdout/stdouttrace@v1.39.0

## Primeiro trace

Para começar sem infraestrutura nenhuma, vamos usar o exporter que imprime os spans no terminal:

package main

import (
	"context"
	"errors"
	"log"
	"os"
	"time"

	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/codes"
	"go.opentelemetry.io/otel/exporters/stdout/stdouttrace"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
)

var tracer = otel.Tracer("api-pedidos")

func iniciarTracing() (*sdktrace.TracerProvider, error) {
	exporter, err := stdouttrace.New(stdouttrace.WithWriter(os.Stdout))
	if err != nil {
		return nil, err
	}

	tp := sdktrace.NewTracerProvider(sdktrace.WithBatcher(exporter))
	otel.SetTracerProvider(tp)
	return tp, nil
}

func criarPedido(ctx context.Context, usuarioID int) error {
	ctx, span := tracer.Start(ctx, "criarPedido")
	defer span.End()

	span.SetAttributes(attribute.Int("usuario.id", usuarioID))

	if err := validarEstoque(ctx); err != nil {
		return err
	}

	if err := salvarNoBanco(ctx); err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, err.Error())
		return err
	}

	return nil
}

func validarEstoque(ctx context.Context) error {
	_, span := tracer.Start(ctx, "validarEstoque")
	defer span.End()

	time.Sleep(20 * time.Millisecond)
	return nil
}

func salvarNoBanco(ctx context.Context) error {
	_, span := tracer.Start(ctx, "salvarNoBanco")
	defer span.End()

	span.SetAttributes(attribute.String("db.system", "postgresql"))
	time.Sleep(50 * time.Millisecond)
	return errors.New("timeout no banco")
}

func main() {
	tp, err := iniciarTracing()
	if err != nil {
		log.Fatal(err)
	}
	defer tp.Shutdown(context.Background())

	if err := criarPedido(context.Background(), 42); err != nil {
		log.Println("erro:", err)
	}
}

Os conceitos:

TracerProvider: configura para onde os spans vão (o exporter) e como são enviados. O WithBatcher junta vários spans e envia em lotes, em vez de um por um;
tracer.Start(ctx, nome): cria um span. Se o ctx já tiver um span, o novo vira filho dele. E retorna um novo ctx contendo o span criado, que passamos adiante;
span.End(): marca o fim do span. Sempre com defer;
SetAttributes: adiciona informações ao span, como os atributos do slog;
RecordError e SetStatus: registram o erro e marcam o span como falho;
tp.Shutdown: envia os spans que ainda estão no lote antes do programa sair. Sem ele, os últimos spans se perdem. Isso conversa bastante com o graceful shutdown do dia 90.

De novo o context aparece como peça central: é através dele que um span sabe quem é o seu pai. Se você criar um span com context.Background() no meio do código, ele começa um trace novo, separado.

A saída é um JSON por span, bem verboso. Resumindo o que importa:

2025/12/12 10:00:00 erro: timeout no banco

{"Name":"validarEstoque","SpanContext":{"TraceID":"73c2d8a88208bf9dfa9fdcea3cca1b30","SpanID":"ca760c8111170330",...},"Parent":{"SpanID":"0257038c675a84b0",...},...}
{"Name":"salvarNoBanco","SpanContext":{"TraceID":"73c2d8a88208bf9dfa9fdcea3cca1b30","SpanID":"165fbcc74d096c55",...},"Parent":{"SpanID":"0257038c675a84b0",...},"Attributes":[{"Key":"db.system","Value":{"Type":"STRING","Value":"postgresql"}}],...}
{"Name":"criarPedido","SpanContext":{"TraceID":"73c2d8a88208bf9dfa9fdcea3cca1b30","SpanID":"0257038c675a84b0",...},"Parent":{"SpanID":"0000000000000000",...},"Status":{"Code":"Error","Description":"timeout no banco"},"Events":[{"Name":"exception",...}],...}

Os três spans têm o mesmo TraceID, ou seja, fazem parte da mesma requisição. O validarEstoque e o salvarNoBanco têm como Parent o SpanID do criarPedido, que por sua vez não tem pai (é a raiz). E o criarPedido está com status Error e um evento exception com o erro.

Os spans aparecem na ordem em que terminaram: os filhos terminam antes do pai.

## Mandando para o Jaeger

Ler JSON no terminal não é prático. O Jaeger é uma ferramenta open source para visualizar traces, e aceita o protocolo do OpenTelemetry (o OTLP) direto:

docker run --rm -p 16686:16686 -p 4318:4318 jaegertracing/jaeger:2.13.0

A porta 4318 recebe os traces via OTLP/HTTP e a 16686 é a interface web.

Agora vamos trocar o exporter e instrumentar um servidor HTTP de verdade. Duas dependências novas:

go get go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp@v1.39.0 \
  go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp@v0.64.0

package main

import (
	"context"
	"errors"
	"log"
	"math/rand/v2"
	"net/http"
	"time"

	"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/codes"
	"go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp"
	"go.opentelemetry.io/otel/sdk/resource"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
	semconv "go.opentelemetry.io/otel/semconv/v1.37.0"
)

var tracer = otel.Tracer("api-pedidos")

func iniciarTracing(ctx context.Context) (*sdktrace.TracerProvider, error) {
	exporter, err := otlptracehttp.New(ctx,
		otlptracehttp.WithEndpoint("localhost:4318"),
		otlptracehttp.WithInsecure(),
	)
	if err != nil {
		return nil, err
	}

	res := resource.NewWithAttributes(
		semconv.SchemaURL,
		semconv.ServiceName("api-pedidos"),
		semconv.ServiceVersion("1.0.0"),
	)

	tp := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(exporter),
		sdktrace.WithResource(res),
	)
	otel.SetTracerProvider(tp)
	return tp, nil
}

func pedidosHandler(w http.ResponseWriter, r *http.Request) {
	if err := criarPedido(r.Context(), 42); err != nil {
		http.Error(w, "erro ao criar pedido", http.StatusInternalServerError)
		return
	}
	w.Write([]byte("pedido criado\n"))
}

// criarPedido e validarEstoque iguais ao exemplo anterior

func salvarNoBanco(ctx context.Context) error {
	_, span := tracer.Start(ctx, "salvarNoBanco")
	defer span.End()

	span.SetAttributes(attribute.String("db.system", "postgresql"))
	time.Sleep(time.Duration(30+rand.IntN(100)) * time.Millisecond)

	if rand.IntN(5) == 0 { // 20% das vezes o banco falha
		return errors.New("timeout no banco")
	}
	return nil
}

func main() {
	ctx := context.Background()

	tp, err := iniciarTracing(ctx)
	if err != nil {
		log.Fatal(err)
	}
	defer tp.Shutdown(ctx)

	mux := http.NewServeMux()
	mux.HandleFunc("/pedidos", pedidosHandler)

	handler := otelhttp.NewHandler(mux, "servidor")

	log.Println("servidor rodando em :8095")
	log.Fatal(http.ListenAndServe(":8095", handler))
}

O que mudou:

otlptracehttp envia os spans para o Jaeger em vez de imprimir no terminal. O resto do código não muda nada, essa é a graça do OpenTelemetry;
resource identifica quem está gerando os traces. Sem o ServiceName, o serviço aparece como unknown_service. O pacote semconv (semantic conventions) traz os nomes padronizados de atributos;
otelhttp.NewHandler é um middleware que cria automaticamente um span para cada requisição recebida, com método, rota e status code. E coloca esse span no r.Context(), então o criarPedido vira filho dele sem mudarmos nada no handler.

Fazendo 20 requisições e abrindo o Jaeger em http://localhost:16686, o serviço api-pedidos aparece com os 20 traces, 4 deles com erro (marcados em vermelho). Um trace com erro fica assim:

servidor                        137ms  GET /pedidos → 500
└── criarPedido                 137ms  usuario.id=42  ❌ timeout no banco
    ├── validarEstoque           20ms
    └── salvarNoBanco           116ms  db.system=postgresql

E um trace com sucesso:

servidor                         70ms  GET /pedidos → 200
└── criarPedido                  70ms  usuario.id=42
    ├── validarEstoque           20ms
    └── salvarNoBanco            49ms  db.system=postgresql

Na interface do Jaeger isso aparece como uma linha do tempo, com cada span como uma barra. Dá para ver na hora que o salvarNoBanco é a parte lenta da requisição, e que foi ele que falhou.

O otelhttp também tem um otelhttp.NewTransport para o cliente HTTP. Ele envia o trace ID num header (traceparent) para o próximo serviço. Se esse serviço também usar OpenTelemetry, os spans dele entram no mesmo trace, e conseguimos ver uma requisição atravessando vários microsserviços. É isso que torna o tracing “distribuído”.

# Juntando os pilares

As três ferramentas se complementam no dia a dia:

Um alerta baseado em métricas avisa que a taxa de erro passou de 5%;
No Jaeger, filtramos os traces com erro daquele período e descobrimos que o problema é o salvarNoBanco;
Nos logs daquele trace, encontramos a mensagem de erro completa.

Para o passo 3 funcionar, os logs precisam ter o trace ID. Dá para fazer isso com o mesmo truque do handler customizado do post anterior, pegando o ID com trace.SpanContextFromContext(ctx).TraceID() em vez do request ID. Ou usar a ponte oficial entre slog e OpenTelemetry, o otelslog.

victorstein.dev