2017-09-28 1 views
0

J'ai créé un programme Java de test pour aider à comprendre le fonctionnement du G1GC.G1GC - Comment Tenured peut-il être nettoyé sans GC mélangé?

Mon programme a deux threads - on charge un grand ArrayList avec environ 200 Mo d'objets (seulement 1000 chaînes de caractères), puis il supprime un élément et ajoute un élément dans une boucle avec un sommeil dedans. L'idée ici est d'avoir quelque chose qui vieillit lentement et se retrouvera dans Tenured.

L'autre thread crée simplement une grande chaîne dans une boucle while pour créer beaucoup de déchets pour provoquer des exécutions GC.

Tout cela semble fonctionner, mais ce que je suis troublé, c'est que les déchets en cours d'utilisation semblent être nettoyés sans GC mélangés en cours d'exécution.

[Eden: 581.0M(581.0M)->0.0B(573.0M) Survivors: 9216.0K->9216.0K Heap: 904.3M(1024.0M)->330.9M(1024.0M)] 
[Times: user=0.03 sys=0.00, real=0.00 secs] 
2017-09-28T16:22:14.889+0000: 2.415: 2017-09-28T16:22:14.889+0000[GC concurrent-root-region-scan-start] 
: 2.415: Total time for which application threads were stopped: 0.0081917 seconds, Stopping threads took: 0.0000852 seconds 
2017-09-28T16:22:14.889+0000: 2.415: [GC concurrent-root-region-scan-end, 0.0002779 secs] 
2017-09-28T16:22:14.889+0000: 2.415: [GC concurrent-mark-start] 
2017-09-28T16:22:14.904+0000: 2.430: [GC concurrent-mark-end, 0.0143310 secs] 
2017-09-28T16:22:14.905+0000: 2.431: [GC remark 2017-09-28T16:22:14.905+0000: 2.431: [Finalize Marking, 0.0003653 secs] 2017-09-28T16:22:14.905+0000: 2.431: [GC ref-proc2017-09-28T16:22:14.905+0000: 2.431: [SoftReference, 0 refs, 0.0008964 secs]2017-09-28T16:22:14.906+0000: 2.432: [WeakReference, 0 refs, 0.0005380 secs]2017-09-28T16:22:14.907+0000: 2.433: [FinalReference, 2 refs, 0.0005460 secs]2017-09-28T16:22:14.907+0000: 2.434: [PhantomReference, 0 refs, 0 refs, 0.0010243 secs]2017-09-28T16:22:14.908+0000: 2.435: [JNI Weak Reference, 0.0000090 secs], 0.0034419 secs] 2017-09-28T16:22:14.909+0000: 2.435: [Unloading, 0.0008396 secs], 0.0057362 secs] 
[Times: user=0.03 sys=0.00, real=0.01 secs] 
2017-09-28T16:22:14.911+0000: 2.437: Total time for which application threads were stopped: 0.0069810 seconds, Stopping threads took: 0.0011536 seconds 
2017-09-28T16:22:14.911+0000: 2.437: [GC cleanup 418M->302M(1024M), 0.0014100 secs] 
[Times: user=0.00 sys=0.00, real=0.00 secs] 
2017-09-28T16:22:14.912+0000: 2.438: Total time for which application threads were stopped: 0.0015190 seconds, Stopping threads took: 0.0000697 seconds 
2017-09-28T16:22:14.912+0000: 2.438: [GC concurrent-cleanup-start] 
2017-09-28T16:22:14.912+0000: 2.439: [GC concurrent-cleanup-end, 0.0000987 secs] 
2017-09-28T16:22:14.987+0000: 2.513: [GC pause (G1 Evacuation Pause) (young) 2.513: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4816, predicted base time: 5.38 ms, remaining time: 44.62 ms, target pause time: 50.00 ms] 
2.513: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 573 regions, survivors: 9 regions, predicted young region time: 3.54 ms] 
2.513: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 573 regions, survivors: 9 regions, old: 0 regions, predicted pause time: 8.92 ms, target pause time: 50.00 ms] 
2017-09-28T16:22:14.991+0000: 2.517: [SoftReference, 0 refs, 0.0010742 secs]2017-09-28T16:22:14.992+0000: 2.518: [WeakReference, 0 refs, 0.0006150 secs]2017-09-28T16:22:14.992+0000: 2.519: [FinalReference, 0 refs, 0.0004760 secs]2017-09-28T16:22:14.993+0000: 2.519: [PhantomReference, 0 refs, 0 refs, 0.0008707 secs]2017-09-28T16:22:14.994+0000: 2.520: [JNI Weak Reference, 0.0000094 secs] 2.521: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 14 regions, reclaimable: 13071400 bytes (1.22 %), threshold: 5.00 %] 
, 0.0077749 secs] 
    [Parallel Time: 3.6 ms, GC Workers: 16] 
     [GC Worker Start (ms): Min: 2513.1, Avg: 2513.6, Max: 2515.2, Diff: 2.1] 
     [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.9] 
     [Update RS (ms): Min: 0.0, Avg: 0.4, Max: 1.1, Diff: 1.1, Sum: 6.3] 
     [Processed Buffers: Min: 0, Avg: 1.2, Max: 4, Diff: 4, Sum: 20] 
     [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.8] 
     [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] 
     [Object Copy (ms): Min: 1.2, Avg: 2.3, Max: 2.9, Diff: 1.7, Sum: 36.9] 
     [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 2.1] 
     [Termination Attempts: Min: 1, Avg: 1.1, Max: 2, Diff: 1, Sum: 18] 
     [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.3] 
     [GC Worker Total (ms): Min: 1.4, Avg: 3.0, Max: 3.5, Diff: 2.1, Sum: 47.3] 
     [GC Worker End (ms): Min: 2516.5, Avg: 2516.6, Max: 2516.6, Diff: 0.1] 
    [Code Root Fixup: 0.0 ms] 
    [Code Root Purge: 0.0 ms] 
    [Clear CT: 0.2 ms] 
    [Other: 4.0 ms] 
     [Choose CSet: 0.0 ms] 
     [Ref Proc: 3.4 ms] 
     [Ref Enq: 0.2 ms] 
     [Redirty Cards: 0.1 ms] 
     [Humongous Register: 0.0 ms] 
     [Humongous Reclaim: 0.0 ms] 
     [Free CSet: 0.2 ms] 
    [Eden: 573.0M(573.0M)->0.0B(607.0M) Survivors: 9216.0K->7168.0K Heap: 787.9M(1024.0M)->221.4M(1024.0M)] 

Ceci est un extrait du journal GC. Notez que cette course entre:

[Eden: 581.0M(581.0M)->0.0B(573.0M) Survivors: 9216.0K->9216.0K Heap: 904.3M(1024.0M)->330.9M(1024.0M)] 
... 
[Eden: 573.0M(573.0M)->0.0B(607.0M) Survivors: 9216.0K->7168.0K Heap: 787.9M(1024.0M)->221.4M(1024.0M)] 

Ainsi, l'utilisation de Titularisé semble avoir rétréci sur cette course. Cependant, il n'y a aucune mention d'un GC mixte, enfait tout ce qu'il donne est:

[G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 14 regions, reclaimable: 13071400 bytes (1.22 %), threshold: 5.00 %] 

Ma question est - comment est l'espace nettoyé sans se titularisé un mélange (ou complet) GC passe?

Répondre

1

Aucune collection mixte n'est nécessaire pour évacuer les anciennes régions qui se sont révélées totalement non référencées par le cycle simultané.

2017-09-28T16: 22: 14,911 + 0000: 2,437: [nettoyage de GC 418M-> 302M (1024M), 0.0014100 secs]

Il y a des drapeaux d'exploitation additionnels, par exemple, -XX:+G1PrintHeapRegions, qui peut être utilisé pour suivre un tel nettoyage. Voir le oracle blog sur les journaux G1GC pour une explication détaillée.

+0

Merci. Je pense que j'ai frappé ce cas de bord comme mon code pour créer une certaine désabonnement sur les objets tenured a laissé tomber le premier élément de ma liste d'Array et a ajouté un nouveau à la fin. Lorsque j'ai rempli l'ArrayList au démarrage, je suppose que la JVM alloue des objets dans une région jusqu'à ce qu'elle soit pleine. Dès que j'ai randomisé l'élément, je laissais tomber les GC mélangés apparaissent comme prévu. –