O coletor de lixo Java ConcurrentMarkSweep não remove todo o lixo

Question

Forma curta:O coletor de lixo do CMS parece não estar conseguindo coletar uma quantidade cada vez maior de lixo;eventualmente, nossa JVM fica cheia e o aplicativo não responde.Forçar um GC através de uma ferramenta externa (JConsole ou jmap -histo:live) limpa uma vez.

ATUALIZAR:O problema parece estar relacionado ao plugin JTop para JConsole;se não executarmos o JConsole ou sem o plugin JTop, o comportamento desaparecerá.

(Notas técnicas:estamos executando o Sun JDK 1.6.0_07, 32 bits, em uma caixa Linux 2.6.9.Atualizar a versão do JDK não é realmente uma opção, a menos que haja um motivo importante e inevitável.Além disso, nosso sistema não está conectado a uma máquina acessível pela Internet, portanto, capturas de tela do JConsole, etc., não são uma opção.)

Atualmente estamos executando nossa JVM com os seguintes sinalizadores:

-server -Xms3072m -Xmx3072m -XX:NewSize=512m -XX:MaxNewSize=512m 
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled 
-XX:CMSInitiatingOccupancyFraction=70 
-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 
-XX:+DisableExplicitGC

Observando o gráfico de memória no JConsole, há um GC completo que é executado a cada aproximadamente 15 minutos durante as primeiras horas de vida útil do nosso aplicativo;após cada GC completo, há cada vez mais memória em uso.Depois de algumas horas, o sistema atinge um estado estável onde há aproximadamente 2 GB de memória usada na geração antiga do CMS.

O que parece um vazamento de memória clássico, exceto que se usarmos qualquer ferramenta que force um GC completo (apertando o botão "coletar lixo" no JConsole ou executando jmap -histo:live, etc), a geração antiga cai repentinamente para aproximadamente 500 MB usados ​​e nosso aplicativo responde novamente pelas próximas horas (durante o qual o mesmo padrão continua - após cada GC completo, mais e mais da geração antiga está cheia).

Uma coisa digna de nota:no JConsole, a contagem de GC ConcurrentMarkSweep relatada permanecerá em 0 até forçarmos um GC com jconsole/jmap/etc.

Usando jmap -histo e jmap -histo:live em sequência, sou capaz de determinar que os objetos aparentemente não coletados consistem em:

• vários milhões HashMapse matrizes de HashMap$Entry (em uma proporção de 1:1)
• vários milhões Vectorse matrizes de objetos (proporção de 1:1 e quase igual ao número de HashMaps)
• vários milhões HashSet, Hashtable, e com.sun.jmx.remote.util.OrderClassLoaders, bem como matrizes de Hashtable$Entry (aproximadamente o mesmo número de cada;cerca de metade dos HashMaps e Vetores)

Existem alguns trechos da saída do GC abaixo;minha interpretação deles parece ser que o GC do CMS está sendo abortado sem falhar no GC de parar o mundo.Estou interpretando mal essa saída de alguma forma?Existe algo que causaria isso?

Durante o tempo de execução normal, os blocos de saída do CMS GC têm a seguinte aparência:

36301.827: [GC [1 CMS-initial-mark: 1856321K(2621330K)] 1879456K(3093312K), 1.7634200 secs] [Times: user=0.17 sys=0.00, real=0.18 secs]
36303.638: [CMS-concurrent-mark-start]
36314.903: [CMS-concurrent-mark: 7.804/11.264 secs] [Times: user=2.13 sys=0.06, real=1.13 secs]
36314.903: [CMS-concurrent-preclean-start]
36314.963: [CMS-concurrent-preclean: 0.037/0.060 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
36314.963: [CMS-concurrent-abortable-preclean-start]
36315.195: [GC 36315.195: [ParNew: 428092K->40832K(471872K), 1.1705760 secs] 2284414K->1897153K(3093312K), 1.1710560 secs] [Times: user=0.13 sys=0.02, real=0.12 secs]
CMS: abort preclean due to time 36320.059: [CMS-concurrent-abortable-preclean: 0.844/5.095 secs] [Times: user=0.74 sys=0.05, real=0.51 secs]
36320.062: [GC[YG occupancy: 146166 K (471872 K)]36320.062: [Rescan (parallel), 1.54078550 secs]36321.603: [weak refs processing, 0.0042640 secs] [1 CMS-remark: 1856321K(2621440K)] 2002488K(3093312K), 1.5456150 secs] [Times: user=0.18 sys=0.03, real=0.15 secs]
36321.608: [CMS-concurrent-sweep-start]
36324.650: [CMS-concurrent-sweep: 2.686/3.042 secs] [Times: uesr=0.66 sys=0.02, real=0.30 secs]
36324.651: [CMS-concurrent-reset-start]
36324.700: [CMS-concurrent-reset: 0.050/0.050 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

e é isso;a próxima linha será o próximo ParNew GC.

Quando forçamos um GC usando jmap -histo:live, obtemos:

48004.088: [CMS-concurrent-mark: 8.012/8.647 secs] [Times: user=1.15 sys=0.02, real=0.87 secs]
(concurrent mode interrupted)

seguido por aproximadamente 125 linhas do formulário abaixo:(alguns GeneratedMethodAccessor, alguns GeneratedSerializationConstructorAccessor, alguns GeneratedConstructorAccessor, etc)

[Unloading class sun.reflect.GeneratedMethodAccessor3]

seguido pela:

: 1911295K->562232K(2621440K), 15.6886180 secs] 2366440K->562232K(3093312K), [CMS Perm: 52729K->51864K(65536K)], 15.6892270 secs] [Times: user=1.55 sys=0.01, real=1.57 secs]

Desde já, obrigado!

Answer 1

com.sun.jmx.remote.util.orderclassloader é usado na camada remota do JMX e uma rápida revisão do código sugere que eles são criados como parte do processo de unidade para solicitações remotas dentro da JVM. A vida útil desses carregadores de classes estará diretamente relacionada à vida útil da coisa que não foi soltada, de modo que, uma vez que não haja mais referências a essa coisa que o carregador de classe poderia ser lançado.

Eu não ficaria surpreso se, nesse caso, a presença dessas instâncias fosse um resultado direto de você usar o JCONSOLE para examinar os acontecimentos na JVM. E parece que eles seriam limpos pelo GC como parte da operação normal.

Eu acho que é possível que haja um bug na implementação do JMX (parece improvável em uma JVM relativamente atualizada) ou talvez você tenha alguns MBeans personalizados ou esteja usando algumas ferramentas JMX personalizadas que estão causando o problema. Mas, em última análise, estou suspeitando que o OrderClassLoader seja provavelmente uma rejeição vermelha e o problema está em outro lugar (Broken GC ou algum outro vazamento).

Answer 2

NOTAS TÉCNICAS: Estamos executando o Sun JDK 1.6.0_07, 32 bits, em uma caixa Linux 2.6.9. Atualizar a versão JDK não é realmente uma opção, a menos que haja um motivo principal inevitável e principal.

Várias versões Java mais recentes tiveram atualizações para o coletor de lixo do CMS. Notavelmente 6U12, 6U14 e 6U18.

Não sou um especialista com coisas do GC, mas acho que as correções do Preliamento em 6u14 poderia Corrija o problema que você está vendo. Obviamente, eu poderia dizer a mesma coisa sobre os bugs de descarregamento da classe 6U18. Como eu disse, não sou especialista em coisas do GC.

Existem correções para:

• 6u10: (afeta 6u4+) O CMS nunca limpa os referentes quando -xx:+parallelrefprocenabled
• 6U12: CMS: codificação incorreta de matrizes de objetos transbordados durante o impedimento simultâneo
• 6U12: CMS: Manuseio incorreto de estouro ao usar marcação simultânea paralela
• 6U14: CMS: Falha de asserção "IS_CMS_THREAD == Thread :: Current ()-> is_concurrentgc_thread ()"
• 6U14: CMS: Precisa de cmsInitationingProwCupancyFração para o Perm, divorciando -se do CMSInitationingCupancyFração
• 6U14: CMS ASSERT: _CONCURENT_ITERATION_SAFE_LIMIT ATUALIZAÇÃO perdida
• 6U14: CMS: Manuseio incorreto de transbordamento durante o impedimento de listas de referência
• 6U14: Sigsegv ou (! Is_null (v), "OOP Valor nunca pode ser zero") ASSERÇÃO Ao executar com CMS e Cooops
• 6U14: CMS: Livelock no CompactibleFreelistspace :: block_size ().
• 6U14: Faça o CMS funcionar com oops compactados
• 6U18: CMS: Core Dump with -xx:+usecompressedoops
• 6U18: CMS: Bugs relacionados à descarga de classe
• 6U18: CMS: ReduceNitialCardmarks inseguros na presença de cms impedindo
• 6U18: [Regressão] -xx: newratio com -xx:+useConcmarksweepgc causa erro fatal
• 6u20: as marcas de cartão podem ser adiadas por muito tempo

Além de todos os itens acima, o 6U14 também introduziu o G1 Coletor de lixo, embora ainda esteja em teste. G1 tem como objetivo substituir o CMS no Java 7.

O G1 pode ser usado no Java 6u14 e mais recente com os seguintes interruptores da linha de comando:

-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC

Answer 3

Eu começaria com algo muito mais simples, como:

-server -Xms3072m -Xmx3072m -XX:+UseParallelOldGC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 

E veja se isso atende às suas necessidades.

Answer 4

Parece que você está construindo objetos que apontam para seus proprietários ( A aponta para B aponta para A ).Isso faz com que as contagens de referência permaneçam maiores que zero, de modo que o coletor de lixo não possa limpá-las.Você precisa quebrar o ciclo ao liberá-los.Anular a referência em A ou B resolverá o problema.Isso funciona mesmo em referências maiores como (A -> B -> C -> D -> A).Vetores e matrizes de objetos podem ser usados ​​pelos seus HashMaps.

A presença dos carregadores remotos pode indicar uma falha na limpeza e fechamento de referências a objetos carregados via JNDI ou outro método de acesso remoto.

EDITAR:Dei uma segunda olhada em sua última linha.Você pode querer aumentar a alocação de permissão.