爲什麼當前倖存者中年齡爲n + 1的對象的大小大於前一個倖存者中的年齡爲n的對象的大小？

Question

當試圖優化JVM GC標記時，我添加了-XX:+PrintTenuringDistribution來打印不同年齡的對象大小分佈，並且我發現了一個奇怪的現象。

直觀上，當前GC過程中年齡（n + 1）的對象的大小應該小於上次GC過程中年齡爲n的對象的大小。

第二個GC中年齡爲2的對象是第一個GC中年齡爲1的那些對象。假設第一個GC中年齡爲1的活體的大小爲S11，第二個GC中年齡爲2的活體的大小爲S22。然後S11> S22，因爲隨着年齡1某些對象被銷燬

但我看到的是：

- 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 

正如我們看到的，它的尺寸增大。我不知道爲什麼會發生這種情況。以下是完整的GC日誌：

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 

Answer 1

公式Size(age(n+1)) < Size(age(n))是錯誤的。

使用您gc.log上面作爲一個例子，在第一GC分析表明，Size(age(1))是5028488，但在第二GC分析表明，Size(age(1))是2600248，這意味着對象產生比開始更慢。

所以，你會看到，在第二GC，該Size(age(2)）爲5030440，幾乎等於在第一GC的Size(age(1))，這使得它比第二GC的的Size(age(1))更大。

關鍵是生成速度是不斷變化。所以可能是Size(age(n+1)) < Size(age(n))，或者可能是Size(age(n+1)) > Size(age(n))，這一切都有可能。

希望我沒有誤解你的問題。

Answer 2

該解決方案正在密切關注日誌。您的輸出顯示爲ParNew Desired survivor size 85557248 bytes，但查看最後一個日誌，則會看到總共消耗22898584字節的空間。這比倖存者可以接受的要大。所以基本上，你的年齡統計必須同時參考survivor和tenured。

我想，你有一些年齡爲2/3/4/5/6的物件已經被提升到tenured，並且不受收集發生的影響。