Profiling

O código desta página foi executado nas cinco linguagens, num núcleo de CPU reservado, e cada versão lenta foi medida com o profiler da sua linguagem.

O relatório, lento e corrigido, em cada linguagem

Cada versão gera 100 mil pedidos de 20 mil clientes e monta uma linha por cliente, com o total. A diferença entre as duas versões está numa função: a lenta confere se o cliente já está numa lista percorrendo a lista; a corrigida usa um conjunto. Com a variável SO=lento, o programa roda só a versão lenta, para o profiler.

type Pedido = { clienteId: number; total: number };

function gerarPedidos(n: number): Pedido[] {
  return Array.from({ length: n }, (_, i) => ({ clienteId: (i * 7919) % 20_000, total: i % 500 }));
}

function formatarLinha(clienteId: number, total: number): string {
  return `cliente ${clienteId}: R$ ${total.toFixed(2)}`;
}

// Versão lenta: includes percorre a lista inteira a cada pedido (O(n²))
function clientesUnicosLento(pedidos: Pedido[]): number[] {
  const clientes: number[] = [];
  for (const p of pedidos) if (!clientes.includes(p.clienteId)) clientes.push(p.clienteId);
  return clientes;
}

// Versão corrigida: o Set confere a presença em tempo constante
function clientesUnicos(pedidos: Pedido[]): number[] {
  return [...new Set(pedidos.map((p) => p.clienteId))];
}

function relatorio(pedidos: Pedido[], unicos: (p: Pedido[]) => number[]): string[] {
  const totais = new Map<number, number>();
  for (const p of pedidos) totais.set(p.clienteId, (totais.get(p.clienteId) ?? 0) + p.total);
  return unicos(pedidos).map((c) => formatarLinha(c, totais.get(c)!));
}

const pedidos = gerarPedidos(100_000);
const versoes = [["lento", clientesUnicosLento], ["corrigido", clientesUnicos]] as const;
for (const [nome, f] of versoes) {
  if (process.env.SO === "lento" && nome !== "lento") continue;
  const inicio = performance.now();
  const linhas = relatorio(pedidos, f);
  const ms = (performance.now() - inicio).toFixed(0);
  console.log(`${nome}: ${linhas.length} clientes em ${ms} ms`);
}

import os
import time
from collections import defaultdict


def gerar_pedidos(n: int) -> list[tuple[int, int]]:
    return [((i * 7919) % 20_000, i % 500) for i in range(n)]


def formatar_linha(cliente_id: int, total: int) -> str:
    return f"cliente {cliente_id}: R$ {total:.2f}"


def clientes_unicos_lento(pedidos: list[tuple[int, int]]) -> list[int]:
    # Versão lenta: "not in" numa lista percorre a lista inteira a cada pedido (O(n²))
    clientes: list[int] = []
    for cliente_id, _ in pedidos:
        if cliente_id not in clientes:
            clientes.append(cliente_id)
    return clientes


def clientes_unicos(pedidos: list[tuple[int, int]]) -> list[int]:
    # Versão corrigida: o dicionário guarda a ordem e confere a presença em tempo constante
    return list(dict.fromkeys(cliente_id for cliente_id, _ in pedidos))


def relatorio(pedidos, unicos) -> list[str]:
    totais: dict[int, int] = defaultdict(int)
    for cliente_id, total in pedidos:
        totais[cliente_id] += total
    return [formatar_linha(c, totais[c]) for c in unicos(pedidos)]


pedidos = gerar_pedidos(100_000)
for nome, f in [("lento", clientes_unicos_lento), ("corrigido", clientes_unicos)]:
    if os.environ.get("SO") == "lento" and nome != "lento":
        continue
    inicio = time.perf_counter()
    linhas = relatorio(pedidos, f)
    print(f"{nome}: {len(linhas)} clientes em {(time.perf_counter() - inicio) * 1000:.0f} ms")

package main

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

type Pedido struct{ ClienteID, Total int }

func gerarPedidos(n int) []Pedido {
	pedidos := make([]Pedido, n)
	for i := range pedidos {
		pedidos[i] = Pedido{(i * 7919) % 20_000, i % 500}
	}
	return pedidos
}

func formatarLinha(clienteID, total int) string {
	return fmt.Sprintf("cliente %d: R$ %.2f", clienteID, float64(total))
}

// clientesUnicosLento: slices.Contains percorre a lista inteira a cada pedido (O(n²))
func clientesUnicosLento(pedidos []Pedido) []int {
	var clientes []int
	for _, p := range pedidos {
		if !slices.Contains(clientes, p.ClienteID) {
			clientes = append(clientes, p.ClienteID)
		}
	}
	return clientes
}

// clientesUnicos: o mapa confere a presença em tempo constante
func clientesUnicos(pedidos []Pedido) []int {
	vistos := make(map[int]bool, len(pedidos))
	var clientes []int
	for _, p := range pedidos {
		if !vistos[p.ClienteID] {
			vistos[p.ClienteID] = true
			clientes = append(clientes, p.ClienteID)
		}
	}
	return clientes
}

func relatorio(pedidos []Pedido, unicos func([]Pedido) []int) []string {
	totais := map[int]int{}
	for _, p := range pedidos {
		totais[p.ClienteID] += p.Total
	}
	var linhas []string
	for _, c := range unicos(pedidos) {
		linhas = append(linhas, formatarLinha(c, totais[c]))
	}
	return linhas
}

func main() {
	// Com PERFIL=arquivo, grava um perfil de CPU para o go tool pprof
	if destino := os.Getenv("PERFIL"); destino != "" {
		f, _ := os.Create(destino)
		pprof.StartCPUProfile(f)
		defer pprof.StopCPUProfile()
	}
	pedidos := gerarPedidos(100_000)
	versoes := []struct {
		nome string
		f    func([]Pedido) []int
	}{{"lento", clientesUnicosLento}, {"corrigido", clientesUnicos}}
	for _, v := range versoes {
		if os.Getenv("SO") == "lento" && v.nome != "lento" {
			continue
		}
		inicio := time.Now()
		linhas := relatorio(pedidos, v.f)
		fmt.Printf("%s: %d clientes em %d ms\n", v.nome, len(linhas), time.Since(inicio).Milliseconds())
	}
}

import java.util.ArrayList;
import java.util.HashMap;
import java.util.LinkedHashSet;
import java.util.List;
import java.util.function.Function;

public class Relatorio {
    record Pedido(int clienteId, int total) {}

    static List<Pedido> gerarPedidos(int n) {
        var pedidos = new ArrayList<Pedido>(n);
        for (int i = 0; i < n; i++) pedidos.add(new Pedido((int) ((i * 7919L) % 20_000), i % 500));
        return pedidos;
    }

    static String formatarLinha(int clienteId, int total) {
        return String.format("cliente %d: R$ %.2f", clienteId, (double) total);
    }

    // Versão lenta: contains percorre a lista inteira a cada pedido (O(n²))
    static List<Integer> clientesUnicosLento(List<Pedido> pedidos) {
        var clientes = new ArrayList<Integer>();
        for (var p : pedidos) if (!clientes.contains(p.clienteId())) clientes.add(p.clienteId());
        return clientes;
    }

    // Versão corrigida: o LinkedHashSet guarda a ordem e confere a presença em tempo constante
    static List<Integer> clientesUnicos(List<Pedido> pedidos) {
        var clientes = new LinkedHashSet<Integer>();
        for (var p : pedidos) clientes.add(p.clienteId());
        return new ArrayList<>(clientes);
    }

    static List<String> relatorio(List<Pedido> pedidos,
                                  Function<List<Pedido>, List<Integer>> unicos) {
        var totais = new HashMap<Integer, Integer>();
        for (var p : pedidos) totais.merge(p.clienteId(), p.total(), Integer::sum);
        var linhas = new ArrayList<String>();
        for (var c : unicos.apply(pedidos)) linhas.add(formatarLinha(c, totais.get(c)));
        return linhas;
    }

    public static void main(String[] args) {
        var pedidos = gerarPedidos(100_000);
        var soLento = "lento".equals(System.getenv("SO"));
        for (var nome : List.of("lento", "corrigido")) {
            if (soLento && !nome.equals("lento")) continue;
            Function<List<Pedido>, List<Integer>> f =
                nome.equals("lento") ? Relatorio::clientesUnicosLento : Relatorio::clientesUnicos;
            long inicio = System.nanoTime();
            var linhas = relatorio(pedidos, f);
            long ms = (System.nanoTime() - inicio) / 1_000_000;
            System.out.printf("%s: %d clientes em %d ms%n", nome, linhas.size(), ms);
        }
    }
}

using System.Diagnostics;
using System.Globalization;

var pedidos = Enumerable.Range(0, 100_000)
    .Select(i => new Pedido((int)(i * 7919L % 20_000), i % 500)).ToList();
var soLento = Environment.GetEnvironmentVariable("SO") == "lento";
foreach (var (nome, f) in new (string, Func<List<Pedido>, List<int>>)[]
             { ("lento", Funcoes.ClientesUnicosLento), ("corrigido", Funcoes.ClientesUnicos) })
{
    if (soLento && nome != "lento") continue;
    var relogio = Stopwatch.StartNew();
    var linhas = Funcoes.Relatorio(pedidos, f);
    Console.WriteLine($"{nome}: {linhas.Count} clientes em {relogio.ElapsedMilliseconds} ms");
}

record Pedido(int ClienteId, int Total);

static class Funcoes
{
    static string FormatarLinha(int clienteId, int total) =>
        string.Create(CultureInfo.InvariantCulture, $"cliente {clienteId}: R$ {total:F2}");

    // Versão lenta: Contains percorre a lista inteira a cada pedido (O(n²))
    public static List<int> ClientesUnicosLento(List<Pedido> pedidos)
    {
        var clientes = new List<int>();
        foreach (var p in pedidos) if (!clientes.Contains(p.ClienteId)) clientes.Add(p.ClienteId);
        return clientes;
    }

    // Versão corrigida: o HashSet confere a presença em tempo constante
    public static List<int> ClientesUnicos(List<Pedido> pedidos)
    {
        var vistos = new HashSet<int>();
        return pedidos.Select(p => p.ClienteId).Where(vistos.Add).ToList();
    }

    public static List<string> Relatorio(List<Pedido> pedidos, Func<List<Pedido>, List<int>> unicos)
    {
        var totais = new Dictionary<int, int>();
        foreach (var p in pedidos)
            totais[p.ClienteId] = totais.GetValueOrDefault(p.ClienteId) + p.Total;
        return unicos(pedidos).Select(c => FormatarLinha(c, totais[c])).ToList();
    }
}

O resultado, nas cinco linguagens

	Versão lenta	Versão corrigida	Quantas vezes mais rápida
TypeScript	894 ms	28 ms	32
Python	11.374 ms	30 ms	379
Go	286 ms	12 ms	24
Java	1.011 ms	177 ms	6
C#	172 ms	10 ms	17

As cinco versões encontraram os mesmos 20 mil clientes. A versão corrigida em Java ficou mais lenta que as outras. Os candidatos são a compilação inicial da JVM, que ainda não otimizou o código numa execução tão curta, e o String.format das 20 mil linhas; o teste não mediu qual dos dois pesa, e é exatamente o que um novo perfil diria.

O que muda de uma linguagem para outra

	Busca linear (lenta)	Conjunto (corrigida)
TypeScript	`Array.includes`	`Set`
Python	`in` numa `list`	`dict.fromkeys`, que guarda a ordem
Go	`slices.Contains`	`map[int]bool`
Java	`ArrayList.contains`	`LinkedHashSet`, que guarda a ordem
C#	`List.Contains`	`HashSet` com `Where(vistos.Add)`

A busca linear é rápida o bastante em todas as linguagens com poucos itens. O problema é o número de itens multiplicado pelo número de buscas: 100 mil pedidos procurando numa lista que chega a 20 mil.

Os comandos de profiling

Os comandos usados no teste, um por linguagem.

Node: grava um arquivo .cpuprofile, que abre no painel de desempenho do Chrome ou no Speedscope:

SO=lento node --cpu-prof relatorio.ts

Python: o cProfile, ordenado pelo tempo próprio de cada função:

SO=lento python3 -m cProfile -s tottime relatorio.py

Go: o programa grava o perfil quando recebe PERFIL (o trecho com runtime/pprof no exemplo), e o pprof lista as funções:

SO=lento PERFIL=cpu.prof ./rel
go tool pprof -top -nodecount=5 rel cpu.prof
go tool pprof -http=:8080 rel cpu.prof   # gráfico de chama no navegador

Java: uma gravação do JDK Flight Recorder e as amostras de execução:

SO=lento java -XX:StartFlightRecording=filename=rec.jfr,settings=profile Relatorio.java
jfr print --events jdk.ExecutionSample rec.jfr

C#: o dotnet-trace (instalado com dotnet tool install -g dotnet-trace), que já amostra a CPU no perfil padrão:

SO=lento dotnet-trace collect -o rel.nettrace -- ./app
dotnet-trace report rel.nettrace topN -n 6

No teste, a primeira tentativa no C# usou --profile cpu-sampling, o nome de versões anteriores, e a versão 10 do dotnet-trace recusou: The specified profile 'cpu-sampling' does not apply. Sem --profile, o padrão incluiu a amostragem de CPU.

E a memória no Python, com o tracemalloc:

import tracemalloc

tracemalloc.start()
# ... o código medido ...
for estatistica in tracemalloc.take_snapshot().statistics("lineno")[:3]:
    print(estatistica)

Lista de revisão

Antes de otimizar

Existe uma medida do problema, com dados e carga realistas?
O sintoma é CPU alta, espera, memória crescendo ou pausas do coletor? O profiler escolhido mede esse sintoma?

Lendo o perfil

A análise olha o tempo acumulado, e não só o próprio?
O caminho até o código da aplicação foi seguido na pilha?
A conclusão leva em conta funções embutidas pelo compilador?

Depois de corrigir

O ganho foi confirmado medindo de novo, sem o profiler?
Há um benchmark ou teste de desempenho que impede o gargalo de voltar?

Em produção

O time sabe como coletar um perfil de uma instância em produção?
Há profiling contínuo, ou ao menos um caminho rápido para ativá-lo?

O relatório, lento e corrigido, em cada linguagem

O resultado, nas cinco linguagens

O que muda de uma linguagem para outra

Os comandos de profiling

Lista de revisão

Prompts para aprofundar

Fazer profiling na minha linguagem

Proteger o desempenho com benchmarks

Revisar código em busca de gargalos