Profiling com JFR e startup

Um médico que atende um paciente com dor de cabeça pede exames antes de receitar. Ele não chuta a causa com base na última reclamação, e também não faz todos os exames do catálogo de uma vez. O JFR (Java Flight Recorder) é o exame de imagem da JVM. Ele fica embutido no próprio runtime, grava o que a aplicação faz em eventos com horário, e deixa o registro num arquivo que pode ser lido depois. Você não precisa instalar um agente externo nem reiniciar o processo com outra ferramenta para começar a gravar.

Esta aula trata de duas perguntas que aparecem juntas em produção. A primeira é como descobrir, com uma gravação do JFR, quem está alocando memória e onde. A segunda é quanto tempo o serviço leva para começar a responder depois de subir, e o que os caches de classes da JVM mudam nesse tempo. Para a segunda, comparamos o CDS, o AppCDS e o cache AOT do JDK 25, e deixamos claro o que não foi medido, como o GraalVM Native Image, que não está instalado nesta máquina. Todas as medições foram feitas em 20/10/2026, com o kotlinc 2.1.21 e o Temurin 21.0.8, com o JDK 25 instalado em paralelo para o cache AOT.

o mapa da aula

Começamos pelo JFR: o que ele grava, como ligar a gravação com uma opção da JVM e por que o perfil escolhido muda o custo. Depois lemos uma gravação real com jfr summary e jfr print, e mostramos como agregar as amostras de alocação por linha de código. Em seguida tratamos das pausas de GC, que o JFR também registra. A segunda metade é o startup: explicamos por que a JVM demora para subir, o que o CDS guarda, a diferença entre o arquivo padrão e o AppCDS, e o cache AOT do JDK 25. A aula termina com erros comuns e exercícios.

1. o que o JFR grava

O JFR é um mecanismo de eventos que vem dentro da JVM. O runtime tem pontos de instrumentação que disparam eventos quando algo acontece: uma coleta de lixo, uma amostra de alocação, uma chamada de método que demorou, uma thread que iniciou. Cada evento recebe um horário e, quando faz sentido, a pilha de chamadas da thread que o disparou. O resultado é um arquivo binário, com extensão .jfr, que você lê depois com ferramentas do próprio JDK.

Essa forma de gravar importa por dois motivos. O primeiro é que a informação sai de dentro do runtime, então o profiler conhece o que a JVM conhece, como a coleta que acabou de acontecer e o tamanho do heap naquele momento. O segundo é que o custo pode ser controlado pelo perfil de eventos escolhido. A documentação do JFR no JDK 21 diz que o perfil profile coleta mais dados e tem mais overhead, enquanto o default tem overhead baixo. Ou seja, a escolha do perfil é uma troca entre detalhe e custo, e não uma escolha de qualidade.

Para começar uma gravação, passe a opção -XX:StartFlightRecording na linha de comando, com o nome do arquivo e o perfil. Em um processo que já está rodando, a mesma gravação pode ser iniciada com jcmd <pid> JFR.start, que é o caminho para investigar um serviço em produção sem reiniciá-lo. Nesta aula usamos a opção de linha de comando, porque ela deixa o experimento reproduzível.

O programa de teste cria, a cada rodada, quarenta objetos Item, monta uma lista com eles e transforma os números de sku em texto com joinToString. Ele repete isso dois milhões de vezes, para que a gravação tenha tempo suficiente para registrar amostras.

class Item(val sku: Int, val preco: Int)

var sink = 0

fun responder(i: Int): String {
    val itens = ArrayList<Item>()
    for (j in 0 until 40) itens.add(Item(j + i, j * 3))
    val texto = itens.joinToString(",") { it.sku.toString() }
    return texto
}

fun main(args: Array<String>) {
    val rodadas = args.getOrNull(0)?.toInt() ?: 200_000
    for (i in 0 until rodadas) {
        sink += responder(i).length
    }
    println("fim sink=$sink")
}

A execução foi esta, com a saída do próprio programa:

java -XX:StartFlightRecording=filename=rec2.jfr,settings=profile -cp jfr.jar JfrKt 2000000
fim sink=593559845

O arquivo rec2.jfr ficou com cerca de 2 segundos de duração. A opção settings=profile foi escolhida porque o objetivo era ver amostras de alocação, que o perfil padrão grava com menos detalhe.

2. lendo a gravação: resumo e eventos

O primeiro comando para qualquer gravação é o jfr summary, que mostra quantos eventos de cada tipo foram gravados e quanto espaço eles ocupam. Ele serve para confirmar que a gravação tem o que você procura antes de gastar tempo com a análise. Este é o trecho real da saída para a gravação desta aula:

 Duration: 2 s

 Event Type                              Count  Size (bytes)
=============================================================
 jdk.ObjectAllocationSample                599          8456
 jdk.ExecutionSample                       129          1290
 jdk.GarbageCollection                      20           405
 jdk.YoungGarbageCollection                 20           241
 jdk.G1GarbageCollection                    20           241

Os eventos de amostragem de alocação, jdk.ObjectAllocationSample, são os que interessam para a pergunta “quem aloca”. Cada um registra a classe do objeto, o peso estimado da amostra em bytes, a thread e a pilha. O peso importa porque a JVM não registra todas as alocações: ela amostra algumas e atribui a cada amostra um peso que representa as alocações parecidas. Por isso a contagem do JFR é uma estimativa, com erro estatístico que diminui quando há muitas amostras.

O comando jfr print mostra os eventos com o detalhe completo. O filtro --events escolhe o tipo, e --stack-depth controla quantos quadros da pilha aparecem (o padrão é 5). Este é um dos eventos de Item da gravação, com a profundidade reduzida a dois quadros:

jdk.ObjectAllocationSample {
  startTime = 12:46:55.536 (2026-10-20)
  objectClass = Item (classLoader = app)
  weight = 383.0 kB
  eventThread = "main" (javaThreadId = 1)
  stackTrace = [
    JfrKt.responder(int) line: 7
    JfrKt.main(String[]) line: 15
  ]
}

A linha 7 é a que cria os Item dentro do laço, e a pilha mostra que a chamada veio do main, na linha 15. Para responder à pergunta “quem aloca mais”, não basta olhar um evento. É preciso somar as amostras pelo quadro do topo da pilha. Fizemos isso com jfr print seguido de uniq -c, o que é suficiente para uma gravação pequena. O comando jfr tem outros subcomandos de visualização, que esta aula não testou, e o JDK Mission Control faz a mesma leitura com interface gráfica.

O resultado da soma pelo quadro do topo está nesta tabela:

A tabela mostra um padrão que a leitura do código sugere, mas que a gravação confirma com números. A maior parte das alocações vem da conversão de sku em texto dentro do joinToString, e as cópias de arrays são o crescimento dos buffers de texto. Os Item aparecem em terceiro lugar na soma, com 130 amostras, o que é menos do que a intuição de quem olha o código costuma atribuir a eles. O que a aula ensina aqui é o método para descobrir essa proporção, que vale para qualquer código.

A figura acompanha o caminho que a informação percorre. A alocação acontece no código da aplicação, a JVM amostra e grava o evento com a pilha, o arquivo guarda tudo, e o jfr print lê o arquivo. A agregação por linha é o passo que transforma centenas de eventos em uma decisão. A caixa à direita mostra que o mesmo arquivo serve para pausas do coletor, que são outro tipo de evento e outra leitura.

Pergunta de entrevistaO que é o JFR e como você o usa para investigar um serviço em produção?

O JFR é um mecanismo de eventos que vem dentro da JVM. O runtime dispara eventos quando algo acontece, como uma coleta de lixo, uma amostra de alocação ou uma thread que iniciou, e cada evento recebe um horário e, quando faz sentido, a pilha de chamadas. O resultado é um arquivo binário com extensão .jfr. Como a informação sai de dentro do runtime, o profiler conhece o que a JVM conhece, e o custo é controlado pelo perfil de eventos: o perfil profile coleta mais dados e tem mais overhead. Inicio a gravação com -XX:StartFlightRecording na linha de comando, ou com jcmd JFR.start num processo que já está rodando, sem reiniciar o serviço. Escolho o perfil pesando o detalhe que preciso contra o overhead.

3. pausas de GC no JFR

O JFR também grava as coletas de lixo, com o evento jdk.GarbageCollection. Ele é uma visão estruturada do que o log de GC mostra, com a causa e a duração de cada coleta. Esta é a primeira coleta da gravação:

jdk.GarbageCollection {
  startTime = 12:46:55.509 (2026-10-20)
  duration = 8.15 ms
  gcId = 0
  name = "G1New"
  cause = "G1 Evacuation Pause"
  sumOfPauses = 8.15 ms
  longestPause = 8.15 ms
  eventThread = "VM Thread" (osThreadId = 18179)
}

A gravação tem 20 desses eventos, todos da geração jovem do G1, e somados eles dão 35,5 ms de pausas, com a maior em 8,15 ms. A conta é simples de fazer com o campo sumOfPauses, e ela responde à pergunta que a aula de Heap, GC e pausas fez com o log: quanto tempo a aplicação ficou parada por coleta. A diferença de leitura é que aqui o evento já vem com o nome do coletor e a causa, sem precisar filtrar linhas de texto.

A gravação mostra o conjunto de alocação e pausa, que é o que um diagnóstico de latência precisa. A aula não discute a espera de alocação do ZGC, que aparece no log e não como um evento de pausa comum, e a aula de GC trata desse caso.

4. startup: por que a JVM demora

Um serviço que sobe lento custa tempo em cada implantação e em cada reinício, e em uma plataforma com escala automática ele custa mais ainda, porque a instância nova só ajuda depois que termina de subir. Parte desse tempo é inevitável. A JVM precisa carregar as classes, verificar se o bytecode é seguro, preparar a memória e executar a inicialização de cada classe. Um programa pequeno gasta pouco nisso, mas um framework grande como o Spring carrega muitas classes antes de atender a primeira requisição, e esta aula não mediu quantas.

O CDS (Class Data Sharing) reduz parte desse trabalho. Ele guarda num arquivo uma imagem das classes já lidas, pronta para ser mapeada na memória, de modo que a JVM não precisa analisar o bytecode de novo. A documentação do JDK 21 diz que, a partir do JDK 12, um arquivo CDS padrão já vem empacotado com o binário do JDK, o que explica por que o startup da JVM já é mais rápido do que seria sem ele. O AppCDS estende o mecanismo para as classes da aplicação, em um arquivo gerado a partir de uma execução de treino.

Para criar um AppCDS, rodamos a aplicação uma vez com -XX:ArchiveClassesAtExit=app21.jsa, e depois usamos o arquivo com -XX:SharedArchiveFile=app21.jsa. A página de CDS do JDK 21 mostra como exemplo a opção -XX:+AutoCreateSharedArchive com -XX:SharedArchiveFile, que cria o arquivo quando ele não existe ou quando foi gerado por outra versão do JDK. O uso de ArchiveClassesAtExit foi testado nesta aula e funcionou, e a página consultada não descreve essa opção em detalhe, então a aula registra isso como verificado pelo teste e não pela documentação.

O experimento usou um programa Kotlin mínimo, que imprime uma linha. Ele é um hello world, e serve para medir o custo fixo da JVM, sem a inicialização de um framework. Cada configuração foi executada 15 vezes, intercalada com as outras, e medimos o tempo de parede de cada execução. A tabela resume o resultado:

Duas leituras saem da tabela. A primeira é que desligar o CDS custa caro: o arquivo padrão do JDK economiza cerca de 28 ms na mediana. A segunda é que o AppCDS, nesse programa, ganha apenas 2,2 ms sobre o CDS padrão, e a faixa de mínimo e máximo dos dois se sobrepõe. Com 15 execuções, essa diferença é pequena demais para afirmar que o AppCDS é mais rápido aqui. A razão é que um hello world carrega poucas classes da aplicação, e o ganho do AppCDS cresce com o número delas.

A contagem de classes carregadas de cada arquivo reforça isso. No JDK 21, o programa carregou 617 classes sem CDS, 580 do arquivo padrão, e todas as 500 do AppCDS vieram do arquivo gerado, o que confirma que o cache estava em uso. O JDK 25 com o cache AOT carregou 832 classes do arquivo.

A figura empilha as cinco configurações na ordem do experimento, e a cor separa o caso sem cache (rosa), o JDK 21 (roxo), o JDK 25 padrão (cinza) e o cache AOT (verde). A barra mais alta, sem CDS, é a que mais se distancia. As três de baixo ficam perto umas das outras, e a leitura correta é que, para um programa pequeno, o salto grande é o CDS padrão e a melhoria seguinte é modesta. As medições de startup de uma aplicação Spring real não foram feitas nesta aula, e a figura não deve ser lida como previsão para esse caso.

5. o cache AOT do JDK 25

O JEP 514, que tem como release o JDK 25, tem como objetivo simplificar a criação de um cache AOT (ahead of time). A documentação do JEP mostra um comando de uma etapa, com -XX:AOTCacheOutput=app.aot na execução que gera o cache, e -XX:AOTCache=app.aot na execução de produção que o usa. A página do JEP afirma como objetivo simplificar a criação do cache “sem perda de expressividade”.

Medimos as duas etapas com o JDK 25 instalado nesta máquina. O comando de criação foi java -XX:AOTCacheOutput=app25.aot -cp hello.jar HelloKt, e a saída terminou com AOTCache creation is complete: app25.aot 10240000 bytes. Na execução com -XX:AOTCache=app25.aot, o log com -Xlog:aot mostrou Opened AOT cache app25.aot., e a medição de 37,3 ms da tabela veio dessa configuração. Uma combinação que não funciona é usar -Xshare:on junto com -XX:AOTCache. A JVM recusou com a mensagem de que a opção AOTCache não pode ser usada junto com -Xshare:on, -Xshare:auto, -Xshare:off, -Xshare:dump ou SharedArchiveFile.

Essa diferença de 12 ms em relação ao CDS padrão do JDK 25 é o efeito que o cache AOT mede neste programa. Ela não diz quanto o cache economiza em um serviço real, porque um serviço real tem mais classes, mais configurações e mais código que roda uma vez na inicialização. A aula não mediu esses casos.

A página do CDS do JDK 21 descreve que um arquivo gerado por outra versão do JDK é recriado quando a opção de criação automática está ligada. Para o cache AOT do JDK 25, a aula não testou o comportamento com uma versão diferente da JVM, e registra isso como lacuna. O cuidado prático é o mesmo nos dois casos: o arquivo deve ser gerado com o mesmo JDK, o mesmo classpath e a mesma imagem que vai rodar em produção.

Pergunta de entrevistaPor que a JVM demora para subir e o que você pode fazer a respeito?

Parte do tempo é inevitável: a JVM precisa carregar as classes, verificar se o bytecode é seguro, preparar a memória e executar a inicialização de cada classe. O CDS, Class Data Sharing, reduz parte desse trabalho guardando num arquivo uma imagem das classes já lidas, pronta para ser mapeada na memória, e o JDK já vem com um arquivo CDS padrão. Para a minha aplicação posso criar um AppCDS, rodando-a uma vez para gerar o arquivo e usando esse arquivo nas execuções seguintes. Isso importa em plataformas com escala automática, onde a instância nova só ajuda depois de subir. Eu mediria antes e depois, porque o ganho depende do programa.

6. GraalVM Native Image: o que não foi medido

O GraalVM Native Image compila a aplicação ahead of time para um executável nativo, sem uma JVM em execução. A troca geral é conhecida: o startup costuma ser muito menor e a memória de repouso costuma ser menor, em compensação o modelo de mundo fechado impõe limites a reflexão, carregamento dinâmico de classes e alguns recursos da linguagem, que precisam ser declarados na compilação. Essa descrição é conhecimento geral, e a aula não a verificou em documentação.

Nesta máquina, o native-image não está instalado. Por isso a aula não tem nenhum tempo de startup, nem de memória, para o GraalVM. Quando for comparar, o caminho é instalar a distribuição, compilar o mesmo hello world e medir com o mesmo método de 15 execuções intercalado, antes de tirar qualquer conclusão sobre o que a troca vale num serviço Spring.

7. erros comuns e boas práticas

O primeiro erro é ligar a gravação com o perfil mais detalhado em produção sem medir o custo. O perfil profile coleta mais dados e tem mais overhead, e a boa prática é começar com o padrão, confirmar o custo num ambiente parecido com o real e só então subir o nível de detalhe.

O segundo erro é ler a soma das amostras como uma contagem exata. O JFR amostra as alocações e atribui um peso a cada amostra, então a tabela de quadros do topo é uma estimativa. Ela é suficiente para achar o caminho principal, mas não para comparar duas diferenças pequenas. Para isso, faça duas gravações e compare a proporção, não a contagem bruta.

O terceiro erro é tirar conclusões de um hello world sobre o startup de um framework. O experimento desta aula mostra o custo fixo da JVM, e não o custo de subir uma aplicação com centenas de beans. Um ganho de 2 ms no hello world pode ser muito maior, ou nulo, num serviço real, e só a medição com a aplicação de verdade responde.

O quarto erro é criar o CDS ou o cache AOT com um classpath e usar outro na execução. Os caches registram o caminho e a versão, e a mudança faz a JVM recusar o arquivo ou ignorá-lo sem chamar atenção. A boa prática é gerar o arquivo no mesmo passo de build que empacota a aplicação, e verificar com -Xlog que o cache foi aberto.

O quinto erro é esquecer que o startup tem uma fase de aquecimento. Logo depois de subir, o código ainda roda no interpretador e nos primeiros níveis do JIT, então a primeira requisição é mais lenta que as seguintes. A aula de JIT e análise de escape trata desse aquecimento, e um teste de startup deve dizer até qual ponto mede o tempo.

8. exercícios

1. Grave a aplicação desta aula com settings=default e com settings=profile, com o mesmo número de rodadas. Compare o número de eventos de jdk.ObjectAllocationSample e o tempo de parede, e explique a diferença.
2. Agregue a gravação pelo quadro do topo da pilha com --stack-depth 1 e compare o resultado com a tabela da seção 2. Depois altere o joinToString para uma construção com StringBuilder e refaça a medição.
3. Repita a medição de startup com um programa que use uma biblioteca com muitas classes, e veja se o ganho do AppCDS sobre o CDS padrão cresce. Use pelo menos 15 execuções intercaladas e mostre mínimo e máximo, não só a mediana.
4. Gere um cache AOT no JDK 25 e tente usá-lo com outro classpath, por exemplo com um jar copiado para outra pasta. Registre a mensagem do -Xlog:aot e explique o que a JVM fez.

9. glossário

JFR (Java Flight Recorder): mecanismo de eventos embutido na JVM, que grava atividades em um arquivo .jfr para leitura posterior.

Perfil do JFR: conjunto de eventos e de configurações de amostragem. O default tem overhead baixo, e o profile coleta mais dados com mais custo.

Amostra de alocação: evento que registra uma alocação escolhida pela JVM, com a pilha da thread e um peso estimado em bytes.

CDS (Class Data Sharing): arquivo com as classes já analisadas, mapeado na memória para reduzir o tempo de carregamento.

AppCDS: extensão do CDS para as classes da própria aplicação, gerada a partir de uma execução de treino.

Cache AOT: arquivo gerado antes da execução com informações de carregamento e de ligação das classes, que a JVM usa para acelerar o startup. O JEP 483 trata do carregamento e da ligação ahead of time no JDK 24, e o JEP 514 simplifica a criação do cache, com release no JDK 25.

GraalVM Native Image: compilador ahead of time que gera um executável nativo sem JVM em execução. Não foi medido nesta aula.

fontes

Consultadas em 20/10/2026.

Oracle, Java SE 21, guia de runtime do JFR, com o perfil profile e o overhead do default: https://docs.oracle.com/en/java/javase/21/jfruntime/

Oracle, Java SE 21, página de referência do comando jfr, com as opções --events e --stack-depth (padrão de 5 quadros) e a descrição do jfr summary: https://docs.oracle.com/en/java/javase/21/docs/specs/man/jfr.html

Oracle, Java SE 21, Class Data Sharing, com a afirmação de que um arquivo CDS padrão vem com o JDK a partir do JDK 12, e o exemplo com -XX:+AutoCreateSharedArchive e -XX:SharedArchiveFile: https://docs.oracle.com/en/java/javase/21/vm/class-data-sharing.html. A página não descreve -XX:ArchiveClassesAtExit em detalhe; o uso dessa opção foi verificado pelo teste.

OpenJDK, JEP 483, carregamento e ligação de classes ahead of time, do JDK 24: https://openjdk.org/jeps/483

OpenJDK, JEP 514, facilidade de criação do cache AOT, com release no JDK 25, e os comandos -XX:AOTCacheOutput e -XX:AOTCache: https://openjdk.org/jeps/514

As medições desta aula foram feitas em 20/10/2026, com o kotlinc 2.1.21 instalado junto ao IntelliJ IDEA, o Temurin 21.0.8 e o OpenJDK 25 instalado em /Users/jeangrijp/Library/Java/JavaVirtualMachines/openjdk-25. O GraalVM Native Image não está instalado nesta máquina, e nenhum tempo dele foi medido.

relacionados

• Trilha de Kotlin
• Curriculo de um Desenvolvedor Kotlin
• Bytecode e decompilação
• Heap, GC e pausas
• JIT e análise de escape
• Boxing e alocações escondidas