Mensagens do Log da Coleta de Lixo do Java

Eu configurei o java para despejar informações de garbage collection nos logs ( GC detalhado ). Não tenho certeza do que significam as inputs de garbage collection nos logs. Uma amostra dessas inputs é publicada abaixo. Eu pesquisei no Google e não encontrei explicações sólidas.

Eu tenho algumas suposições razoáveis, mas estou procurando respostas que forneçam definições estritas do que significam os números nas inputs, respaldados por fonts confiáveis. Um +1 automático para todas as respostas que citam a documentação do sol. Minhas perguntas são:

  1. O que PSYoungGen se refere? Eu suponho que tenha algo a ver com a geração anterior (mais jovem?), Mas o que exatamente?
  2. Qual é a diferença entre o segundo trio de números e o primeiro?
  3. Por que um nome (PSYoungGen) especificado para o primeiro trio de números, mas não o segundo?
  4. O que cada número (tamanho da memory) no trio significa. Por exemplo, em 109884K-> 14201K (139904K), é a memory antes de GC 109884k e, em seguida, é reduzida para 14201K. Como o terceiro número é relevante? Por que nós exigiríamos um segundo conjunto de números?

8109.128: [GC [PSYoungGen: 109884K-> 14201K (139904K)] 691015K-> 595332K (1119040K), 0,0454530 seg.]

8112.111: [GC [PSYoungGen: 126649K-> 15528K (142336K)] 707780K-> 605892K (1121472K), 0,0934560 seg.]

8112.802: [GC [PSYoungGen: 130344K-> 3732K (118592K)] 720708K-> 607895K (1097728K), 0,0682690 seg.]

   

A maior parte é explicada no GC Tuning Guide (que você faria bem em ler mesmo assim).

A opção de linha de comando -verbose:gc faz com que as informações sobre o heap e a garbage collection sejam impressas em cada coleção. Por exemplo, aqui está a saída de um aplicativo de servidor grande:

 [GC 325407K->83000K(776768K), 0.2300771 secs] [GC 325816K->83372K(776768K), 0.2454258 secs] [Full GC 267628K->83769K(776768K), 1.8479984 secs] 

Aqui vemos duas collections menores seguidas por uma coleção principal. Os números antes e depois da seta (por exemplo, 325407K->83000K da primeira linha) indicam o tamanho combinado dos objects 325407K->83000K antes e depois da garbage collection, respectivamente. Após collections menores, o tamanho inclui alguns objects que são lixo (não estão mais vivos), mas que não podem ser recuperados. Esses objects estão contidos na geração de posse ou referenciados pelas gerações temporárias ou permanentes.

O próximo número entre parênteses (por exemplo, (776768K) novamente da primeira linha) é o tamanho confirmado do heap: a quantidade de espaço utilizável para objects java sem solicitar mais memory do sistema operacional. Observe que esse número não inclui um dos espaços survivor, já que apenas um pode ser usado a qualquer momento e também não inclui a geração permanente, que contém os metadados usados ​​pela máquina virtual.

O último item na linha (por exemplo, 0.2300771 secs ) indica o tempo gasto para realizar a coleta; neste caso, aproximadamente um quarto de segundo.

O formato da coleção principal na terceira linha é semelhante.

O formato da saída produzida por -verbose:gc está sujeito a alterações em versões futuras.

Não sei por que há um PSYoungGen no seu; você mudou o coletor de lixo?

  1. PSYoungGen refere-se ao coletor de lixo em uso para a coleção menor. PS significa Scavenge Paralelo.
  2. O primeiro conjunto de números é o tamanho antes / depois da geração jovem e o segundo conjunto é para o heap inteiro. ( Diagnosticar um problema de garbage collection detalha o formato)
  3. O nome indica a geração e o coletor em questão, o segundo conjunto é para o heap inteiro.

Um exemplo de um GC completo associado também mostra os coletores usados ​​para as gerações antigas e permanentes:

 3.757: [Full GC [PSYoungGen: 2672K->0K(35584K)] [ParOldGen: 3225K->5735K(43712K)] 5898K->5735K(79296K) [PSPermGen: 13533K->13516K(27584K)], 0.0860402 secs] 

Finalmente, detalhando uma linha de sua saída de log de exemplo:

 8109.128: [GC [PSYoungGen: 109884K->14201K(139904K)] 691015K->595332K(1119040K), 0.0454530 secs] 
  • 107Mb usado antes do GC, 14Mb usado após o GC, tamanho máximo da geração nova 137Mb
  • Pilha de 675Mb usada antes do GC, heap de 581Mb usado após o GC, tamanho máximo do heap de 1Gb
  • GC menor ocorreu 8109.128 segundos desde o início da JVM e levou 0.04 segundos

Eu só queria mencionar que é possível obter o log detalhado do GC com o

 -XX:+PrintGCDetails 

parâmetro. Então você vê a saída PSYoungGen ou PSPermGen como na resposta.

Também -Xloggc:gc.log parece gerar a mesma saída como -verbose:gc mas você pode especificar um arquivo de saída no primeiro.

Exemplo de uso:

 java -Xloggc:./memory.log -XX:+PrintGCDetails Memory 

Para visualizar melhor os dados, você pode tentar o gcviewer (uma versão mais recente pode ser encontrada no github ).

Tome cuidado para escrever os parâmetros corretamente, eu esqueci o “+” e meu JBoss não iria iniciar, sem qualquer mensagem de erro!