Pourquoi la taille des objets d'âge n + 1 dans suvivor actuel est-elle plus grande que celle des objets d'âge n dans suvivor précédent?

En essayant d'optimiser les drapeaux JVM GC, j'ai ajouté -XX:+PrintTenuringDistribution pour imprimer la distribution de taille d'objet de différents âges, et j'ai trouvé un phénomène étrange. Intuitivement, la taille des objets avec l'âge (n + 1) dans le processus GC actuel doit être inférieure à la taille des objets ayant l'âge n dans le dernier processus GC.Pourquoi la taille des objets d'âge n + 1 dans suvivor actuel est-elle plus grande que celle des objets d'âge n dans suvivor précédent?

Les objets avec l'âge 2 dans le second GC sont les objets avec l'âge 1 dans le premier CPG. Supposons que la taille des objets vivants avec l'âge 1 dans le premier GC est S11, et la taille des objets vivants avec l'âge 2 dans le second GC est S22. Puis S11> S22, parce que certains objets avec l'âge 1 sont détruits

Mais ce que j'ai vu est:

- age 1: 5028488 bytes, 5028488 total 
gc happened... 
- age 2: 5030440 bytes, 7630688 total 
gc happened... 
- age 3: 6864328 bytes, 10406920 total 
gc happened... 
- age 4: 13155416 bytes, 17153720 total 
gc happened... 
- age 5: 11057632 bytes, 15633880 total 
gc happened... 
- age 6: 17349112 bytes, 22898584 total

Comme on le voit, sa taille a augmenté. Je ne sais pas pourquoi c'est arrivé. Voici le journal GC complet:

2017-08-30T13:22:33.821+0800: 219271.297: [GC (Allocation Failure) 
2017-08-30T13:22:33.821+0800: 219271.297: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 5028488 bytes, 5028488 total 
- age 2:  394616 bytes, 5423104 total 
- age 3:  414024 bytes, 5837128 total 
- age 4:  851040 bytes, 6688168 total 
- age 5:  462728 bytes, 7150896 total 
- age 6:  526064 bytes, 7676960 total 
: 1343960K->9188K(1504064K), 0.0105175 secs] 5697641K->4363292K(8221504K), 0.0106539 secs] [Times: user=0.11 sys=0.01, real=0.01 secs] 
2017-08-30T13:22:33.831+0800: 219271.308: Total time for which application threads were stopped: 0.0119211 seconds, Stopping threads took: 0.0001500 seconds 
2017-08-30T13:22:34.486+0800: 219271.963: [GC (Allocation Failure) 2017-08-30T13:22:34.486+0800: 219271.963: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 2600248 bytes, 2600248 total 
- age 2: 5030440 bytes, 7630688 total 
- age 3:  392760 bytes, 8023448 total 
- age 4:  413704 bytes, 8437152 total 
- age 5:  850888 bytes, 9288040 total 
- age 6:  462488 bytes, 9750528 total 
: 1346148K->11226K(1504064K), 0.0103425 secs] 5700252K->4365843K(8221504K), 0.0104998 secs] [Times: user=0.11 sys=0.01, real=0.01 secs] 
2017-08-30T13:22:34.497+0800: 219271.973: Total time for which application threads were stopped: 0.0116511 seconds, Stopping threads took: 0.0000986 seconds 
2017-08-30T13:22:35.151+0800: 219272.627: [GC (Allocation Failure) 2017-08-30T13:22:35.151+0800: 219272.627: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 3132664 bytes, 3132664 total 
- age 2:  409928 bytes, 3542592 total 
- age 3: 6864328 bytes, 10406920 total 
- age 4:  392304 bytes, 10799224 total 
- age 5:  413120 bytes, 11212344 total 
- age 6:  588304 bytes, 11800648 total 
: 1348186K->12885K(1504064K), 0.0109247 secs] 5702803K->4367954K(8221504K), 0.0110585 secs] [Times: user=0.11 sys=0.02, real=0.01 secs] 
2017-08-30T13:22:35.162+0800: 219272.638: Total time for which application threads were stopped: 0.0122836 seconds, Stopping threads took: 0.0001519 seconds 
2017-08-30T13:22:35.841+0800: 219273.318: [GC (Allocation Failure) 2017-08-30T13:22:35.841+0800: 219273.318: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 2544776 bytes, 2544776 total 
- age 2: 1045056 bytes, 3589832 total 
- age 3:  408472 bytes, 3998304 total 
- age 4: 13155416 bytes, 17153720 total 
- age 5:  392008 bytes, 17545728 total 
- age 6:  412920 bytes, 17958648 total 
: 1349845K->19062K(1504064K), 0.0100055 secs] 5704914K->4374704K(8221504K), 0.0101450 secs] [Times: user=0.10 sys=0.02, real=0.01 secs] 
2017-08-30T13:22:35.851+0800: 219273.328: Total time for which application threads were stopped: 0.0113139 seconds, Stopping threads took: 0.0001079 seconds 
2017-08-30T13:22:36.260+0800: 219273.736: Total time for which application threads were stopped: 0.0018019 seconds, Stopping threads took: 0.0003786 seconds 
2017-08-30T13:22:36.521+0800: 219273.997: [GC (Allocation Failure) 2017-08-30T13:22:36.521+0800: 219273.997: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 2977976 bytes, 2977976 total 
- age 2:  408656 bytes, 3386632 total 
- age 3:  781704 bytes, 4168336 total 
- age 4:  407912 bytes, 4576248 total 
- age 5: 11057632 bytes, 15633880 total 
- age 6:  391592 bytes, 16025472 total 
: 1355810K->16950K(1504064K), 0.0107807 secs] 5711453K->4372995K(8221504K), 0.0109248 secs] [Times: user=0.11 sys=0.02, real=0.01 secs] 
2017-08-30T13:22:36.532+0800: 219274.008: Total time for which application threads were stopped: 0.0121995 seconds, Stopping threads took: 0.0001272 seconds 
2017-08-30T13:22:37.214+0800: 219274.691: [GC (Allocation Failure) 2017-08-30T13:22:37.214+0800: 219274.691: [ParNew Desired survivor size 85557248 bytes, new threshold 6 (max 6) 
- age 1: 3480256 bytes, 3480256 total 
- age 2:  473344 bytes, 3953600 total 
- age 3:  407336 bytes, 4360936 total 
- age 4:  781080 bytes, 5142016 total 
- age 5:  407456 bytes, 5549472 total 
- age 6: 17349112 bytes, 22898584 total

Source

2017-08-30 moshangcheng

Pourrait-il être, que les objets ne deviennent pas plus mais en croissance? Donc disons, un objet avec une référence, qui est 'null' lors de la première collection mais qui a changé pour référencer un objet réel lors de l'itération suivante? – Jonathan

Les nouveaux objets référencés lors de l'itération suivante ont leurs propres âges – moshangcheng

La formule Size(age(n+1)) < Size(age(n)) est erronée.

Utilisez votre gc.log ci-dessus comme un exemple, dans le premier gc, le Size(age(1)) est 5028488, mais dans la deuxième gc, le Size(age(1)) est 2600248, ce qui signifie que l'objet générer plus lentement que le début.

Alors, vous verrez que dans la deuxième gc, le Size(age(2)) est 5030440, presque égale à la Size(age(1)) dans la première gc, qui rendent plus grand que le l'Size(age(1)) dans la deuxième gc.

Le point clé est que la vitesse de génération est en constante évolution. Donc peut être Size(age(n+1)) < Size(age(n)), ou peut être Size(age(n+1)) > Size(age(n)), tout est possible.

J'espère que je n'ai pas mal compris votre question.

Source

2017-08-30 07:28:18 Javdroider

Les objets dont l'âge est 2 dans le second GC sont les objets dont l'âge est 1 dans le premier GC. Supposons que la taille des objets vivants avec l'âge 1 dans le premier GC est S11, et la taille des objets vivants avec l'âge 2 dans le second GC est S22. Alors S11> S22, car certains objets d'âge 1 sont détruits. – moshangcheng

L'âge de ces objets générés entre le premier GC et le second GC doit être de 1, pas de 2. – moshangcheng

ok, je vous ai. Donc c'est étrange ... – Javdroider

La solution examine de très près la bille. Votre sortie indique ParNew Desired survivor size 85557248 bytes mais en regardant votre dernier journal, vous voyez une consommation d'espace combinée de 22898584 octets. C'est plus grand que ce que le survivant peut prendre. Donc, fondamentalement, votre âge-statistique doit faire référence survivor et tenured en même temps.

Je suppose, vous avez quelques objets d'âge 2/3/4/5/6 qui ont déjà été promu à tenured et ne sont pas affectés par la collecte qui se passe.

Source

2017-09-07 08:24:50 Jonathan

Pourquoi la taille des objets d'âge n + 1 dans suvivor actuel est-elle plus grande que celle des objets d'âge n dans suvivor précédent?

Répondre

Questions connexes