没什么用的文章，后面再完善
1. 准备工作
// 启动程序，模拟用户请求
// 每100毫秒钟创建1000线程，每个线程创建一个512kb的对象，最多100毫秒内同时存在1000线程，并发量1000/s，吞吐量6000/s，查看GC的情况
@SpringBootApplication
public class PerformanceApplication {
public static void main(String[] args) {
SpringApplication.run(PerformanceApplication.class, args);
Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> {
new Thread(() -> {
for (int i = 0; i < 1000; i++) {
try {
// 不干活，专门512kb的小对象
byte[] temp = new byte[1024 * 512];
Thread.sleep(new Random().nextInt(100)); // 随机睡眠200毫秒秒以内
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}).start();
}, 100, 100, TimeUnit.MILLISECONDS);
}
}
设置1G内存启动
java -Xmx1024m -Xloggc:gc1.log -jar performance-1.0.0.jar
观察GC日志，有大量的FULL GC产生
# tail -f gc1.log
46.475: [GC (Allocation Failure) 321425K->81068K(432640K), 0.0075337 secs]
46.538: [GC (Allocation Failure) 355013K->85772K(427008K), 0.0086097 secs]
46.598: [GC (Allocation Failure) 359880K->93436K(432128K), 0.0088183 secs]
46.657: [GC (Allocation Failure) 367774K->97997K(432128K), 0.0084785 secs]
46.717: [GC (Allocation Failure) 372349K->105773K(433152K), 0.0087932 secs]
46.777: [GC (Allocation Failure) 380907K->111333K(433152K), 0.0080634 secs]
46.837: [GC (Allocation Failure) 386375K->115525K(432128K), 0.0080195 secs]
46.896: [GC (Allocation Failure) 390685K->121653K(432640K), 0.0083160 secs]
46.954: [GC (Allocation Failure) 396899K->125197K(433152K), 0.0088764 secs]
47.014: [GC (Allocation Failure) 400910K->131950K(433152K), 0.0086126 secs]
47.076: [GC (Allocation Failure) 407797K->139046K(433664K), 0.0097555 secs]
47.136: [GC (Allocation Failure) 415227K->144230K(429568K), 0.0082831 secs]
47.145: [Full GC (Ergonomics) 144230K->46254K(430080K), 0.0217230 secs]
# jstat -gc $(jcmd | grep "jar" | awk '{print $1}') 5s
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
16384.0 14336.0 0.0 1024.0 271360.0 93443.3 54784.0 26106.4 30080.0 28148.3 3968.0 3540.2 13 0.068 2 0.060 0.128
64000.0 45056.0 0.0 44673.4 229376.0 68493.2 92672.0 46707.6 30080.0 28148.4 3968.0 3540.2 25 0.166 4 0.111 0.277
62464.0 62976.0 0.0 51777.6 220672.0 0.0 92672.0 47323.6 30080.0 28163.6 3968.0 3543.3 55 0.500 4 0.111 0.611
53248.0 53248.0 0.0 52321.6 242688.0 57571.3 92672.0 47931.6 30080.0 28163.6 3968.0 3543.3 91 0.912 4 0.111 1.023
53248.0 53248.0 0.0 50241.5 242688.0 0.0 92672.0 48667.6 30336.0 28193.4 3968.0 3543.3 137 1.439 4 0.111 1.549
49152.0 49152.0 46689.4 0.0 250880.0 123525.5 92672.0 73004.4 30336.0 28195.3 3968.0 3543.3 192 2.023 4 0.111 2.134
45568.0 45568.0 0.0 40033.2 257024.0 102403.7 98304.0 59565.9 30336.0 28201.6 3968.0 3543.3 255 2.673 7 0.192 2.865
39936.0 40448.0 0.0 36417.1 268288.0 86954.3 103936.0 52388.4 30336.0 28207.1 3968.0 3543.3 325 3.329 12 0.311 3.640
36864.0 36864.0 29280.9 0.0 274432.0 154836.3 113152.0 72922.8 30336.0 28207.1 3968.0 3543.3 402 4.050 18 0.449 4.499
33280.0 33280.0 0.0 0.0 282624.0 0.0 126976.0 43201.5 30336.0 28210.5 3968.0 3543.3 485 4.862 25 0.615 5.477
27136.0 26624.0 0.0 17024.5 294912.0 293156.7 136192.0 123050.4 30336.0 28211.7 3968.0 3543.3 572 5.664 30 0.748 6.412
12800.0 12800.0 0.0 6144.2 322560.0 0.0 128000.0 59660.9 30336.0 28211.7 3968.0 3543.3 657 6.111 33 0.812 6.923
使用https://github.com/chewiebug/GCViewer分析GC日志
gc 停顿时间23秒，gc次数6651次。没有并行gc的情况偶有都是0，full gc 1.5秒。full gc次数75次。也就是整个gc耗时23+1.5 =24.5秒。
右下角展示了GC汇总，总共停顿24.65秒，停顿了6726次，最大停顿40毫秒
内存汇总：总内存735M，FULL GC释放了13078M，年轻代GC释放了2188509M，
2. 查看配置参数
# jinfo -flags $(jcmd | grep "jar" | awk '{print $1}')
Attaching to process ID 3523, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.192-b12
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=65011712 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=357564416 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=21495808 -XX:OldSize=43515904 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC
Command line: -Xmx1024m -Xloggc:gc1.log
发现默认使用ParallelScavenge 收集器，-XX:+UseParallelGC
查看默认自适应是否打开，发现是默认打开的。
# java -XX:+PrintFlagsFinal -version| grep UseAdaptiveSizePolicy
bool UseAdaptiveSizePolicy = true {product}
bool UseAdaptiveSizePolicyFootprintGoal = true {product}
bool UseAdaptiveSizePolicyWithSystemGC = false {product}
java version "1.8.0_192"
Java(TM) SE Runtime Environment (build 1.8.0_192-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.192-b12, mixed mode)
3. 调整线程数
先查看当前gc线程的数量
# java -XX:+PrintFlagsFinal -version| grep ParallelGCThreads
uintx ParallelGCThreads = 4 {product}
java version "1.8.0_192"
Java(TM) SE Runtime Environment (build 1.8.0_192-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.192-b12, mixed mode)
调整GC的线程数为8
java -Xmx1024m -Xloggc:gc1.log -XX:ParallelGCThreads=8 -jar performance-1.0.0.jar
观察GC日志和GC情况
# jstat -gc $(jcmd | grep "jar" | awk '{print $1}') 5s
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
9216.0 6656.0 0.0 6624.1 126976.0 30307.9 33792.0 9201.9 30080.0 28162.4 3968.0 3541.5 7 0.051 1 0.033 0.084
30720.0 29696.0 0.0 29376.9 288768.0 81127.8 33792.0 26362.4 30080.0 28167.0 3968.0 3541.5 15 0.135 1 0.033 0.168
78848.0 78336.0 51297.6 0.0 192000.0 126283.7 33792.0 26890.4 30080.0 28187.2 3968.0 3544.6 34 0.460 1 0.033 0.493
55808.0 55808.0 51745.6 0.0 236032.0 170107.9 33792.0 27642.4 30080.0 28187.6 3968.0 3544.6 66 1.026 1 0.033 1.058
53248.0 53248.0 0.0 51297.6 242688.0 0.0 33792.0 28602.4 30080.0 28193.8 3968.0 3544.6 105 1.651 1 0.033 1.684
51712.0 51712.0 50273.5 0.0 245760.0 99778.1 33792.0 31162.5 30336.0 28216.8 3968.0 3544.6 154 2.372 1 0.033 2.404
50688.0 50688.0 0.0 45089.4 246784.0 20584.0 90112.0 84889.9 30336.0 28216.8 3968.0 3544.6 211 3.189 3 0.173 3.362
45568.0 45568.0 42113.3 0.0 258048.0 0.0 95744.0 58013.2 30336.0 28227.3 3968.0 3544.6 276 4.088 8 0.319 4.408
40448.0 40448.0 37985.2 0.0 268288.0 148951.5 102912.0 58035.4 30336.0 28227.3 3968.0 3544.6 348 4.930 14 0.478 5.408
36352.0 37376.0 29248.9 0.0 274432.0 103838.0 117248.0 54450.0 30336.0 28231.0 3968.0 3544.6 426 5.841 21 0.684 6.525
33792.0 33280.0 28768.9 0.0 281088.0 174840.9 137216.0 66786.2 30336.0 28231.0 3968.0 3544.6 512 6.733 28 0.860 7.594
23040.0 23040.0 15456.5 0.0 303104.0 124009.7 138752.0 66680.2 30336.0 28232.2 3968.0 3544.6 601 7.528 33 1.023 8.552
9728.0 9728.0 6752.2 0.0 329216.0 257139.0 130560.0 22606.4 30336.0 28232.8 3968.0 3545.1 684 8.122 35 1.078 9.200
3584.0 3584.0 2112.1 0.0 342016.0 142569.1 130560.0 66927.7 30336.0 28233.9 3968.0 3545.1 764 8.560 35 1.078 9.637
2048.0 2048.0 0.0 1088.0 345088.0 0.0 130560.0 82120.2 30336.0 28233.9 3968.0 3545.1 843 9.036 35 1.078 10.114
1024.0 1024.0 0.0 0.0 347136.0 0.0 151040.0 19461.8 30336.0 28234.3 3968.0 3545.1 920 9.459 37 1.120 10.579
1024.0 1024.0 544.0 0.0 347136.0 0.0 167936.0 93843.2 30336.0 28239.8 3968.0 3545.1 996 9.924 41 1.227 11.151
1024.0 1024.0 0.0 576.0 347136.0 0.0 187392.0 37104.2 30336.0 28240.2 3968.0 3545.1 1073 10.415 45 1.314 11.729
1024.0 1024.0 608.0 0.0 347136.0 0.0 203776.0 30744.1 30336.0 28240.5 3968.0 3545.1 1148 10.921 48 1.394 12.315
1024.0 1024.0 576.0 0.0 347136.0 214555.3 216064.0 187676.5 30336.0 28240.5 3968.0 3545.1 1224 11.365 50 1.440 12.805
1024.0 1024.0 576.0 0.0 347136.0 0.0 230912.0 81068.0 30336.0 28241.7 3968.0 3545.1 1300 11.829 53 1.521 13.349
1024.0 1024.0 0.0 576.0 347136.0 58922.5 245248.0 201609.5 30336.0 28241.7 3968.0 3545.1 1375 12.323 55 1.562 13.885
1024.0 1024.0 576.0 0.0 347136.0 0.0 261632.0 109684.6 30336.0 28242.0 3968.0 3545.1 1450 12.788 58 1.632 14.420
1024.0 1024.0 0.0 576.0 347136.0 286513.0 273408.0 246602.1 30336.0 28242.0 3968.0 3545.1 1525 13.271 60 1.679 14.949
1024.0 1024.0 544.0 0.0 347136.0 0.0 287744.0 84600.8 30336.0 28242.0 3968.0 3545.1 1600 13.821 63 1.756 15.578
1024.0 1024.0 0.0 512.0 347136.0 77189.9 302080.0 112878.8 30336.0 28242.0 3968.0 3545.1 1673 14.350 65 1.817 16.167
1024.0 1024.0 576.0 0.0 347136.0 0.0 301568.0 233148.0 30336.0 28247.9 3968.0 3545.1 1750 14.796 66 1.841 16.637
调整GC线程数后，每5秒的YGC，FGC，GC耗时都比之前有所降低，但不多
调整GC的线程数为2在观察，变化不大
使用UseParNewGC收集新生代空间，FGC剧增
# jstat -gc $(jcmd | grep "jar" | awk '{print $1}') 5s
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
2112.0 2112.0 1931.4 0.0 17024.0 14327.0 42368.0 13648.1 30080.0 28165.9 3968.0 3549.0 18 0.052 1 0.015 0.067
3200.0 3200.0 3072.1 0.0 25984.0 0.0 63988.0 57336.7 30080.0 28170.2 3968.0 3549.0 100 0.351 36 0.902 1.253
5184.0 5184.0 5124.6 0.0 41856.0 0.0 103284.0 93713.2 30080.0 28185.4 3968.0 3552.1 208 1.070 90 2.486 3.556
5632.0 5632.0 5124.6 0.0 45120.0 0.0 126980.0 126505.0 30080.0 28185.8 3968.0 3552.1 334 2.062 148 4.397 6.459
5632.0 5632.0 0.0 0.0 45376.0 0.0 111032.0 61501.6 30080.0 28191.6 3968.0 3552.1 501 3.167 204 6.321 9.488
5696.0 5696.0 5632.2 0.0 45568.0 0.0 111068.0 89173.9 30080.0 28211.8 3968.0 3552.1 714 4.347 266 8.319 12.667
5696.0 5696.0 0.0 5632.2 45824.0 0.0 120356.0 119428.6 30080.0 28214.4 3968.0 3552.1 972 5.599 322 10.137 15.736
5696.0 5696.0 5632.2 5632.2 46080.0 46054.0 117776.0 117394.8 30336.0 28228.3 3968.0 3552.1 1266 6.906 369 11.692 18.598
5760.0 5760.0 0.0 5632.2 46208.0 0.0 111068.0 52887.5 30336.0 28228.3 3968.0 3552.1 1585 8.310 407 13.138 21.448
5760.0 5760.0 5632.2 0.0 46464.0 0.0 111068.0 43693.1 30336.0 28232.0 3968.0 3552.1 1947 9.807 442 14.387 24.194
5824.0 5824.0 0.0 0.0 46592.0 0.0 111068.0 44229.8 30336.0 28232.0 3968.0 3552.1 2321 11.390 473 15.608 26.998
5824.0 5824.0 5632.2 0.0 46848.0 0.0 111068.0 106229.5 30336.0 28233.2 3968.0 3552.1 2759 12.933 505 16.761 29.694
5824.0 5824.0 0.0 1024.0 47104.0 46993.7 111068.0 87819.6 30336.0 28233.7 3968.0 3552.6 3210 14.473 537 17.915 32.388
使用-XX:+UseParallelOldGC，开启ParallelScavenge 收集器收集老年代，也没有多少改善
4. 使用CMS收集器
java -Xmx1024m -Xloggc:gc1.log -XX:+UseConcMarkSweepGC -jar performance-1.0.0.jar
# jinfo -flags $(jcmd | grep "jar" | awk '{print $1}')
Attaching to process ID 80888, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.192-b12
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=65011712 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=348913664 -XX:MaxTenuringThreshold=6 -XX:MinHeapDeltaBytes=196608 -XX:NewSize=21626880 -XX:OldPLABSize=16 -XX:OldSize=43384832 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseFastUnorderedTimeStamps -XX:+UseParNewGC
Command line: -Xmx1024m -Xloggc:gc1.log -XX:+UseConcMarkSweepGC
YGC增加，FGC次数减少
# jstat -gc $(jcmd | grep "jar" | awk '{print $1}') 5s
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
2112.0 2112.0 1861.6 0.0 16896.0 9810.2 42368.0 10964.0 30000.0 28126.5 3888.0 3550.9 18 0.079 2 0.009 0.088
34048.0 34048.0 0.0 0.0 272640.0 216505.5 707840.0 32960.9 30000.0 28130.8 3888.0 3550.9 89 0.365 6 0.055 0.419
34048.0 34048.0 33800.2 0.0 272640.0 130578.0 707840.0 169192.9 30000.0 28145.3 3888.0 3554.0 104 0.612 6 0.055 0.667
34048.0 34048.0 0.0 33797.4 272640.0 40305.9 707840.0 611599.4 30000.0 28146.5 3888.0 3554.0 129 0.973 6 0.055 1.027
34048.0 34048.0 0.0 33795.4 272640.0 175341.4 707840.0 598308.4 30000.0 28149.5 3888.0 3554.0 163 1.454 8 0.062 1.516
34048.0 34048.0 33797.4 0.0 272640.0 192785.8 707840.0 97579.8 30000.0 28176.4 3888.0 3554.0 207 2.033 12 0.077 2.110
34048.0 34048.0 0.0 33797.4 272640.0 113810.4 707840.0 89410.7 30000.0 28176.9 3888.0 3554.0 259 2.736 14 0.084 2.820
34048.0 34048.0 0.0 33799.4 272640.0 0.0 707840.0 523112.5 30256.0 28191.1 3888.0 3554.0 321 3.479 14 0.084 3.563
34048.0 34048.0 30208.9 0.0 272640.0 137959.8 707840.0 231797.5 30256.0 28191.1 3888.0 3554.0 392 4.169 16 0.092 4.261
34048.0 34048.0 30725.3 0.0 272640.0 0.0 707840.0 646042.7 30256.0 28193.1 3888.0 3554.0 472 4.900 17 0.093 4.993
34048.0 34048.0 0.0 25091.1 272640.0 183144.3 707840.0 631219.8 30256.0 28193.1 3888.0 3554.0 561 5.679 19 0.102 5.781
34048.0 34048.0 19973.0 0.0 272640.0 0.0 707840.0 630728.3 30256.0 28194.3 3888.0 3554.0 658 6.429 21 0.110 6.540
34048.0 34048.0 3587.2 0.0 272640.0 75777.4 707840.0 27581.2 30256.0 28194.9 3888.0 3554.4 756 6.883 22 0.117 7.000
34048.0 34048.0 0.0 1029.2 272640.0 124731.2 707840.0 27604.3 30256.0 28195.9 3888.0 3554.4 854 7.193 22 0.117 7.310
34048.0 34048.0 0.0 7.1 272640.0 125280.2 707840.0 27627.3 30256.0 28195.9 3888.0 3554.4 951 7.487 22 0.117 7.604
34048.0 34048.0 5125.3 0.0 272640.0 206798.3 707840.0 27650.3 30256.0 28196.4 3888.0 3554.4 1047 7.942 22 0.117 8.059
5. 使用G1
java -Xmx1024m -Xloggc:gc1.log -XX:+UseG1GC -jar performance-1.0.0.jar
没有FGC，但是停顿时间变长
# jstat -gc $(jcmd | grep "jar" | awk '{print $1}') 5s
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
0.0 3072.0 0.0 3072.0 35840.0 1024.0 24576.0 15893.7 30080.0 28155.1 3968.0 3540.3 11 0.079 0 0.000 0.079
0.0 3072.0 0.0 3072.0 480256.0 20480.0 283648.0 194317.4 30080.0 28157.4 3968.0 3540.3 21 0.111 0 0.000 0.111
0.0 1024.0 0.0 1024.0 557056.0 29696.0 490496.0 490241.1 30080.0 28175.9 3968.0 3543.4 33 0.154 0 0.000 0.154
0.0 0.0 0.0 0.0 660480.0 17408.0 388096.0 144797.0 30080.0 28175.9 3968.0 3543.4 56 0.250 0 0.000 0.250
0.0 0.0 0.0 0.0 660480.0 15360.0 388096.0 173093.3 30080.0 28182.8 3968.0 3543.4 84 0.342 0 0.000 0.342
0.0 1024.0 0.0 1024.0 659456.0 16384.0 388096.0 197765.9 30336.0 28206.0 3968.0 3543.4 121 0.499 0 0.000 0.499
0.0 0.0 0.0 0.0 629760.0 38912.0 418816.0 418732.3 30336.0 28207.1 3968.0 3543.4 166 0.965 0 0.000 0.965
0.0 0.0 0.0 0.0 596992.0 36864.0 451584.0 450659.4 30336.0 28220.6 3968.0 3543.4 219 1.740 0 0.000 1.740
0.0 0.0 0.0 0.0 55296.0 7168.0 993280.0 595972.5 30336.0 28220.6 3968.0 3543.4 281 2.757 0 0.000 2.757
0.0 0.0 0.0 0.0 55296.0 4096.0 993280.0 400753.0 30336.0 28221.0 3968.0 3543.4 354 4.035 0 0.000 4.035
0.0 0.0 0.0 0.0 55296.0 5120.0 993280.0 515319.2 30336.0 28222.3 3968.0 3543.4 435 5.616 0 0.000 5.616
0.0 0.0 0.0 0.0 524288.0 8192.0 524288.0 430204.9 30336.0 28223.5 3968.0 3543.4 529 7.274 0 0.000 7.274
0.0 0.0 0.0 0.0 55296.0 2048.0 993280.0 594269.0 30336.0 28224.0 3968.0 3543.8 619 9.167 0 0.000 9.167
0.0 0.0 0.0 0.0 55296.0 2048.0 993280.0 657918.1 30336.0 28226.3 3968.0 3543.8 713 11.149 0 0.000 11.149
0.0 0.0 0.0 0.0 55296.0 1024.0 993280.0 611886.0 30336.0 28226.3 3968.0 3543.8 808 13.313 0 0.000 13.313
0.0 0.0 0.0 0.0 55296.0 2048.0 993280.0 762033.6 30336.0 28226.8 3968.0 3543.8 909 15.617 0 0.000 15.617
0.0 0.0 0.0 0.0 55296.0 2048.0 993280.0 777123.6 30336.0 28230.5 3968.0 3543.8 1016 18.021 0 0.000 18.021
