Я запускаю программу Java с сборщиком мусора G1, используя следующие опции:
-XX:-UseBiasedLocking
-XX:+UnlockExperimentalVMOptions
-XX:+UseG1GC
-verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/var/tmp/gclog.out
Результат выглядит так:
44900.297: [GC pause (young)44900.386 (initial-mark), 0.08894851 secs]
: [GC concurrent-mark-start]
[Parallel Time: 83.7 ms]
[GC Worker Start Time (ms): 44900297.6 44900297.6 44900297.6 44900297.6 44900297.6 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7 44900297.7
Avg: 44900297.7, Min: 44900297.6, Max: 44900297.7, Diff: 0.1]
[Update RS (ms): 23.5 24.3 25.0 25.0 23.9 24.4 25.2 24.1 25.7 24.7 24.8 24.4 24.7
Avg: 24.6, Min: 23.5, Max: 25.7, Diff: 2.1]
[Processed Buffers : 16 19 19 23 20 24 18 18 18 17 20 16 19
Sum: 247, Avg: 19, Min: 16, Max: 24, Diff: 8]
[Ext Root Scanning (ms): 2.2 2.7 2.2 2.6 3.0 3.1 2.2 1.1 2.3 3.0 2.2 2.4 2.9
Avg: 2.4, Min: 1.1, Max: 3.1, Diff: 2.0]
[Mark Stack Scanning (ms): 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0 0.0
Avg: 0.0, Min: 0.0, Max: 0.0, Diff: 0.0]
[Scan RS (ms): 14.1 14.6 14.5 14.3 14.6 14.2 14.4 14.5 14.0 13.9 14.6 14.5 14.0
Avg: 14.3, Min: 13.9, Max: 14.6, Diff: 0.8]
[Object Copy (ms): 41.4 39.5 39.4 39.0 39.6 39.5 39.1 41.4 39.0 39.3 39.3 39.8 39.5
Avg: 39.7, Min: 39.0, Max: 41.4, Diff: 2.4]
[Termination (ms): 1.3 1.4 1.5 1.6 1.5 1.4 1.6 1.4 1.5 1.7 1.5 1.4 1.3
Avg: 1.5, Min: 1.3, Max: 1.7, Diff: 0.4]
[Termination Attempts : 1185 1205 1219 1436 1171 1231 1471 1237 1461 1526 1353 1259 1170
Sum: 16924, Avg: 1301, Min: 1170, Max: 1526, Diff: 356]
[GC Worker End Time (ms): 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.3 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2 44900380.2
Avg: 44900380.2, Min: 44900380.2, Max: 44900380.3, Diff: 0.1]
[GC Worker Times (ms): 82.6 82.6 82.6 82.6 82.6 82.6 82.5 82.6 82.5 82.5 82.5 82.5 82.5
Avg: 82.6, Min: 82.5, Max: 82.6, Diff: 0.1]
[Other: 1.2 ms]
[Clear CT: 0.5 ms]
[Other: 4.8 ms]
[Choose CSet: 0.0 ms]
[ 1331M->830M(1840M)]
[Times: user=1.07 sys=0.01, real=0.09 secs]
44901.205: [GC concurrent-mark-end, 0.8186002 sec]
44901.205: [GC remark, 0.0258621 secs]
[Times: user=0.02 sys=0.00, real=0.03 secs]
44901.231: [GC concurrent-count-start]
44901.479: [GC concurrent-count-end, 0.2478477]
44901.479: [GC cleanup 940M->931M(1840M), 0.0073079 secs]
Может ли кто-нибудь понять, что происходит?