Profiling tem sido uma das minhas principais atividades nos últimos meses. Como a aplicação que eu trabalho chegou a um bom grau de maturidade onde há poucas funcionalidades a sere feitas e os bugs de produção são raros, hoje o principal esforço é melhorar o desempenho e reduzir o uso de recursos. Por isso muito se pede para investigar o uso de CPU ou reduzir o tempo de processamento, o que me levou a estudar com se dá o uso da CPU em produção e como funciona internamente o Kafka Stream.
É nesse contexto que resolvi finalmente investir um tempo para tentar gerar um diagrama muito interessante chamado Flamegraph. Caso você ainda não o conheça, vamos primeiro falar sobre ele e depois mostrar como você pode gerar ele na sua aplicação Java facilmente!
O Flamegraph
O Flamegraph é um diagrama de monitoramento do uso da CPU criado por Brendan Gregg enquanto trabalhava investigando problemas de performance no MySQL. Caso você queira ler a descrição do próprio criador, recomendo um post no site pessoal dele Flame Graphs e um artigo na Communications da ACM chamado The Flame Graph.
A informação provida pelo flamegraph pode não parecer nova, ela já era provida por diversas ferramentas de profiling, mas a forma de interação com o dado é mais interessante e dos dá mais informações sobre o que realmente acontece em tempo de execução. O VisualVM já provê informação semelhante, mas a forma que ela é exibida, apesar de mais acurada, torna difícil visualizar o real uso da CPU. As ferramentas tradicionais agrupavam o uso de CPUs por threads, como é visto na imagem abaixo. Conseguimos ver o uso de cada thread, o que de certa forma está parcialmente certo, mas dificulta a visualização pois não vemos o dado real por CPU.
Pode parecer estranho o que vou afirmar aqui, mas threads não existem! Threads são uma abstração do Sistema Operacional que facilitam o desenvolvimento de software ao tratar o paralelismo como uma necessidade básica. Para entender melhor essa afirmação temos que entender que CPU é um recurso do nosso sistema que é compartilhado entre as diversas threads. O que o flamegraph faz é mostrar todo o uso de CPU ignorando a existência de threads e isso ajuda muito na visualização!
Ao afirmar the threads não existem não estou dizendo que você não deva abolir threads, muito pelo contrário. Mas muitas vezes o processamento que está distribuído em diversas threads é implementado pelo memso código. Vamos pensar no Kafka Stream! Nós normalmente implementamos uma pipeline que é única e será executada pela StreamThread. Uma aplicação em produção terá diversas StreamThread executando o mesmo código! Quando olhamos para o VisualVM, temos que optar por uma dessas StreamThread, enquanto ao olharmos para o flamegraph, vemos todas as StreamThreads!!!
Isso acontece porque ao se colocar todo o tempo de CPU em um único eixo, facilita-se a visualização. O flamegraph reduz o número de variáveis a se considerar para se extrair um dado simples: tempo de CPU!
Como extrair o Flamegraph?!
Se você fizer essa pesquisa no Google, já aviso que se deparará com diversos posts com muita informação antiga e pouca comparação. Verá posts onde só se usou as ferramentas de performance do Linux, outros posts usando somente o Java Flight Recorder e outros posts usando agentes nativos que integram código Java com as ferramentas nativas do Linux. Nesse post eu vou mostrar como exatrair de duas formas e depois comparar os resultados obtidos por ambas as formas.
Extraindo usando apenas o Java Flight Recorder!
A primeira forma de se extrair o flamegraph é pegar as informações necessárias usando apenas ferramentas providas pela JVM e depois processar essa informações
criando o framegraph. A JVM já provê uma série de ferramentas de profiling que estão dentro do JDK. Se você não conhece o comando jcmd recomendo parar tudo que
está fazendo e dar uma olhada nele. Na documentação do jcmd você consegue encontrar a
descrição de todo comandos que você pode executar só passando o PID da JVM que você quer olhar.
> jcmd MyProgram help (or "jcmd 2125 help")
2125:
The following commands are available:
JFR.stop
JFR.start
JFR.dump
JFR.check
VM.native_memory
VM.check_commercial_features
VM.unlock_commercial_features
ManagementAgent.stop
ManagementAgent.start_local
ManagementAgent.start
Thread.print
GC.class_stats
GC.class_histogram
GC.heap_dump
GC.run_finalization
GC.run
VM.uptime
VM.flags
VM.system_properties
VM.command_line
VM.version
helpPara gerar o flamegraph independentemente do método, você precisará do async-profiler. É uma excelente ferramenta que gera o flamegraph a partir da gravação do Java Flight Recorder e também gera usando o agente nativo.
Nesse primeiro método vamos usar o Java Flight Recorder para gravar as informações de execução e depois gerar o flamegraph, para gravar as informações você
pode usar os dois métodos abaixos, ambos foram extraídos de scripts de profile que eu uso. No primeiro eu inicio a gravação, depois gero trafego (o qual foi
substituído pelo sleep) e por fim finalizo a gravação. A vantagem desse método é que você grava somente o periodo em que o trafego foi gerado.
DURATION=1200 ## 2 minutos
rm -f /tmp/recording.jfr ## Apaga gravações antigas que podem ter sido feitas
NAME=$(cat /dev/urandom | tr -dc 'a-zA-Z' | fold -w 15 | head -n 1) ## Gera um nome aleatório para evitar conflitos
PID=$(ps -a | grep java | awk '{print $1}') ## Acessa número do processo em execução se rodando em docker/k8s
jcmd $PID JFR.start name=$NAME settings=profile ## Inicia gravação
sleep $DURATION
jcmd $PID JFR.stop name=$NAME filename=/tmp/recording.jfrNo segundo método, o jcmd é executado de forma asincrona usando os parâmetros duration e delay. Esse método é bom para capturar informações
do ambiente de produção sem precisar reiniciar o servidor.
DELAY=10m
DURATION=20m
rm -f /tmp/recording.jfr ## Apaga gravações antigas que podem ter sido feitas
NAME=$(cat /dev/urandom | tr -dc 'a-zA-Z' | fold -w 15 | head -n 1) ## Gera um nome aleatório para evitar conflitos
PID=$(ps -a | grep java | awk '{print $1}') ## Acessa número do processo em execução se rodando em docker/k8s
jcmd $PID JFR.start name=$NAME settings=profile delay=$DELAY duration=$DURATION ## Inicia gravaçãoDepois de capturado o arquivo recording.jfr, você precisa gerar o flamegraph usando o
converter do async-profile.
Para isso execute o comando abaixo e voilà!!! Você tem uma pagina HTML pura para colocar onde quiser. Eu coloquei ela como
artefato dos testes de carga da aplicação.
java -cp converter.jar jfr2flame --dot --total --alloc --classify --title "My CPU Profile" /tmp/recording.jfr /tmp/flamegraph.htmlO tamanho do arquivo gerado será proporcional ao tempo de gravação, por isso garanta que há espaço em disco e use sabiamente a duração (duration) e o atrado (delay) para capturar o melhor momento da execução.
Extraindo usando agente nativo
A grande desvantagem de usar somente o Java Flight Recorder é que algumas informações sobre a execução nativa é perdida. Ao migrar para a execução usando o agente nativo consegui, por exemplo, identificar alguns trechos de código que usavam exceptions para controle de fluxo o que pode ser um grande problema de desempenho.
Para executar usando agente natvo com o async-profiler, basta fazer o download da buil,
copiar para o ambiente de execução e depois executar o comando asprof como mostrado abaixo.
DURATION=1200
PID=$(ps -a | grep java | awk '{print $1}') ## Acessa número do processo em execução se rodando em docker/k8s
/tmp/async-profiler-3.0-linux-x64/bin; ./asprof -d $DURATION -f /tmp/flamegraph.html $PIDA desvantagem desse método é que você alterou o ambiente em que o seu software está rodando. Isso não tem problemas na grande maioria dos casos, mas não é muito bem visto para ambientes de produção.
Recomendações
Eu recomendo que você use constantemente ferramentas de profiling para visualizar o que está acontecendo no seu software. Existe uma máxima na área de adminstração que pode ser aplicada em qualquer lugar das nossa vidas "o que não pode ser medido, não pode ser gerenciado", logo é importante para você saber como está o tempo de execução do seu software.
A segunda recomendação é você, caso precise melhorar o desempenho do seu software, olhar primeiro para o local que mais impacta o desemepenho. Ganho de performance é proprocional ao tempo de desempenho, por isso só investa tempo onde há mais indicios de tempo gasto.
Uma outra recomendação é que você pode criar ferramentas de análise de desempenho automatizadas usando ferramentas de DevOps. Quem sabe criar uma task no Jenkins que extrai o FlameGraph e depois salva para análises futuras? Ou salvar essa página para cada nova versão e comparar como o desempenho tem evoluido?
Eu espero ter ajuda com alguma coisa!
