SubMundo Java

Dimensionamento do pool de conexões – se, por exemplo,  um banco de dados tiver um limite de 100 conexões e você possuir 3 aplicações com pools de 100 conexões (300 conexões ao total) você pode ter alguma requisição aguardando uma conexão ser liberada pelo pool, ocasionando lentidão no sistema.

PreparedStatements – Normalmente uma conexão tem uma relação de “um pra um” com um PreparedStatement, entretanto, a criação deste objeto pode ser custoso. Em servidores de aplicações modernos é possível “cachear” PreparedStatements. Para cada conexão é criado um cache, tornando as consultas ao banco de dados mais veloz. É possível configurar o tamanho do cache de PreparedStatements o que pode impactar na velocidade do sistema para baixo ou para cima.

Gerenciamento de memória – Embora a JVM possua um mecanismo eficiente de coleta de lixo, um bug na aplicação pode fazer com que o coletor de lixo (garbage collector) não identifique os objetos que devem ser excluídos da memória, resultando em um fenômeno conhecido como vazamento de memória (leak memory) e consequentemente em OutOfMemoryError.

Outros – Outros fatores envolvendo e/ou não a plataforma Java podem ocasionar lentidão em seu sistema como CPU, Run Queue, I/O, Network Throughput e etc.

Por onde iniciar

É muito comum iniciar uma análise de desempenho “atacando” os gargalos. Em Java, um dos problemas mais comuns esta justamente no gerenciamento de memória, ocasinado pela sua aplicação ou por um framework de terceiro. Muitas vezes apenas a atualização de um framework pode garantir um ganho enorme de performance. Neste primeiro POST, irei abordar uma das maneiras de analisar a heap de uma aplicação Java, tendo como foco a identificação de vazamento de memória.

Entendendo a coleta de lixo

De uma maneira bem simples, um objeto é elegível a ser coletado pelo mecanismo de coleta de lixo quando nenhum outro objeto da heap o referencia. Desta forma, se criamos uma aplicação cujo a soma de número de objetos instanciados (em bytes) é maior que o tamanho configurado da heap, então acontece OutOfMemoryError. É muito comum isto acontecer em relatórios cujo o número de registros apresentados ao usuário é muito grande e em funcionalidades stateful. É justamente nesta parte do sistema que devemos suspeitar em um primeiro momento.

Identificando “O” vazamento de memória

Muitas vezes nós, desenvolvedores, não temos a noção (embora devessemos) de qual funcionalidade é mais utilizada do sistema e para sistemas com muitas funcionalidades fica ainda mais difícil saber por onde começar, desta forma, uma maneira eficiente de identificar vazamento de memória é no sistema em produção.

A maneira mais simples de identificar um vazamento de memória é através de JMX, entretanto, para que isto funcione é necessário que JMX esteja ativado no servidor, o que pode ser incomum (ou apenas não permitir conexão remota). A maneira que irei demonstrar a seguir, consiste em utilizar do log do garbage collector para obter um gráfico similar ao obtido pelo jconsole, pois é muito mais simples você convencer ao administrador a ativar o log do que o suporte a JMX (ou conexão remota via JMX).

Obtendo o log do GC

Para ativar o log da JVM (Sun Hostpot) passe os seguintes parâmetros ao inicia-la:

-verbose:gc
-Xloggc:PATH_TO_LOG_FILE

Exemplo:

java -Xms16M -Xmx16M -verbose:gc -Xloggc:/logs/gc.log -jar leak-memory.jar

O que significa:

Execute o programa leak-memory.jar com tamanho inicial e total de 16M (-Xms16M e Xmx16M), ative o log do GC (-verborse:gc) e grave no arquivo /logs/gc.log (-Xloggc:gc.log)

O arquivo /logs/gc.log deve conter algo como:

9.317: [GC 4160K->1491K(15744K), 0.0190010 secs]
27.595: [GC 5651K->5302K(15744K), 0.0467940 secs]
34.715: [GC 9462K->9182K(15744K), 0.0414860 secs]
34.757: [Full GC 9182K->9177K(15744K), 0.0700270 secs]

Exemplo prático

Observe a imagem abaixo:

Leak Memory

Para analisarmos o log do GC, criei uma aplicação Swing que instância um número determinado de objetos User e adiciona a uma collection (List, atributo da classe Main), estes objetos estão sempre sendo referenciados, desta forma, nenhum deles será coletado pelo coletor de lixo.

DICA:

Configure o programa para instanciar 1000 objetos User e clique no botão GO! a cada 10 segundos, depois de mais ou menos 5 minutos acontecerá o OutOfMemoryError indicado pela seguinte mensagem:

Exception in thread “AWT-EventQueue-0″ java.lang.OutOfMemoryError: Java heap space

Obtendo o gráfico da heap

Para obtermos o gráfico da memória da JVM utilizaremos o gc.log gerado. Você pode parsear o arquivo e transforma-lo em um CSV criando o gráfico através de um programa de planilha como o excel, mas pra agilizar o processo, iremos utilizar o programa gcviewer.

Utilizando o gcviewer, abra o arquivo gc.log (obtido pela experiência proposta acima) e será apresentado um gráfico como este:

gcviewer

No gcviewer desabilite todas as opções (menu view) deixando apenas Data Panel, Full GC Lines e Used Heap.

Em degradê (vermelho pra branco) temos o tamanho total da heap (~16 MB), a linha horizontal azul representa o tamanho em bytes usado na heap pela aplicação e as linhas verticais pretas representam o momento que foi efetuado o Full GC.

É possível identificar que nesta aplicação existe um vazamento de memória devido ao used heap space sempre crescer e nunca diminuir (o que seria desejável em uma aplicação saudável). Ou seja, em uma aplicação normal, quando é executado o GC a parte utilizada da heap deveria diminuir, ou seja, a linha deveria descer. Perceba que mesmo ao ser executado o full GC a linha não desce, o que é totalmente compreensível pois estamos referenciando todos os objetos que criamos. Além disso, um pouco antes de ocorrer o OutOfMemoryError muitos full GCs acontecem o que faz com que a aplicação fique muito lenta.

Identificando “ONDE ESTÁ” o vazamento de memória

Existem muitas maneiras de descobrir onde está o vazamento de memória. Irei descrever duas maneiras de se obter um dump para podermos analisar os objetos da heap.

Heap dump on OutOfMemoryError – Através de um parâmetro da JVM um arquivo de dump com a extensão .hprof será criado no diretório em que foi executado o programa, quando ocorrer um OutOfMemoryError.

Exemplo:

java -XX:+HeapDumpOnOutOfMemoryError -Xms16M -Xmx16M -verbose:gc -Xloggc:/logs/gc.log -jar leak-memory.jar

Heap shot – Consiste em tirar um shot da heap com o programa em execução.

Para tanto, precisamos saber qual o PID do processo Java que queremos obter o dump, usaremos então o jps para obter o PID e o jmap para obter o dump (ambos já vem com a JVM):

henrique@henrique-ubuntu:/logs$ jps
12594 Jps
12577 jar
10857 gcviewer-1.29.jar
10363 Main

No caso, Main é a classe principal do leak-memory.jar. Para obtermos o dump deste programa executamos:

jmap -F -dump:format=b,file=dump.hprof 10363

Após obtermos o dump (de qualquer uma das maneiras descritas acima) podemos carregar um relatório que nos possibilitará enxergarmos o que está acontecendo dentro da heap. Para tanto, utilizaremos uma outra ferramenta da JDK chamada jhat.

OBS: Após obtermos o dump é desejável retirá-lo de produção para um máquina local.

henrique@henrique-ubuntu:~/dev/workspace/netbeans/leak-memory/dist$ jhat java_pid12635.hprof
Reading from java_pid12635.hprof…
Dump file created Sun Apr 18 19:00:44 BRT 2010
Snapshot read, resolving…
Resolving 755646 objects…
Chasing references, expect 151 dots…………………………………………………………………………………………………………………………………….
Eliminating duplicate references…………………………………………………………………………………………………………………………………….
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

Conforme descrito na saída do programa, um HTTP server é criado na porta 7000, desta forma basta acessarmos http://localhost:7000 e obtemos o relatório desejado, conforme demonstra a figura abaixo:

jhat

Conforme é possível observar na imagem acima, todas as classes usadas no programa leak-memory.jar que não fazem parte da JVM são apresentadas e existem várias maneiras de encontrarmos a informação necessária. O que estamos procurando é um número grande de instâncias de uma mesma classe, desta forma ao clicar no link “Heap Histogram” será apresentada uma tela conforme demonstra a imagem a seguir:

histogram

Se navegarmos um pouco sobre esta tela descobrimos que:

Existem 359770 da classe java.util.LinkedList$Entry (cujo tamanho é 20 bytes)
Existem 359756 da classe br.com.submundojava.User (cujo tamanho é 16 bytes)

Ou seja, calculando o valor total destes objetos obtemos o seguinte resultado:

(359770 * 20) + (359756 * 16) = 12951496 (~12.3 MB)

Considerando que o número muito próximo de Entry e User deduzimos que Entry contém User. Além disso, o tamanho da JVM é de ~16 MB, o que significa que estas duas classes possuem instâncias que ocupam cerca de 80% da memória o que nos indica um forte candidato a ser o culpado pelo OutOfMemoryError.

OBS: Os valores aqui descritos são aproximados, nas minhas contas o tamanho em bytes das instâncias de User bateram exatamente com o programa eclipse memory analyzer (citado no final), entretanto, o valor em bytes das instâncias de Entry foram apenas parecidos.

Próximos passos

Existem muitas maneiras (talvez mais fáceis e inteligentes do que esta) para encontrarmos gargalos na memória. Além disso, as ferramentas jmap e jhat possuem vários outros recurso, recomendo um estudo mais profundo das mesmas.
No exemplo citado nest POST fica óbvio onde encontrar o problema e posso garantir que no mundo real a “coisa” não é tão simples assim. Além disso, existem ferramentas mais modernas do que o jhat, como é o caso do eclipse memory analyzer que possui recursos maravilhosos que indicam onde pode ser encontrado um possível vazamento de memória.

Conclusão

O que foi apresentado neste POST é uma maneira criativa de se obter informações sobre a heap de um sistema em produção, esta técnica já foi utilizada muitas vezes e solucionou diversos problemas. Espero ter contribuido com as horas de sono de algum leitor.

Arquivos e Referências

leak-memory.jar – Usado para efetuar os testes.

Tuning Garbage Collection with the 5.0 Java[tm] Virtual Machine – O título já diz tudo

http://www.arquiteturajava.com.br/ – Capítulo 3.2, Gerenciar memória não é simples

http://www.javaperformancetuning.com/ – Alguns artigos bem antigos mas ainda válidos

Forte abraço e aguardo seus comentários.