性能测试和优化实录（mybatisplus异步写库@Async引起的对象无法释放问题）
2024-06-10 00:51:56
通过调整和优化系统运行参数，观察性能测试结果：
1. 全部使用默认参数
1.1 启动脚本
java -jar server.jar1.1 jmap -heap数据
# jmap -heap 2605
Attaching to process ID 2605, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.152-b16using thread-local object allocation.
Parallel GC with 10 thread(s)Heap Configuration:MinHeapFreeRatio = 0MaxHeapFreeRatio = 100MaxHeapSize = 4127195136 (3936.0MB)NewSize = 85983232 (82.0MB)MaxNewSize = 1375731712 (1312.0MB)OldSize = 171966464 (164.0MB)NewRatio = 2SurvivorRatio = 8MetaspaceSize = 21807104 (20.796875MB)CompressedClassSpaceSize = 1073741824 (1024.0MB)MaxMetaspaceSize = 17592186044415 MBG1HeapRegionSize = 0 (0.0MB)Heap Usage:
PS Young Generation
Eden Space:capacity = 924319744 (881.5MB)used = 244085456 (232.7780303955078MB)free = 680234288 (648.7219696044922MB)26.407036913840933% used
From Space:capacity = 8912896 (8.5MB)used = 8880272 (8.468887329101562MB)free = 32624 (0.0311126708984375MB)99.63396857766544% used
To Space:capacity = 11010048 (10.5MB)used = 0 (0.0MB)free = 11010048 (10.5MB)0.0% used
PS Old Generationcapacity = 256901120 (245.0MB)used = 25238840 (24.06963348388672MB)free = 231662280 (220.93036651611328MB)9.824340197504783% used
这个时候的空间分配中，From Space和To Space的空间非常小，这是由于jvm自动调整了初始值的原因。
1.3 压力测试数据（15分钟）
jmeter -n -t tp192-168-0-208.jmx -l test.jtl -e -o result
Creating summariser <summary>
Created the tree successfully using tp192-168-0-208.jmx
Starting standalone test @ Fri May 13 10:14:22 CST 2022 (1652408062039)
Waiting for possible Shutdown/StopTestNow/HeapDump/ThreadDump message on port 4445
summary + 104 in 00:00:08 = 13.5/s Avg: 3540 Min: 122 Max: 7538 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary + 5774 in 00:00:30 = 192.5/s Avg: 260 Min: 60 Max: 1235 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 5878 in 00:00:38 = 156.0/s Avg: 318 Min: 60 Max: 7538 Err: 0 (0.00%)
summary + 6478 in 00:00:30 = 215.8/s Avg: 231 Min: 56 Max: 956 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 12356 in 00:01:08 = 182.5/s Avg: 272 Min: 56 Max: 7538 Err: 0 (0.00%)
summary + 4027 in 00:01:00 = 67.1/s Avg: 220 Min: 57 Max: 852 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 16383 in 00:02:08 = 128.3/s Avg: 260 Min: 56 Max: 7538 Err: 0 (0.00%)
summary + 4737 in 00:00:30 = 158.0/s Avg: 222 Min: 58 Max: 773 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 21120 in 00:02:38 = 133.9/s Avg: 251 Min: 56 Max: 7538 Err: 0 (0.00%)
summary + 6646 in 00:00:30 = 221.5/s Avg: 222 Min: 57 Max: 860 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 27766 in 00:03:08 = 147.9/s Avg: 244 Min: 56 Max: 7538 Err: 0 (0.00%)
summary + 4974 in 00:00:35 = 140.2/s Avg: 231 Min: 54 Max: 1708 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 32740 in 00:03:43 = 146.7/s Avg: 242 Min: 54 Max: 7538 Err: 0 (0.00%)
summary + 12 in 00:00:25 = 0.5/s Avg: 304 Min: 160 Max: 426 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 32752 in 00:04:09 = 131.7/s Avg: 242 Min: 54 Max: 7538 Err: 0 (0.00%)
summary + 4049 in 00:00:29 = 139.2/s Avg: 222 Min: 49 Max: 917 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 36801 in 00:04:38 = 132.5/s Avg: 240 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6332 in 00:00:30 = 210.9/s Avg: 219 Min: 51 Max: 1199 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 43133 in 00:05:08 = 140.2/s Avg: 237 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 5845 in 00:00:30 = 194.9/s Avg: 228 Min: 57 Max: 1124 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 48978 in 00:05:38 = 145.0/s Avg: 236 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 156 in 00:00:31 = 5.0/s Avg: 278 Min: 77 Max: 816 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 49134 in 00:06:09 = 133.3/s Avg: 236 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 3048 in 00:00:29 = 104.9/s Avg: 229 Min: 60 Max: 827 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 52182 in 00:06:38 = 131.2/s Avg: 236 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6161 in 00:00:30 = 205.2/s Avg: 227 Min: 55 Max: 963 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 58343 in 00:07:08 = 136.4/s Avg: 235 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6186 in 00:00:30 = 206.4/s Avg: 224 Min: 55 Max: 930 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 64529 in 00:07:38 = 141.0/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 985 in 00:00:36 = 27.4/s Avg: 231 Min: 61 Max: 637 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 65514 in 00:08:14 = 132.7/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 2020 in 00:00:24 = 83.9/s Avg: 231 Min: 61 Max: 704 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 67534 in 00:08:38 = 130.5/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6109 in 00:00:30 = 203.6/s Avg: 227 Min: 56 Max: 822 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 73643 in 00:09:08 = 134.5/s Avg: 233 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6437 in 00:00:30 = 214.5/s Avg: 222 Min: 54 Max: 918 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 80080 in 00:09:38 = 138.6/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 1809 in 00:00:31 = 58.0/s Avg: 238 Min: 60 Max: 752 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 81889 in 00:10:09 = 134.5/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 1000 in 00:00:29 = 34.7/s Avg: 235 Min: 59 Max: 719 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 82889 in 00:10:38 = 130.0/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6135 in 00:00:30 = 204.5/s Avg: 229 Min: 53 Max: 822 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 89024 in 00:11:08 = 133.3/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 6566 in 00:00:30 = 218.8/s Avg: 223 Min: 53 Max: 855 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 95590 in 00:11:38 = 137.0/s Avg: 231 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 2697 in 00:00:31 = 87.2/s Avg: 233 Min: 61 Max: 793 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 98287 in 00:12:09 = 134.9/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 526 in 00:00:30 = 17.5/s Avg: 292 Min: 70 Max: 1009 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 98813 in 00:12:39 = 130.3/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 5541 in 00:00:29 = 188.4/s Avg: 234 Min: 56 Max: 1380 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 104354 in 00:13:08 = 132.4/s Avg: 232 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 5681 in 00:00:30 = 191.4/s Avg: 263 Min: 61 Max: 1721 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 110035 in 00:13:38 = 134.6/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 4969 in 00:00:31 = 162.6/s Avg: 232 Min: 57 Max: 882 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 115004 in 00:14:08 = 135.6/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 167 in 00:00:32 = 5.2/s Avg: 333 Min: 83 Max: 790 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 115171 in 00:14:41 = 130.8/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
summary + 3652 in 00:00:20 = 180.2/s Avg: 230 Min: 59 Max: 841 Err: 0 (0.00%) Active: 0 Started: 50 Finished: 50
summary = 118823 in 00:15:01 = 131.9/s Avg: 234 Min: 49 Max: 7538 Err: 0 (0.00%)
Tidying up ... @ Fri May 13 10:29:23 CST 2022 (1652408963170)
... end of run可以看到其中，有间歇性的性能骤降现象，降低幅度非常大，从100多，直接下降到了个位数。
1.4 性能统计报告（15分钟）
1.5 图形报告（15分钟）
可以看到性能报告上的性能数据是大幅波动的。
2. 使用优化参数
禁用自动优化
2.1 启动脚本
java -Xms4096m -Xmx4096m -Xmn1024m -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -jar server.jar2.2 jmap -heap数据
# jmap -heap 3561
Attaching to process ID 3561, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.152-b16using thread-local object allocation.
Parallel GC with 10 thread(s)Heap Configuration:MinHeapFreeRatio = 40MaxHeapFreeRatio = 70MaxHeapSize = 4294967296 (4096.0MB)NewSize = 1073741824 (1024.0MB)MaxNewSize = 1073741824 (1024.0MB)OldSize = 3221225472 (3072.0MB)NewRatio = 2SurvivorRatio = 8MetaspaceSize = 21807104 (20.796875MB)CompressedClassSpaceSize = 1073741824 (1024.0MB)MaxMetaspaceSize = 17592186044415 MBG1HeapRegionSize = 0 (0.0MB)Heap Usage:
PS Young Generation
Eden Space:capacity = 859832320 (820.0MB)used = 41461280 (39.540557861328125MB)free = 818371040 (780.4594421386719MB)4.822019251381478% used
From Space:capacity = 106954752 (102.0MB)used = 7634944 (7.28125MB)free = 99319808 (94.71875MB)7.138480392156863% used
To Space:capacity = 106954752 (102.0MB)used = 0 (0.0MB)free = 106954752 (102.0MB)0.0% used
PS Old Generationcapacity = 3221225472 (3072.0MB)used = 704981104 (672.3223724365234MB)free = 2516244368 (2399.6776275634766MB)21.88549389441808% used39109 interned Strings occupying 3980112 bytes.
这个时候的空间分配中，From Space和To Space的空间具比较正常了，按照设置的比例分配的，这是禁用自动调整策略的结果。
2.3 压力测试数据（15分钟）
jmeter -n -t tp192-168-0-208.jmx -l test.jtl -e -o result
Creating summariser <summary>
Created the tree successfully using tp192-168-0-208.jmx
Starting standalone test @ Fri May 13 10:40:33 CST 2022 (1652409633122)
Waiting for possible Shutdown/StopTestNow/HeapDump/ThreadDump message on port 4445
summary + 3633 in 00:00:27 = 136.3/s Avg: 363 Min: 58 Max: 7301 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary + 6312 in 00:00:30 = 210.4/s Avg: 237 Min: 55 Max: 1067 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 9945 in 00:00:57 = 175.6/s Avg: 283 Min: 55 Max: 7301 Err: 0 (0.00%)
summary + 6449 in 00:00:32 = 202.7/s Avg: 221 Min: 51 Max: 1429 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 16394 in 00:01:28 = 185.3/s Avg: 258 Min: 51 Max: 7301 Err: 0 (0.00%)
summary + 2534 in 00:00:58 = 43.5/s Avg: 232 Min: 53 Max: 1104 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 18928 in 00:02:27 = 129.1/s Avg: 255 Min: 51 Max: 7301 Err: 0 (0.00%)
summary + 6412 in 00:00:30 = 213.8/s Avg: 223 Min: 52 Max: 1090 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 25340 in 00:02:57 = 143.5/s Avg: 247 Min: 51 Max: 7301 Err: 0 (0.00%)
summary + 6672 in 00:00:30 = 222.3/s Avg: 222 Min: 48 Max: 924 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 32012 in 00:03:27 = 154.9/s Avg: 242 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 2287 in 00:01:00 = 38.1/s Avg: 258 Min: 55 Max: 1112 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 34299 in 00:04:27 = 128.6/s Avg: 243 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6454 in 00:00:30 = 215.1/s Avg: 232 Min: 54 Max: 958 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 40753 in 00:04:57 = 137.4/s Avg: 241 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6569 in 00:00:30 = 219.0/s Avg: 225 Min: 51 Max: 1301 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 47322 in 00:05:27 = 144.9/s Avg: 239 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 2767 in 00:01:00 = 46.1/s Avg: 256 Min: 53 Max: 961 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 50089 in 00:06:27 = 129.5/s Avg: 240 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6066 in 00:00:30 = 202.6/s Avg: 228 Min: 53 Max: 1360 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 56155 in 00:06:57 = 134.8/s Avg: 239 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6467 in 00:00:30 = 215.5/s Avg: 227 Min: 52 Max: 1151 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 62622 in 00:07:27 = 140.2/s Avg: 237 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 3495 in 00:01:03 = 55.6/s Avg: 244 Min: 52 Max: 911 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 66117 in 00:08:30 = 129.8/s Avg: 238 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 5236 in 00:00:27 = 193.3/s Avg: 233 Min: 50 Max: 1378 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 71353 in 00:08:57 = 133.0/s Avg: 237 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6585 in 00:00:30 = 219.6/s Avg: 226 Min: 50 Max: 1145 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 77938 in 00:09:27 = 137.5/s Avg: 236 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 4342 in 00:01:03 = 69.0/s Avg: 235 Min: 52 Max: 1037 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 82280 in 00:10:30 = 130.7/s Avg: 236 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 4203 in 00:00:27 = 155.2/s Avg: 236 Min: 54 Max: 924 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 86483 in 00:10:57 = 131.7/s Avg: 236 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6698 in 00:00:30 = 223.4/s Avg: 222 Min: 50 Max: 952 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 93181 in 00:11:27 = 135.7/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 5001 in 00:00:30 = 164.0/s Avg: 235 Min: 53 Max: 1256 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 98182 in 00:11:57 = 136.9/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 282 in 00:00:30 = 9.6/s Avg: 311 Min: 76 Max: 731 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 98464 in 00:12:27 = 131.9/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 3503 in 00:00:31 = 112.8/s Avg: 247 Min: 54 Max: 1007 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 101967 in 00:12:58 = 131.1/s Avg: 236 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6495 in 00:00:29 = 224.3/s Avg: 224 Min: 50 Max: 1367 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 108462 in 00:13:27 = 134.5/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 6131 in 00:00:30 = 204.5/s Avg: 233 Min: 52 Max: 1016 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 114593 in 00:13:57 = 137.0/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 461 in 00:00:31 = 14.9/s Avg: 292 Min: 57 Max: 819 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 115054 in 00:14:28 = 132.6/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 2624 in 00:00:29 = 90.3/s Avg: 238 Min: 52 Max: 902 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 117678 in 00:14:57 = 131.2/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
summary + 495 in 00:00:04 = 136.5/s Avg: 281 Min: 62 Max: 884 Err: 0 (0.00%) Active: 0 Started: 50 Finished: 50
summary = 118173 in 00:15:00 = 131.3/s Avg: 235 Min: 48 Max: 7301 Err: 0 (0.00%)
Tidying up ... @ Fri May 13 10:55:33 CST 2022 (1652410533641)
... end of run性能测试数据仍然有间隙性的下降，而且幅度很大。
2.4 性能统计报告（15分钟）
2.5 图形报告（15分钟）
可以看到性能报告上的性能数据是大幅波动的。
3. g1垃圾回收测试
采用传说中的g1垃圾回收器进行压力测试。
3.1 启动脚本
java -Xms2048m -Xmx2048m -XX:+UseG1GC -XX:G1HeapRegionSize=1m -XX:MaxGCPauseMillis=100 -XX:+UnlockExperimentalVMOptions -jar server.jar3.2 jmap -heap数据
# jmap -heap 5587
Attaching to process ID 5587, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.152-b16using thread-local object allocation.
Garbage-First (G1) GC with 10 thread(s)Heap Configuration:MinHeapFreeRatio = 40MaxHeapFreeRatio = 70MaxHeapSize = 2147483648 (2048.0MB)NewSize = 1363144 (1.2999954223632812MB)MaxNewSize = 1287651328 (1228.0MB)OldSize = 5452592 (5.1999969482421875MB)NewRatio = 2SurvivorRatio = 8MetaspaceSize = 21807104 (20.796875MB)CompressedClassSpaceSize = 1073741824 (1024.0MB)MaxMetaspaceSize = 17592186044415 MBG1HeapRegionSize = 1048576 (1.0MB)Heap Usage:
G1 Heap:regions = 2048capacity = 2147483648 (2048.0MB)used = 1045954552 (997.4999923706055MB)free = 1101529096 (1050.5000076293945MB)48.70605431497097% used
G1 Young Generation:
Eden Space:regions = 971capacity = 1324351488 (1263.0MB)used = 1018167296 (971.0MB)free = 306184192 (292.0MB)76.88044338875693% used
Survivor Space:regions = 27capacity = 28311552 (27.0MB)used = 28311552 (27.0MB)free = 0 (0.0MB)100.0% used
G1 Old Generation:regions = 0capacity = 794820608 (758.0MB)used = 0 (0.0MB)free = 794820608 (758.0MB)0.0% used28680 interned Strings occupying 2623584 bytes.内存空间分配在刚开始时，主要分配到了Eden区，这个应该和调低了响应时间为100毫秒有关。
3.3 压力测试数据（15分钟）
jmeter -n -t tp192-168-0-208.jmx -l test.jtl -e -o result
Creating summariser <summary>
Created the tree successfully using tp192-168-0-208.jmx
Starting standalone test @ Fri May 13 11:44:15 CST 2022 (1652413455392)
Waiting for possible Shutdown/StopTestNow/HeapDump/ThreadDump message on port 4445
summary + 1250 in 00:00:14 = 87.1/s Avg: 564 Min: 76 Max: 6998 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary + 6012 in 00:00:30 = 200.2/s Avg: 249 Min: 64 Max: 931 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 7262 in 00:00:44 = 163.6/s Avg: 303 Min: 64 Max: 6998 Err: 0 (0.00%)
summary + 6603 in 00:00:30 = 220.3/s Avg: 226 Min: 58 Max: 854 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 13865 in 00:01:14 = 186.4/s Avg: 267 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 3088 in 00:01:00 = 51.5/s Avg: 228 Min: 59 Max: 825 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 16953 in 00:02:14 = 126.2/s Avg: 260 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 5683 in 00:00:30 = 189.4/s Avg: 223 Min: 58 Max: 871 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 22636 in 00:02:44 = 137.7/s Avg: 250 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 6515 in 00:00:30 = 217.1/s Avg: 220 Min: 59 Max: 859 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 29151 in 00:03:14 = 150.0/s Avg: 243 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 3608 in 00:00:31 = 117.0/s Avg: 236 Min: 62 Max: 1006 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 32759 in 00:03:45 = 145.5/s Avg: 243 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 54 in 00:00:29 = 1.9/s Avg: 248 Min: 93 Max: 444 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 32813 in 00:04:14 = 129.0/s Avg: 243 Min: 58 Max: 6998 Err: 0 (0.00%)
summary + 5257 in 00:00:30 = 175.3/s Avg: 222 Min: 55 Max: 1296 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 38070 in 00:04:44 = 133.9/s Avg: 240 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6314 in 00:00:30 = 210.4/s Avg: 221 Min: 62 Max: 957 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 44384 in 00:05:14 = 141.2/s Avg: 237 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 4765 in 00:00:30 = 157.8/s Avg: 237 Min: 57 Max: 930 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 49149 in 00:05:45 = 142.6/s Avg: 237 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 20 in 00:00:30 = 0.7/s Avg: 274 Min: 156 Max: 418 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 49169 in 00:06:14 = 131.3/s Avg: 237 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 4159 in 00:00:30 = 138.7/s Avg: 234 Min: 58 Max: 938 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 53328 in 00:06:44 = 131.9/s Avg: 237 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6448 in 00:00:30 = 214.9/s Avg: 229 Min: 60 Max: 1119 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 59776 in 00:07:14 = 137.6/s Avg: 236 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6533 in 00:00:30 = 217.7/s Avg: 220 Min: 60 Max: 1034 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 66309 in 00:07:44 = 142.8/s Avg: 234 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 263 in 00:00:34 = 7.8/s Avg: 294 Min: 77 Max: 671 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 66572 in 00:08:18 = 133.6/s Avg: 235 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 3391 in 00:00:26 = 129.7/s Avg: 238 Min: 58 Max: 951 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 69963 in 00:08:44 = 133.4/s Avg: 235 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 5254 in 00:00:30 = 175.3/s Avg: 224 Min: 60 Max: 1113 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 75217 in 00:09:14 = 135.7/s Avg: 234 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6627 in 00:00:30 = 220.6/s Avg: 225 Min: 61 Max: 1339 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 81844 in 00:09:44 = 140.0/s Avg: 233 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 1118 in 00:00:36 = 31.2/s Avg: 247 Min: 72 Max: 729 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 82962 in 00:10:20 = 133.8/s Avg: 234 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 2437 in 00:00:24 = 101.1/s Avg: 231 Min: 60 Max: 801 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 85399 in 00:10:44 = 132.5/s Avg: 233 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 5171 in 00:00:30 = 172.3/s Avg: 230 Min: 62 Max: 827 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 90570 in 00:11:14 = 134.3/s Avg: 233 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6550 in 00:00:30 = 218.3/s Avg: 221 Min: 56 Max: 1000 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 97120 in 00:11:44 = 137.9/s Avg: 232 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 4077 in 00:01:00 = 68.0/s Avg: 238 Min: 58 Max: 954 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 101197 in 00:12:44 = 132.4/s Avg: 233 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 5204 in 00:00:30 = 173.5/s Avg: 235 Min: 58 Max: 1016 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 106401 in 00:13:14 = 133.9/s Avg: 233 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 6055 in 00:00:30 = 201.8/s Avg: 227 Min: 62 Max: 901 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 112456 in 00:13:44 = 136.4/s Avg: 232 Min: 55 Max: 6998 Err: 0 (0.00%)
summary + 4446 in 00:01:00 = 74.1/s Avg: 236 Min: 54 Max: 1147 Err: 0 (0.00%) Active: 50 Started: 50 Finished: 0
summary = 116902 in 00:14:44 = 132.2/s Avg: 233 Min: 54 Max: 6998 Err: 0 (0.00%)
summary + 2734 in 00:00:16 = 171.5/s Avg: 233 Min: 61 Max: 1303 Err: 0 (0.00%) Active: 0 Started: 50 Finished: 50
summary = 119636 in 00:15:00 = 132.9/s Avg: 233 Min: 54 Max: 6998 Err: 0 (0.00%)
Tidying up ... @ Fri May 13 11:59:15 CST 2022 (1652414355945)
... end of run仍然存在间隙性的性能骤降现象。
3.4 性能统计报告（15分钟）
3.5 图形报告（15分钟）
可以看到性能报告上的性能数据是大幅波动的。
4. 压测时的服务器状态
4.1 性能测试时应用服务器状态
4.2 性能测试时数据库服务器状态
4.3 性能测试时压力端资源使用情况
5. 长时间压测后的异常情况
5.1 压测2小时以后的内存分配情况
jmap -heap 5587
Attaching to process ID 5587, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.152-b16using thread-local object allocation.
Garbage-First (G1) GC with 10 thread(s)Heap Configuration:MinHeapFreeRatio = 40MaxHeapFreeRatio = 70MaxHeapSize = 2147483648 (2048.0MB)NewSize = 1363144 (1.2999954223632812MB)MaxNewSize = 1287651328 (1228.0MB)OldSize = 5452592 (5.1999969482421875MB)NewRatio = 2SurvivorRatio = 8MetaspaceSize = 21807104 (20.796875MB)CompressedClassSpaceSize = 1073741824 (1024.0MB)MaxMetaspaceSize = 17592186044415 MBG1HeapRegionSize = 1048576 (1.0MB)Heap Usage:
G1 Heap:regions = 2048capacity = 2147483648 (2048.0MB)used = 2145644488 (2046.2460403442383MB)free = 1839160 (1.7539596557617188MB)99.91435743868351% used
G1 Young Generation:
Eden Space:regions = 0capacity = 1048576 (1.0MB)used = 0 (0.0MB)free = 1048576 (1.0MB)0.0% used
Survivor Space:regions = 0capacity = 0 (0.0MB)used = 0 (0.0MB)free = 0 (0.0MB)0.0% used
G1 Old Generation:regions = 0capacity = 2146435072 (2047.0MB)used = 2145644488 (2046.2460403442383MB)free = 790584 (0.7539596557617188MB)99.963167579103% used35898 interned Strings occupying 3762496 bytes.可以看到整个堆都被Old区全部占用了，并且可用空间比例几乎为0。
5.2 垃圾回收信息
jstat -gcutil 5587 3000S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 0.00 0.00 99.98 92.01 88.07 67991 761.119 1013 3360.058 4121.1760.00 0.00 0.00 99.99 92.01 88.07 68002 761.310 1014 3363.424 4124.7340.00 0.00 0.00 99.97 92.01 88.07 68016 761.478 1015 3366.982 4128.4600.00 0.00 0.00 99.97 92.01 88.07 68016 761.478 1015 3366.982 4128.4600.00 0.00 0.00 99.96 92.01 88.07 68024 761.647 1016 3370.487 4132.1340.00 0.00 0.00 99.96 92.01 88.07 68034 761.812 1017 3373.835 4135.6480.00 100.00 92.86 99.03 92.01 88.07 68037 761.839 1017 3377.259 4139.0980.00 0.00 0.00 99.97 92.01 88.07 68045 761.993 1018 3377.259 4139.252老年代空间已经几乎被100%占用，已经无法分配出空间来使用了。
6. 问题原因
通过堆转储文件，发现对内存中存在50多万个new出来的业务实例对象无法释放，通过检查代码，发现之前为了提高写库性能，使用了mybatisplus的异步写机制。
注释掉@Async注解，重新打包，进行压测，间隙性的性能下降以及最终的性能下降问题都没有了。只是在取消了异步写库机制，正常情况下的性能比之前的性能有一定的下降。同等条件下，异步写库性能大概220左右，取消异步写库，采用同步写日志方式后，性能在180左右，但是性能变得比较稳定，不再有大幅波动的现象了。
经过这个过程，确认了如果程序中存在重大的内存泄漏等问题，简单通过优化jvm参数是无能为力的。jvm参数的性能优化只能解决它能够解决的问题。
性能测试和优化实录（mybatisplus异步写库@Async引起的对象无法释放问题）相关推荐
- 你所不知道的日志异步落库
https://www.cnblogs.com/scy251147/p/9193075.html 在互联网设计架构过程中,日志异步落库,俨然已经是高并发环节中不可缺少的一环.为什么说是高并发环节中不可 ...
- 短小强悍的JavaScript异步调用库
原文链接: 7 lines JavaScript library for calling asynchronous functions 翻译人员: 铁锚 翻译时间: 2014年02月18日 示例地 ...
- 你完全没了解过的日志异步落库
前言 在互联网设计架构过程中,日志异步落库,俨然已经是高并发环节中不可缺少的一环.为什么说是高并发环节中不可缺少的呢? 原因在于,如果直接用mq进行日志落库的时候,低并发下,生产端生产数据,然后由消费 ...
- Qt ModbusTCP ModbusRTU 使用同步读和异步写
使用Qt自带的库开发,添加相关头文件 #include <QModbusTcpClient> #include <QModbusReply> #include <QSer ...
- Python数据分析：异常值检验的两种方法 -- Z 分数 上下分位点（放入自写库，一行代码快速实现）
本文已在公众号 " 数据分析与商业实践 " 首发.关注一下~,更多商业数据分析案例源码等你来撩.后台回复 "异常值" ,即可获取本文的案例示范与包含详细注释的源 ...
- 一位入行4年的优化师是怎么写出一本信息流广告入门书的？
作者 | 宁阿姨 责编 | 一点也点 出版社编辑访谈:宁阿姨,2016年入行做信息流广告,操作过日消耗1000元到1000000元的账户.擅长从实际操作中总结优化经验,她的公众号"三里屯信息 ...
- 【FPGA】单端口RAM的设计（异步读、异步写）
前面有博文写了同步读写和异步读.同步写的单端口RAM设计: [FPGA]单端口RAM的设计(同步读.同步写) [FPGA]单端口RAM的设计(异步读.同步写) 这篇博文讲异步读写: 在博文:[FPGA ...
- .NET WebAPI 用ExceptionFilterAttribute实现错误（异常）日志的记录（log4net做写库操作）
.NET WebAPI 用ExceptionFilterAttribute实现错误(异常)日志的记录(log4net做写库操作) 参考文章: (1).NET WebAPI 用ExceptionFilt ...
- DL之NN/CNN：NN算法进阶优化(本地数据集50000张训练集图片)，六种不同优化算法实现手写数字图片识别逐步提高99.6%准确率
DL之NN/CNN:NN算法进阶优化(本地数据集50000张训练集图片),六种不同优化算法实现手写数字图片识别逐步提高99.6%准确率 目录 设计思路 设计代码 设计思路 设计代码 import mn ...
最新文章
- HDU2853（最大权完美匹配）
- （转）IE的box模型显示bug
- ZeptoN正在将程序放入Java
- java 考试复习整理——JAVA类和类成员的修饰符
- java 基础编程题 5
- IAM页，IAM链表，分配单元
- linux 下挂载光驱
- k8s部署jar包_K8S部署SpringBoot应用_都超的博客-CSDN博客_k8s springboot
- 如何下载Discuz
- 九宫怎么排列和使用_开心数独：好友都在玩的数独九宫格小游戏，居家无聊杀时间必备！...
- 常见运维监控系统的技术选型
- Windows下载最新谷歌浏览器
- bootstrap制作一个优美的导航栏
- 【Oracle】ngrok 映射数据库地址为外网
- 手机收不到第三方发送的短信及验证码
- STC8H开发(十五): GPIO驱动Ci24R1无线模块
- 万恶的NPE如何避免，几种你必须知道的方案！！！
- BZOJ 3875: [Ahoi2014Jsoi2014]骑士游戏 dp spfa
- 区块链学习到底学什么？需要去区块链培训机构吗？
- 如何有效进行测试执行进度计划的制订