Os objetos de referência de processamento do Java G1 GC funcionam devagar

Eu tenho batido contra a execução em Java. Funciona 24 horas e bate em cerca de 100 vezes por segundo. Durante o dia, o tempo de processamento do GC sobe lentamente de 20 a 60 ms até 10.000 a 6.000 ms e depois cai para 20 a 60 ms. Esse padrão é repetido de tempos em tempos. Dos logs de GC, descobri que, na maioria das vezes, gasto em GC para processar objetos de referência (Ref Proc). Então, quais são as causas de um tempo GC tão longo?

Server: Amazon EC2 m1.small
OS: Ubuntu 10.04.3 LTS
Java: Oracle 1.7.0_07

Exemplo de logs do GC:

2012-09-13T16:51:20.091+0400: 167239.936: [GC pause (young), 62.58395400 secs]
...
[Other: 62489.7 ms]
    [Choose CSet:   0.0 ms]
    [Ref Proc: 62433.9 ms]
    [Ref Enq:   0.0 ms]
    [Free CSet:   0.7 ms]
[Eden: 200M(200M)->0B(199M) Survivors: 4096K->5120K Heap: 578M(1024M)->380M(1024M)]

Hora - gráfico "Ref Proc":

09:37:59 - 242.4 ms
09:38:50 - 226.0 ms
09:39:00 - 83.6 ms
...
11:45:22 - 451.8 ms
11:46:04 - 489.3 ms
11:46:46 - 505.6 ms
...
14:05:40 - 1027.3 ms
14:06:01 - 796.6 ms
14:06:35 - 1064.0 ms
...
15:44:32 - 1920.4 ms
15:45:04 - 2116.7 ms
15:45:39 - 2196.8 ms
...
16:19:07 - 3983.3 ms
16:19:43 - 4494.9 ms
16:20:16 - 4065.2 ms
...
16:33:11 - 7690.1 ms
16:33:50 - 8501.4 ms
16:34:28 - 8059.3 ms
...
16:47:14 - 51378.6 ms
16:49:11 - 57529.2 ms
16:51:20 - 62433.9 ms
16:53:00 - 46.1 ms
16:53:30 - 45.5 ms
16:54:03 - 45.0 ms
...
16:54:38 - 57.0 ms
16:55:09 - 20.9 ms
16:55:43 - 21.3 ms
...
16:09:45 - 134.3 ms
16:10:21 - 142.1 ms
16:10:58 - 147.5 ms
...
17:18:51 - 177.3 ms
17:19:27 - 135.8 ms
17:20:03 - 179.6 ms

Eu encontrei no parâmetro de fontes java PrintReferenceGC. Log do GC mostrado a seguir

[SoftReference, 0 refs, 0.0000050 secs]
[WeakReference, 6 refs, 0.0000030 secs]
[FinalReference, 113 refs, 0.0011180 secs]
[PhantomReference, 0 refs, 0.0000020 secs]
[JNI Weak Reference, 3.9010450 secs]

Este é um problema da JNI Weak Reference.

questionAnswers(2)

yourAnswerToTheQuestion