A média é onde os problemas de performance vão se esconder
O painel dizia 210 ms e o cliente dizia que estava lento. Os dois estavam certos, e foi o histograma que encerrou a discussão.
Terça-feira, 8h20. O painel estava daquele verde que dá vontade de tirar print: latência média de 210 ms na rota de produção por talhão, taxa de erro em 0,04%, CPU do pod em 38%. No mesmo minuto, um cliente com 14 fazendas cadastradas abria o terceiro chamado da semana com a frase que eu já tinha ouvido umas quatrocentas vezes na época em que eu atendia telefone: "o sistema está lento".
Os dois estavam certos. Esse é o problema inteiro.
Peguei uma semana de duracao_requisicao_bucket daquela rota, joguei num histograma e mandei no canal antes de escrever qualquer explicação:
faixa (ms) requisições %
0 – 50 ████████████████████████████████████ 412.883 41,3
50 – 100 ██████████████████████████████████ 389.204 38,9
100 – 250 ███████████ 128.470 12,9
250 – 500 ███ 41.902 4,2
500 – 1000 ▏ 7.611 0,8
1000 – 2000 ▏ 912 0,1
2000 – 4000 ▏ 603 0,1
4000 – 8000 █ 14.207 1,4
8000 – 16000 ▏ 3.200 0,3
média 210 ms mediana 61 ms p95 360 ms p99 6.084 ms p99,9 13.500 msOlha o vale. Entre 500 ms e 4 s quase não tem ninguém, e aí, do nada, quatorze mil requisições voltam a se acumular na faixa dos 4 aos 8 segundos. Isso não é uma cauda que decai suave. É um segundo morro. Não existe uma população de requisições nesse sistema — existem duas, e elas não têm nada a ver uma com a outra. Uma responde em 61 ms. A outra passa seis segundos fazendo alguma coisa completamente diferente.
A média de 210 ms é o ponto exato entre os dois morros, onde não mora ninguém.
O que a média faz com a sua cabeça
Média e desvio padrão são ótimas ferramentas para descrever uma distribuição normal: simétrica, com um pico central, caindo igual para os dois lados. Altura de pessoas é assim. Tempo de resposta não é, nunca foi, e não tem como ser — existe um limite físico inferior (a requisição não pode demorar menos que a ida e volta na rede) e não existe limite superior nenhum. A distribuição é espremida contra a parede da esquerda e livre para esticar até o timeout à direita.
Quer a prova mais barata de que a sua latência não é normal? Calcule o desvio padrão. Naquela distribuição ali em cima ele dá 976 ms. Se a coisa fosse normal, 95% das requisições estariam entre a média menos dois desvios e a média mais dois: de −1.742 ms a 2.162 ms. Requisição que termina um segundo e meio antes de começar. É o número te dizendo, com todas as letras, que a ferramenta não serve para esse dado.
Percentil não assume forma nenhuma, e é por isso que ele funciona. p95 = 360 ms quer dizer uma coisa só: ordene todas as requisições da mais rápida para a mais lenta e a que está na posição 95% tem 360 ms. É contagem, não é modelo. Não tem hipótese escondida.
p99 não é o pior caso — é uma em cada cem
Aqui é onde eu vejo mais gente escorregar, inclusive gente boa. "p99 de 6 segundos? Ah, mas é só o pior caso, 1% dos usuários." Não. É 1% das requisições, e usuário não faz uma requisição.
A tela de acompanhamento de safra do nosso produto dispara oito chamadas quando abre: o resumo por talhão, a lista de movimentações, os alertas, o gráfico de produtividade, o filtro de safras, o cabeçalho do produtor, as permissões e o contador de pendências. Oito. A tela só termina de carregar quando a mais lenta responde.
A chance de nenhuma das oito cair na cauda é 0,998 = 0,9227. Ou seja, a chance de pelo menos uma cair é 7,7%. Uma em cada treze aberturas de tela pega um p99. Com o p95 fica pior de enxergar e melhor de entender: 0,958 = 0,663, então 33,7% das aberturas de tela têm pelo menos uma chamada acima do p95. Uma em cada três.
Um técnico de campo abre umas 30 telas por turno. São 240 chamadas. A chance de ele passar o dia inteiro sem encostar em nenhuma requisição de p99 é 0,99240 = 0,0896. Traduzindo: 91% dos usuários pegam o "1% de pior caso" todo santo dia. O painel continua verde. O chamado continua chegando.
Foi essa conta, escrita num guardanapo digital de três linhas, que virou a conversa com o produto. Não foi o gráfico bonito. Foi o 91%.
Média de p99 é um número que não existe
Descobri isso do jeito ruim. O painel tinha uma série chamada p99_5m e o cartão do topo mostrava a média dessa série na janela selecionada. Durante semanas eu olhei para "p99 (24h): 1,5 s" e achei que estava tudo sob controle.
Percentil é uma estatística de ordem. Ele não comuta com média, não é linear, não pode ser somado nem dividido. Tirar o p99 de cada minuto e depois tirar a média disso não te dá o p99 da hora — te dá um número sem nome e sem interpretação, que pode estar acima ou abaixo do valor real, e você não tem como saber para que lado. É o mesmo tipo de agregação que faz um pipeline de dados mentir sem quebrar nada: a conta roda, o resultado sai, e ninguém percebe que a semântica evaporou no caminho.
No nosso caso a distorção era brutal, porque a lentidão era concentrada. Numa janela de dez minutos das 17h — hora em que os romaneios do dia são fechados —, nove minutos tinham p99 de 340 ms e um minuto tinha 400 das suas 1.000 requisições acima de seis segundos. A média dos dez p99 dá 1,5 s. O p99 real das 10.000 requisições dá 11,2 s. Fator de sete.
O jeito certo é somar os buckets do histograma primeiro e calcular o percentil depois — uma vez só, no fim.
analise/percentil_por_bucket.py# buckets vêm do Prometheus, cru: {limite_superior_ms: contagem_no_bucket}
from statistics import mean
LIMITES_MS = [10, 25, 50, 100, 250, 500, 1000, 2500, 5000, 10000, 20000]
def percentil_de_histograma(buckets, p):
"""Interpola linearmente dentro do bucket onde o alvo cai."""
total = sum(buckets.values())
alvo = total * p
acumulado, piso = 0, 0.0
for limite in LIMITES_MS:
contagem = buckets.get(limite, 0)
if acumulado + contagem >= alvo and contagem:
fracao = (alvo - acumulado) / contagem
return piso + (limite - piso) * fracao
acumulado += contagem
piso = limite
return float(LIMITES_MS[-1]) # estourou o último bucket: só sabemos ">= 20s"
def somar_buckets(janelas):
total = {}
for janela in janelas:
for limite, contagem in janela.items():
total[limite] = total.get(limite, 0) + contagem
return total
minutos = carregar_buckets_por_minuto('2026-03-18T17:00', '2026-03-18T17:10')
media_dos_p99 = mean(percentil_de_histograma(m, 0.99) for m in minutos)
p99_da_janela = percentil_de_histograma(somar_buckets(minutos), 0.99)
print(f'média dos p99 por minuto: {media_dos_p99:.0f} ms') # 1.506 ms <- mentira
print(f'p99 da janela inteira: {p99_da_janela:.0f} ms') # 11.240 ms <- verdadeNo Prometheus isso é uma linha e a diferença mora inteira no sum by (le): histogram_quantile(0.99, sum by (le) (rate(duracao_requisicao_bucket[1h]))) soma os buckets antes de estimar o quantil. Se você escreveu avg_over_time(...p99...[1h]) em algum painel, apaga hoje.
Onde a cauda nasce
Cauda longa quase nunca é "o sistema está devagar". É um caminho de código diferente sendo tomado por uma minoria das requisições. Achar qual é o trabalho todo.
| Sintoma | Causa provável | Como confirmar |
|---|---|---|
| p50 estável, p99 péssimo só para alguns clientes | Plano de execução muda com o volume do filtro — o cliente grande cai no seq scan | pg_stat_statements agrupado por tenant + EXPLAIN ANALYZE com os parâmetros reais do cliente grande |
| Latência cresce proporcional ao tamanho da lista | N+1 no ORM | Contar consultas por requisição (span do APM ou log_min_duration_statement = 0 por 30 s em homologação) |
| Picos regulares, mesmo intervalo, todas as rotas juntas | Pausa de GC ou checkpoint do banco | Log de GC com timestamp e log_checkpoints = on; sobrepor com o gráfico de latência |
| p99 dispara com a concorrência mas CPU e I/O estão baixos | Pool de conexão esgotado ou lock | Métrica de espera na fila do pool; pg_locks junto de pg_stat_activity.wait_event |
| Degradação lenta ao longo de horas, resolve com restart | Vazamento de memória, de conexão ou cache sem TTL | Teste de resistência (soak) de 4 h+ com heap e contagem de conexões plotados no tempo |
| Cauda sem correlação com nada da aplicação | Throttling de CPU do container ou vizinho barulhento no nó | container_cpu_cfs_throttled_seconds_total e latência de disco do nó, não do pod |
O N+1 merece um parágrafo à parte porque ele é o mais covarde da lista. Em homologação, o produtor de teste tem 3 talhões: o ORM faz 1 consulta de talhões e mais 3 de movimentação, o teste E2E roda em 40 ms e passa verde. Em produção, o cliente que reclamou tem 1.847 talhões. São 1.848 consultas, e mesmo que cada uma custe ridículos 1,2 ms de ida e volta, isso é 2,2 segundos gastos só indo e voltando na rede. Nenhum teste funcional pega isso, porque funcionalmente está tudo certo. O resultado da tela está correto. Ele só chega tarde.
O pool de conexão é o mesmo tipo de armadilha, só que com aritmética ainda mais cruel. Se a consulta pesada segura uma conexão por 8 segundos e o pool tem 10, a vazão máxima daquele endpoint é 1,25 requisição por segundo. A décima primeira pessoa não está esperando o banco: está esperando na fila para poder esperar o banco. E o tempo dela aparece no percentil como se fosse lentidão de consulta.
Lendo o plano: onde os seis segundos estavam
A consulta é a de sempre: produção por talhão agregada por safra, com join na movimentação. Roda em 41 ms para quase todo mundo.
EXPLAIN (ANALYZE, BUFFERS) — antesSELECT t.id, t.nome, s.descricao,
SUM(m.quantidade_sacas) AS total_sacas
FROM movimentacao_producao m
JOIN talhao t ON t.id = m.talhao_id
JOIN safra s ON s.id = m.safra_id
WHERE m.tenant_id = 4471
AND m.tipo = 'COLHEITA'
AND m.data_movimento >= '2025-07-01'
AND m.data_movimento < '2026-07-01'
GROUP BY t.id, t.nome, s.descricao
ORDER BY total_sacas DESC;
Sort (actual time=8901.447..8903.115 rows=3184 loops=1)
Sort Key: (sum(m.quantidade_sacas)) DESC
-> HashAggregate (actual time=8886.902..8894.771 rows=3184 loops=1)
Group Key: t.id, t.nome, s.descricao
-> Hash Join (actual time=3.114..8102.663 rows=2094118 loops=1)
Hash Cond: (m.safra_id = s.id)
-> Hash Join (actual time=1.902..7480.221 rows=2094118 loops=1)
Hash Cond: (m.talhao_id = t.id)
-> Seq Scan on movimentacao_producao m
(cost=0.00..1201884.61 rows=2095837 width=24)
(actual time=0.042..6740.219 rows=2094118 loops=1)
Filter: ((tenant_id = 4471) AND (tipo = 'COLHEITA'::text)
AND (data_movimento >= '2025-07-01')
AND (data_movimento < '2026-07-01'))
Rows Removed by Filter: 39766095 -- leu 41,8 M para usar 2 M
Buffers: shared read=1187433 -- 9,1 GB saindo do disco
Planning Time: 0.412 ms
Execution Time: 8914.633 msTrês coisas para ler nessa saída, na ordem. Rows Removed by Filter: 39.766.095 — o banco leu a tabela inteira e jogou fora 95% do que leu. rows estimado 2.095.837 contra 2.094.118 real — o otimizador acertou a estimativa em 0,08%; ele não estava perdido, ele decidiu isso de propósito. E o Buffers, que é a métrica que eu mais ignorei durante anos e hoje é a primeira que eu olho.
Existia um índice em (tenant_id). Ele não foi usado, e o Postgres estava certo em não usar. Para esse tenant específico são 2,1 milhões de linhas de um total de 41,8 milhões — 5% da tabela. Buscar 2,1 milhões de ponteiros no índice e depois pular para 2,1 milhões de posições aleatórias no heap custa, com random_page_cost = 4, bem mais do que varrer tudo de forma sequencial. O otimizador ignora o índice de propósito quando a seletividade é ruim, e essa é a decisão correta na maioria das vezes. Pela mesma razão, índice em coluna de baixa cardinalidade não salva ninguém: tipo tem seis valores distintos em 41,8 milhões de linhas, então filtrar por ele ainda deixa alguns milhões.
A saída não é forçar o índice. É dar ao banco um índice que responda a consulta inteira sem tocar no heap.
EXPLAIN (ANALYZE, BUFFERS) — depois-- ordem importa: igualdade primeiro, range por último.
-- se data_movimento vier antes de tipo, o tipo vira Filter e não Index Cond.
CREATE INDEX CONCURRENTLY idx_mov_prod_tenant_tipo_data
ON movimentacao_producao (tenant_id, tipo, data_movimento DESC)
INCLUDE (talhao_id, safra_id, quantidade_sacas);
Sort (actual time=209.884..210.331 rows=3184 loops=1)
-> HashAggregate (actual time=198.774..206.910 rows=3184 loops=1)
-> Hash Join (actual time=2.441..131.882 rows=2094118 loops=1)
-> Index Only Scan using idx_mov_prod_tenant_tipo_data on movimentacao_producao m
(actual time=0.071..96.418 rows=2094118 loops=1)
Index Cond: ((tenant_id = 4471) AND (tipo = 'COLHEITA'::text)
AND (data_movimento >= '2025-07-01')
AND (data_movimento < '2026-07-01'))
Heap Fetches: 0 -- INCLUDE pagou: não voltou na tabela
Buffers: shared hit=31204 read=8871
Planning Time: 0.508 ms
Execution Time: 213.207 ms8.914 ms para 213 ms. O Heap Fetches: 0 é a linha que confirma que o INCLUDE valeu a pena — sem ele, o índice acha as linhas rápido e depois desperdiça tudo indo buscar as três colunas no heap. E o CONCURRENTLY não é frescura: sem ele, criar esse índice tranca escrita na tabela de movimentação, o que em plena colheita é um jeito criativo de transformar um problema de latência num incidente.
O índice que eu criei e que só piorou tudo
Antes de chegar nesse, eu criei um índice simples em (tipo). Fazia sentido na minha cabeça: o filtro cita tipo, então indexa tipo. Subiu numa quinta.
Não melhorou um milissegundo de leitura — seletividade de 1/6 não convence otimizador nenhum. Mas a importação noturna de romaneio, que insere umas 380 mil linhas naquela tabela, foi de 4m12s para 6m48s, porque agora cada insert tinha mais uma árvore B para manter. Só fui ligar uma coisa à outra dez dias depois, quando o pessoal de infra perguntou por que a janela de carga estava encostando no horário do backup. Rodei o pg_stat_user_indexes e o meu índice estava lá, com idx_scan = 0. Zero. Ele nunca tinha sido usado uma vez sequer, e estava cobrando pedágio em toda escrita há dez dias.
Índice não é grátis. Ele é uma aposta em que a leitura vale mais que a escrita, e a aposta precisa ser conferida depois — idx_scan = 0 em índice com mais de uma semana de vida é candidato a DROP, sem sentimentalismo.
Teste de carga que serve pra alguma coisa
"Vamos simular 1000 usuários simultâneos." De onde saiu esse mil? Ninguém sabe. É o número que aparece quando alguém quer parecer rigoroso sem ter olhado dado nenhum. E "usuário simultâneo" nem é uma unidade útil, porque um cara com a tela aberta tomando café não gera carga alguma.
A modelagem sai do log. Peguei o access log de três terças-feiras, contei requisição por rota por minuto e o desenho apareceu sozinho: 62% do tráfego do dia acontece entre 6h40 e 9h20, quando os romaneios da noite anterior são lançados. O mix no pico é 71% leitura de painel, 18% lançamento de movimentação, 6% geração de relatório e 5% o resto do mundo. O pico sustentado é de 130 requisições por segundo. Esse é o número. Não é mil.
Três testes diferentes, que muita gente trata como um só. Carga roda no pico esperado e responde "estamos dentro do acordado?". Estresse sobe até quebrar e responde "onde é o teto e como ele quebra — degrada ou capota?". Resistência, o soak, roda quatro horas ou mais na carga normal e responde "o que apodrece com o tempo?". O soak é o único que pega vazamento de memória, conexão que não volta pro pool e cache sem TTL, e é justamente o que todo mundo pula porque demora.
carga/producao-por-talhao.jsimport http from 'k6/http';
import { check, group } from 'k6';
import { Trend } from 'k6/metrics';
const painelTalhao = new Trend('painel_talhao', true);
const lancamento = new Trend('lancamento_movimentacao', true);
export const options = {
scenarios: {
// pico real medido no access log: 6h40–9h20, teto de 130 req/s.
// arrival-rate e não VUs fixos: se o servidor engasgar, a carga NÃO cai
// junto — que é exatamente o que o produtor rural faz (clica de novo).
jornada_matinal: {
executor: 'ramping-arrival-rate',
startRate: 18,
timeUnit: '1s',
preAllocatedVUs: 80,
maxVUs: 400,
stages: [
{ target: 48, duration: '3m' },
{ target: 130, duration: '6m' },
{ target: 130, duration: '14m' },
{ target: 18, duration: '3m' },
],
},
},
thresholds: {
// o SLO acordado com o produto, escrito como código executável
'painel_talhao': ['p(95)<800', 'p(99)<2500'],
'lancamento_movimentacao': ['p(99)<1500'],
// o tenant gordo tem orçamento próprio, senão ele some na média geral
'http_req_duration{perfil:tenant_grande}': ['p(99)<4000'],
// abortOnFail: se o erro explodir, não gasta 20 min medindo escombro
'http_req_failed': [{ threshold: 'rate<0.005', abortOnFail: true }],
},
};
const BASE = __ENV.API_URL;
const TENANTS = JSON.parse(open('./tenants-com-cauda.json'));
export default function () {
// 1 em cada 12 iterações usa o tenant de 2,1 M de movimentações
const sorteio = Math.random();
const tenant = sorteio < 0.083 ? TENANTS.grande : TENANTS.medianos[Math.floor(sorteio * TENANTS.medianos.length)];
const params = {
headers: { Authorization: `Bearer ${tenant.token}` },
tags: { perfil: tenant.perfil },
};
group('painel de safra', () => {
const r = http.get(`${BASE}/producao/por-talhao?safra=${tenant.safraAtual}`, params);
painelTalhao.add(r.timings.duration);
check(r, { 'painel 200': (res) => res.status === 200 });
});
if (sorteio < 0.18) {
group('lançar movimentação', () => {
const r = http.post(`${BASE}/movimentacoes`, JSON.stringify({
talhaoId: tenant.talhaoPadrao,
tipo: 'COLHEITA',
quantidadeSacas: 240,
dataMovimento: new Date().toISOString(),
}), { ...params, headers: { ...params.headers, 'Content-Type': 'application/json' } });
lancamento.add(r.timings.duration);
check(r, { 'movimentação 201': (res) => res.status === 201 });
});
}
}Quando um threshold estoura, o k6 sai com código 99 e o stage do Jenkins fica vermelho. Isso não é detalhe de implementação, é a coisa toda: enquanto o resultado do teste de carga for um PDF que alguém lê na sexta, ele não muda decisão nenhuma. Vira portão no pipeline e muda. O mesmo raciocínio que me fez brigar pelo tempo da suíte de regressão vale aqui — número que não bloqueia merge é número decorativo.
O executor também não é escolha de gosto. Com VUs fixos você tem um modelo fechado: se o servidor demora mais, cada VU manda menos requisição e a carga cai sozinha exatamente quando você mais precisava dela. O sistema parece estabilizar num platô confortável que não existe na vida real, porque o usuário de verdade não espera educadamente — ele aperta F5.
Carga contra base de brinquedo é teatro
Aquele tenants-com-cauda.json ali em cima é o ponto mais importante do script inteiro, e é o que quase sempre falta. Rodar carga contra um banco com 200 registros não testa absolutamente nada, porque o plano de execução muda com o volume. Na base pequena o Postgres usa índice em tudo, o join vira nested loop, cabe inteiro em memória e o p99 dá 40 ms. Você olha o relatório e libera. O plano que roda em produção nem foi exercitado uma vez.
E não basta volume — precisa da distribuição. Gerar 2 milhões de movimentações espalhadas uniformemente entre 400 tenants dá 5 mil linhas para cada um, e nesse mundo todo mundo é rápido. A realidade é lei de potência: um tenant sozinho tem 2,1 milhões de linhas e os outros 399 dividem o resto. É esse gordo que quebra a consulta e é exatamente ele que o gerador de dados sintéticos nunca cria, porque quem escreveu o gerador pensou em "dado realista" como sinônimo de "dado médio". Massa de carga é a mesma dívida técnica que a massa de teste funcional, só que com juros maiores, porque o erro aqui não aparece como teste vermelho — aparece como falsa confiança.
Eu já entreguei essa falsa confiança. Rodei carga numa base restaurada de homologação, com 180 mil movimentações, deu p99 de 190 ms, escrevi no card que estava aprovado. Duas semanas depois, produção. Aquela mesma rota, 6,1 segundos.
Transformar "tem que ser rápido" em número
"O sistema tem que ser rápido" não é requisito, é sentimento. Não dá pra testar, não dá pra falhar, não dá pra priorizar contra uma feature. Um SLO dá: 99% das consultas de produção por talhão respondem em menos de 1,2 s, medido em janela móvel de 28 dias.
Com isso vem o error budget, que é a parte que muda comportamento de time. Se a rota faz 4,3 milhões de requisições por mês, 1% são 43 mil requisições que podem estourar 1,2 s sem que nada aconteça. Esse é o orçamento. Se na segunda semana você já queimou 70% dele, a conversa deixa de ser "acha que dá pra otimizar isso?" e passa a ser aritmética: a próxima sprint paga dívida de performance, porque o número acordado com o negócio está prestes a ser quebrado. E se o mês fecha com 18% do orçamento gasto, para de otimizar — você está entregando qualidade que ninguém pediu e cobrando por ela em feature não entregue.
"Mas isso não é otimização prematura?"
É o contra-argumento que sempre aparece, e vem com a autoridade do Knuth em cima. Ele merece resposta de verdade, não uma versão de palha.
Primeiro: a frase original é maior do que a versão que circula. Knuth escreveu que devemos esquecer as pequenas eficiências em cerca de 97% do tempo, que a otimização prematura é a raiz de todo mal, e que não devemos abrir mão das nossas oportunidades naqueles 3% críticos. A segunda metade some das citações porque é menos divertida.
Segundo, e mais importante: aquilo é um argumento sobre micro-otimização especulativa. Trocar laço por laço porque parece mais rápido, reescrever em linguagem mais baixo nível sem perfil, cachear coisa que ninguém pediu. Nada disso tem a ver com escolher a ordem das colunas de um índice, com decidir se a listagem vai paginar, ou com medir. Medir nunca é prematuro. Medir é como você descobre quais são os 3%.
E o crítico tem razão numa parte que eu levei tempo pra aceitar. Eu já desnormalizei tabela preventivamente por causa de um problema de escala que nunca chegou, e o custo disso — consistência a mais para manter, código de sincronização, bug de dado divergente — foi pago por dois anos, todo sprint, por uma lentidão hipotética. Isso é exatamente o mal que o Knuth descreveu. A linha que eu uso hoje: decisão estrutural que é cara de reverter depois (modelo de dado, contrato de API, se a coleção é paginada) se decide no começo, com a cabeça no volume real do maior cliente. Micro-otimização de trecho quente se decide com perfil na mão, nunca antes.
Quando eu atendia suporte, chegava chamado dizendo "está lento" e eu não tinha o que responder além de pedir print. Hoje eu tenho histograma, tenho percentil agregado direito, tenho plano de execução e tenho um limiar que barra merge. Mudou tudo, menos uma coisa: continua sendo o cliente que descobre primeiro.
O painel verde nunca foi uma medida de que o sistema está bom. É uma medida de que a maioria está bem — e a maioria nunca liga pro suporte. Quem liga é a cauda. E a cauda, no nosso caso e provavelmente no seu, é composta dos clientes que têm mais dado, mais uso e mais contrato. São os que mais importam, tratados pela sua métrica principal como ruído estatístico.
Apaga o cartão de média do painel. Sério. Bota o p99 no lugar e depois me conta se alguém sentiu falta.
