Блог

Я тестирую сборщик мусора G1, чтобы узнать, стоит ли переключаться с CMS collector при запуске конкретного приложения.

VisualVM 2.0.4 использовался для мониторинга активности процессора, кучи и GC.

Приложение было запущено с использованием следующих аргументов JVM:

jvm-line-args=-XX: UseG1GC -XX: PrintGCDetails -Xmx10G -XX:InitiatingHeapOccupancyPercent=45

Графики для CPU, GC и пространства кучи показаны ниже.

Примерно в 13:07 отмечается первое зарегистрированное действие GC, при котором используемая куча увеличивается с 8912,9 М (10220,0 М) до 4871,7 М (10224,0 М).

Полный журнал показан ниже:

 [GC pause (G1 Evacuation Pause) (young), 0.5685202 secs]
   [Parallel Time: 561.4 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 545972.2, Avg: 545972.4, Max: 545972.5, Diff: 0.3]
      [Ext Root Scanning (ms): Min: 0.4, Avg: 0.6, Max: 1.1, Diff: 0.8, Sum: 4.8]
      [Update RS (ms): Min: 165.3, Avg: 166.3, Max: 168.1, Diff: 2.8, Sum: 1330.1]
         [Processed Buffers: Min: 40, Avg: 42.5, Max: 48, Diff: 8, Sum: 340]
      [Scan RS (ms): Min: 19.5, Avg: 22.2, Max: 23.7, Diff: 4.2, Sum: 177.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.5, Max: 4.2, Diff: 4.2, Sum: 4.3]
      [Object Copy (ms): Min: 368.6, Avg: 369.4, Max: 371.3, Diff: 2.8, Sum: 2955.2]
      [Termination (ms): Min: 0.0, Avg: 2.0, Max: 2.6, Diff: 2.6, Sum: 16.0]
         [Termination Attempts: Min: 1, Avg: 13463.1, Max: 17469, Diff: 17468, Sum: 107705]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
      [GC Worker Total (ms): Min: 561.0, Avg: 561.1, Max: 561.3, Diff: 0.3, Sum: 4488.5]
      [GC Worker End (ms): Min: 546533.4, Avg: 546533.4, Max: 546533.5, Diff: 0.1]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 1.1 ms]
   [Other: 5.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.8 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.6 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.3 ms]
      [Free CSet: 1.8 ms]
   [Eden: 4438.0M(4438.0M)->0.0B(2048.0K) Survivors: 0.0B->556.0M Heap: 8912.9M(10220.0M)->4871.7M(10224.0M)]
 [Times: user=4.28 sys=0.20, real=0.56 secs] 
  

После этого, как показано на графике выше, появляется много небольших всплесков GC, показывающих, что куче разрешено расти только немного до запуска GC.

Возможно ли вызывать GC реже, освобождая при этом тот же общий объем мусора?

Я пытался использовать -XX:InitiatingHeapOccupancyPercent=75 , однако заметной разницы не было.

Любые предложения будут оценены.

Стандартный вывод для меньших циклов GC:

 [GC pause (G1 Evacuation Pause) (young), 0.0807666 secs]
   [Parallel Time: 78.9 ms, GC Workers: 8]
      [GC Worker Start (ms): Min: 570672.2, Avg: 570672.3, Max: 570672.3, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.2, Max: 0.5, Diff: 0.3, Sum: 1.9]
      [Update RS (ms): Min: 36.9, Avg: 38.8, Max: 39.8, Diff: 2.9, Sum: 310.0]
         [Processed Buffers: Min: 35, Avg: 36.6, Max: 42, Diff: 7, Sum: 293]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 38.6, Avg: 39.7, Max: 41.4, Diff: 2.8, Sum: 317.3]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 8]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.3]
      [GC Worker Total (ms): Min: 78.7, Avg: 78.7, Max: 78.8, Diff: 0.2, Sum: 629.8]
      [GC Worker End (ms): Min: 570751.0, Avg: 570751.0, Max: 570751.0, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.3 ms]
   [Other: 1.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.5 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 502.0M(502.0M)->0.0B(446.0M) Survivors: 8192.0K->64.0M Heap: 5383.7M(10224.0M)->4954.7M(10224.0M)]
 [Times: user=0.63 sys=0.00, real=0.08 secs]