【线上GC问题】-新生代设置过小且并发高的排查

一、现象描述

1.线上系统aa出现大量的FullGC,差不多每5分钟左右就来一次

 2.堆的总内存频繁的波动

3. 堆新生代的Eden区内存波动

4.新生代S区的内存波动图

 5.老年代内存波动

 

二、系统参数配置

-Xms2g
-Xmx2g
-XX:MetaspaceSize=128m
-XX:MaxMetaspaceSize=256m
-XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled
-XX:+UseCMSCompactAtFullCollection
-XX:+UseCMSInitiatingOccupancyOnly
-XX:CMSInitiatingOccupancyFraction=80
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-XX:CICompilerCount=2

三、问题分析

1.GC日志文件

Java HotSpot(TM) 64-Bit Server VM (25.231-b11) for linux-amd64 JRE (1.8.0_231-b11), built on Oct  5 2019 03:00:41 by "java_re" with gcc 7.3.0
Memory: 4k page, physical 4194304k(4192168k free), swap 0k(0k free)
CommandLine flags: -XX:CICompilerCount=2 -XX:CMSInitiatingOccupancyFraction=80 -XX:+CMSParallelRemarkEnabled -XX:CompressedClassSpaceSize=260046848 -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:MaxMetaspaceSize=268435456 -XX:MaxNewSize=523452416 -XX:MaxTenuringThreshold=6 -XX:MetaspaceSize=134217728 -XX:NewSize=523452416 -XX:OldPLABSize=16 -XX:OldSize=1046904832 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSCompactAtFullCollection -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 
2020-08-03T18:20:33.928+0800: 6.840: [GC (Allocation Failure) 2020-08-03T18:20:33.928+0800: 6.840: [ParNew: 409024K->17061K(460096K), 0.0185966 secs] 409024K->17061K(2046080K), 0.0186977 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 
2020-08-03T18:20:38.012+0800: 10.924: [GC (Allocation Failure) 2020-08-03T18:20:38.012+0800: 10.924: [ParNew: 426085K->20122K(460096K), 0.0203565 secs] 426085K->20122K(2046080K), 0.0204780 secs] [Times: user=0.06 sys=0.02, real=0.02 secs] 
2020-08-03T18:20:40.109+0800: 13.021: [GC (Allocation Failure) 2020-08-03T18:20:40.109+0800: 13.021: [ParNew: 429146K->16767K(460096K), 0.0113321 secs] 429146K->16767K(2046080K), 0.0114354 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:40.813+0800: 13.726: [GC (Allocation Failure) 2020-08-03T18:20:40.814+0800: 13.726: [ParNew: 425791K->16729K(460096K), 0.0114301 secs] 425791K->16729K(2046080K), 0.0115442 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:41.244+0800: 14.156: [GC (GCLocker Initiated GC) 2020-08-03T18:20:41.244+0800: 14.156: [ParNew: 425753K->22852K(460096K), 0.0132244 secs] 425753K->22852K(2046080K), 0.0133094 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:41.565+0800: 14.477: [GC (Allocation Failure) 2020-08-03T18:20:41.565+0800: 14.477: [ParNew: 431876K->27004K(460096K), 0.0133724 secs] 431876K->27004K(2046080K), 0.0134887 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:42.032+0800: 14.944: [GC (Allocation Failure) 2020-08-03T18:20:42.032+0800: 14.945: [ParNew: 436028K->23780K(460096K), 0.0274457 secs] 436028K->29497K(2046080K), 0.0275393 secs] [Times: user=0.12 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:42.711+0800: 15.623: [GC (Allocation Failure) 2020-08-03T18:20:42.711+0800: 15.623: [ParNew: 432804K->17487K(460096K), 0.0158206 secs] 438521K->27608K(2046080K), 0.0159313 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:43.732+0800: 16.644: [GC (Allocation Failure) 2020-08-03T18:20:43.732+0800: 16.644: [ParNew: 426511K->17963K(460096K), 0.0160253 secs] 436632K->28693K(2046080K), 0.0161386 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:44.804+0800: 17.717: [GC (Allocation Failure) 2020-08-03T18:20:44.805+0800: 17.717: [ParNew: 426987K->20757K(460096K), 0.0151127 secs] 437717K->31804K(2046080K), 0.0152256 secs] [Times: user=0.08 sys=0.01, real=0.01 secs] 
2020-08-03T18:20:47.551+0800: 20.463: [GC (Allocation Failure) 2020-08-03T18:20:47.551+0800: 20.463: [ParNew: 429781K->21071K(460096K), 0.0163087 secs] 440828K->36213K(2046080K), 0.0164123 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:48.241+0800: 21.153: [GC (Allocation Failure) 2020-08-03T18:20:48.241+0800: 21.153: [ParNew: 430095K->22948K(460096K), 0.0145895 secs] 445237K->38715K(2046080K), 0.0146956 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:49.061+0800: 21.973: [GC (Allocation Failure) 2020-08-03T18:20:49.061+0800: 21.973: [ParNew: 431972K->24002K(460096K), 0.0198639 secs] 447739K->41634K(2046080K), 0.0199915 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:49.863+0800: 22.775: [GC (Allocation Failure) 2020-08-03T18:20:49.863+0800: 22.775: [ParNew: 433026K->20270K(460096K), 0.0169517 secs] 450658K->39112K(2046080K), 0.0170863 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:50.631+0800: 23.544: [GC (Allocation Failure) 2020-08-03T18:20:50.631+0800: 23.544: [ParNew: 429294K->23524K(460096K), 0.0179428 secs] 448136K->45457K(2046080K), 0.0180568 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:51.487+0800: 24.399: [GC (Allocation Failure) 2020-08-03T18:20:51.487+0800: 24.399: [ParNew: 432548K->46068K(460096K), 0.0352409 secs] 454481K->68950K(2046080K), 0.0354077 secs] [Times: user=0.22 sys=0.01, real=0.04 secs] 
2020-08-03T18:20:52.705+0800: 25.617: [GC (Allocation Failure) 2020-08-03T18:20:52.705+0800: 25.617: [ParNew: 455092K->35061K(460096K), 0.0795932 secs] 477974K->102793K(2046080K), 0.0797539 secs] [Times: user=0.31 sys=0.02, real=0.08 secs] 
2020-08-03T18:20:53.682+0800: 26.594: [GC (Allocation Failure) 2020-08-03T18:20:53.682+0800: 26.594: [ParNew: 444085K->12709K(460096K), 0.0112715 secs] 511817K->80441K(2046080K), 0.0113894 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:54.275+0800: 27.187: [GC (Allocation Failure) 2020-08-03T18:20:54.275+0800: 27.188: [ParNew: 421733K->9938K(460096K), 0.0123515 secs] 489465K->77670K(2046080K), 0.0124477 secs] [Times: user=0.08 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:55.233+0800: 28.145: [GC (Allocation Failure) 2020-08-03T18:20:55.233+0800: 28.145: [ParNew: 418962K->26602K(460096K), 0.0168834 secs] 486694K->94334K(2046080K), 0.0170784 secs] [Times: user=0.09 sys=0.01, real=0.01 secs] 
2020-08-03T18:20:55.863+0800: 28.775: [GC (Allocation Failure) 2020-08-03T18:20:55.863+0800: 28.775: [ParNew: 435626K->22928K(460096K), 0.0168902 secs] 503358K->90660K(2046080K), 0.0170209 secs] [Times: user=0.10 sys=0.00, real=0.01 secs] 
2020-08-03T18:20:56.792+0800: 29.704: [GC (Allocation Failure) 2020-08-03T18:20:56.792+0800: 29.704: [ParNew: 431952K->22707K(460096K), 0.0164375 secs] 499684K->90439K(2046080K), 0.0165409 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:57.579+0800: 30.491: [GC (Allocation Failure) 2020-08-03T18:20:57.579+0800: 30.491: [ParNew: 431731K->23669K(460096K), 0.0182820 secs] 499463K->93538K(2046080K), 0.0183952 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:58.276+0800: 31.188: [GC (Allocation Failure) 2020-08-03T18:20:58.276+0800: 31.188: [ParNew: 432693K->15745K(460096K), 0.0244481 secs] 502562K->89035K(2046080K), 0.0245677 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:58.933+0800: 31.845: [GC (Allocation Failure) 2020-08-03T18:20:58.933+0800: 31.846: [ParNew: 424769K->15972K(460096K), 0.0204260 secs] 498059K->90461K(2046080K), 0.0206029 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:20:59.642+0800: 32.554: [GC (Allocation Failure) 2020-08-03T18:20:59.642+0800: 32.554: [ParNew: 424996K->16177K(460096K), 0.0192993 secs] 499485K->92530K(2046080K), 0.0194166 secs] [Times: user=0.11 sys=0.00, real=0.01 secs] 
2020-08-03T18:21:00.503+0800: 33.416: [GC (Allocation Failure) 2020-08-03T18:21:00.503+0800: 33.416: [ParNew: 425201K->17872K(460096K), 0.0187000 secs] 501554K->95319K(2046080K), 0.0188017 secs] [Times: user=0.11 sys=0.01, real=0.02 secs] 
2020-08-03T18:21:01.201+0800: 34.113: [GC (Allocation Failure) 2020-08-03T18:21:01.201+0800: 34.113: [ParNew: 426896K->19791K(460096K), 0.0148376 secs] 504343K->98874K(2046080K), 0.0149277 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:01.911+0800: 34.823: [GC (Allocation Failure) 2020-08-03T18:21:01.911+0800: 34.823: [ParNew: 428815K->19771K(460096K), 0.0188083 secs] 507898K->100227K(2046080K), 0.0189766 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:02.485+0800: 35.397: [GC (Allocation Failure) 2020-08-03T18:21:02.485+0800: 35.397: [ParNew: 428795K->15182K(460096K), 0.0172657 secs] 509251K->96893K(2046080K), 0.0173764 secs] [Times: user=0.10 sys=0.01, real=0.02 secs] 
2020-08-03T18:21:03.134+0800: 36.046: [GC (Allocation Failure) 2020-08-03T18:21:03.134+0800: 36.046: [ParNew: 424206K->15054K(460096K), 0.0199653 secs] 505917K->98520K(2046080K), 0.0201199 secs] [Times: user=0.13 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:03.721+0800: 36.633: [GC (Allocation Failure) 2020-08-03T18:21:03.721+0800: 36.633: [ParNew: 424078K->16871K(460096K), 0.0179418 secs] 507544K->101910K(2046080K), 0.0180915 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:04.456+0800: 37.368: [GC (Allocation Failure) 2020-08-03T18:21:04.456+0800: 37.368: [ParNew: 425895K->14702K(460096K), 0.0167995 secs] 510934K->101350K(2046080K), 0.0169078 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:05.148+0800: 38.060: [GC (Allocation Failure) 2020-08-03T18:21:05.148+0800: 38.060: [ParNew: 423726K->20903K(460096K), 0.0183309 secs] 510374K->109174K(2046080K), 0.0184363 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:05.840+0800: 38.752: [GC (Allocation Failure) 2020-08-03T18:21:05.840+0800: 38.752: [ParNew: 429927K->14425K(460096K), 0.0166173 secs] 518198K->103778K(2046080K), 0.0167376 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:06.712+0800: 39.624: [GC (Allocation Failure) 2020-08-03T18:21:06.712+0800: 39.624: [ParNew: 423449K->17770K(460096K), 0.0189778 secs] 512802K->108238K(2046080K), 0.0190946 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:07.240+0800: 40.152: [GC (Allocation Failure) 2020-08-03T18:21:07.240+0800: 40.152: [ParNew: 426794K->20041K(460096K), 0.0203357 secs] 517262K->112235K(2046080K), 0.0204526 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:07.865+0800: 40.777: [GC (Allocation Failure) 2020-08-03T18:21:07.865+0800: 40.777: [ParNew: 429065K->16458K(460096K), 0.0202534 secs] 521259K->110315K(2046080K), 0.0203850 secs] [Times: user=0.12 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:08.527+0800: 41.440: [GC (Allocation Failure) 2020-08-03T18:21:08.527+0800: 41.440: [ParNew: 425482K->19066K(460096K), 0.0176075 secs] 519339K->113650K(2046080K), 0.0177208 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:09.045+0800: 41.958: [GC (Allocation Failure) 2020-08-03T18:21:09.045+0800: 41.958: [ParNew: 428090K->15520K(460096K), 0.0197093 secs] 522674K->111416K(2046080K), 0.0198396 secs] [Times: user=0.12 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:09.577+0800: 42.490: [GC (Allocation Failure) 2020-08-03T18:21:09.577+0800: 42.490: [ParNew: 424544K->17090K(460096K), 0.0183738 secs] 520440K->113919K(2046080K), 0.0184928 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:12.799+0800: 45.711: [GC (Allocation Failure) 2020-08-03T18:21:12.799+0800: 45.711: [ParNew: 426114K->13127K(460096K), 0.0214209 secs] 522943K->112885K(2046080K), 0.0215457 secs] [Times: user=0.10 sys=0.01, real=0.02 secs] 
2020-08-03T18:21:16.777+0800: 49.689: [GC (Allocation Failure) 2020-08-03T18:21:16.777+0800: 49.689: [ParNew: 422151K->15786K(460096K), 0.0198272 secs] 521909K->116573K(2046080K), 0.0199601 secs] [Times: user=0.10 sys=0.00, real=0.02 secs] 
2020-08-03T18:21:34.074+0800: 66.987: [GC (GCLocker Initiated GC) 2020-08-03T18:21:34.074+0800: 66.987: [ParNew: 424810K->51072K(460096K), 0.0240992 secs] 525597K->172594K(2046080K), 0.0242483 secs] [Times: user=0.09 sys=0.01, real=0.02 secs] 
2020-08-03T18:21:38.217+0800: 71.129: [GC (Allocation Failure) 2020-08-03T18:21:38.217+0800: 71.129: [ParNew: 460096K->44702K(460096K), 0.0338141 secs] 581618K->206931K(2046080K), 0.0340084 secs] [Times: user=0.12 sys=0.01, real=0.03 secs] 
2020-08-03T18:21:48.810+0800: 81.722: [GC (Allocation Failure) 2020-08-03T18:21:48.810+0800: 81.722: [ParNew: 453726K->51072K(460096K), 0.0156151 secs] 615955K->219161K(2046080K), 0.0157964 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:21:55.697+0800: 88.610: [GC (Allocation Failure) 2020-08-03T18:21:55.698+0800: 88.610: [ParNew: 460096K->51072K(460096K), 0.0238222 secs] 628185K->251732K(2046080K), 0.0239578 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] 
2020-08-03T18:22:09.444+0800: 102.356: [GC (Allocation Failure) 2020-08-03T18:22:09.444+0800: 102.356: [ParNew: 460096K->51072K(460096K), 0.0165204 secs] 660756K->260384K(2046080K), 0.0167570 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:22:16.923+0800: 109.836: [GC (Allocation Failure) 2020-08-03T18:22:16.923+0800: 109.836: [ParNew: 460096K->51072K(460096K), 0.0180213 secs] 669408K->284805K(2046080K), 0.0181116 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:22:29.981+0800: 122.893: [GC (Allocation Failure) 2020-08-03T18:22:29.981+0800: 122.893: [ParNew: 460085K->51072K(460096K), 0.0147469 secs] 693819K->300945K(2046080K), 0.0149501 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:22:35.740+0800: 128.652: [GC (Allocation Failure) 2020-08-03T18:22:35.740+0800: 128.652: [ParNew: 460096K->48826K(460096K), 0.0169050 secs] 709969K->329329K(2046080K), 0.0170297 secs] [Times: user=0.06 sys=0.01, real=0.02 secs] 
2020-08-03T18:22:47.226+0800: 140.138: [GC (Allocation Failure) 2020-08-03T18:22:47.226+0800: 140.138: [ParNew: 457850K->51072K(460096K), 0.0245523 secs] 738353K->368152K(2046080K), 0.0247869 secs] [Times: user=0.08 sys=0.01, real=0.02 secs] 
2020-08-03T18:23:03.838+0800: 156.751: [GC (Allocation Failure) 2020-08-03T18:23:03.838+0800: 156.751: [ParNew: 460096K->51072K(460096K), 0.0140052 secs] 777176K->380243K(2046080K), 0.0141573 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 
2020-08-03T18:23:12.207+0800: 165.119: [GC (Allocation Failure) 2020-08-03T18:23:12.207+0800: 165.119: [ParNew: 460096K->43771K(460096K), 0.0137488 secs] 789267K->391349K(2046080K), 0.0139078 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-08-03T18:23:19.415+0800: 172.327: [GC (Allocation Failure) 2020-08-03T18:23:19.415+0800: 172.327: [ParNew: 452795K->51072K(460096K), 0.0243211 secs] 800373K->435115K(2046080K), 0.0244669 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 
2020-08-03T18:23:35.562+0800: 188.474: [GC (Allocation Failure) 2020-08-03T18:23:35.562+0800: 188.474: [ParNew: 460096K->51072K(460096K), 0.0157676 secs] 844139K->465552K(2046080K), 0.0159220 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:23:39.180+0800: 192.092: [GC (Allocation Failure) 2020-08-03T18:23:39.180+0800: 192.092: [ParNew: 460096K->51072K(460096K), 0.0236080 secs] 874576K->503296K(2046080K), 0.0237522 secs] [Times: user=0.08 sys=0.01, real=0.03 secs] 
2020-08-03T18:23:59.028+0800: 211.941: [GC (Allocation Failure) 2020-08-03T18:23:59.028+0800: 211.941: [ParNew: 460096K->49871K(460096K), 0.0115786 secs] 912320K->508295K(2046080K), 0.0117190 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:24:04.362+0800: 217.274: [GC (Allocation Failure) 2020-08-03T18:24:04.362+0800: 217.274: [ParNew: 458895K->51072K(460096K), 0.0242915 secs] 917319K->540789K(2046080K), 0.0244632 secs] [Times: user=0.09 sys=0.01, real=0.03 secs] 
2020-08-03T18:24:19.032+0800: 231.944: [GC (Allocation Failure) 2020-08-03T18:24:19.032+0800: 231.944: [ParNew: 460073K->51072K(460096K), 0.0137814 secs] 949791K->551529K(2046080K), 0.0139411 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:24:24.746+0800: 237.658: [GC (Allocation Failure) 2020-08-03T18:24:24.746+0800: 237.658: [ParNew: 460096K->51072K(460096K), 0.0179078 secs] 960553K->577879K(2046080K), 0.0180277 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 
2020-08-03T18:24:38.778+0800: 251.690: [GC (Allocation Failure) 2020-08-03T18:24:38.778+0800: 251.690: [ParNew: 460096K->51072K(460096K), 0.0193261 secs] 986903K->600777K(2046080K), 0.0195032 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 
2020-08-03T18:24:48.488+0800: 261.401: [GC (Allocation Failure) 2020-08-03T18:24:48.489+0800: 261.401: [ParNew: 460096K->51072K(460096K), 0.0176970 secs] 1009801K->627415K(2046080K), 0.0178454 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:25:01.997+0800: 274.909: [GC (Allocation Failure) 2020-08-03T18:25:01.997+0800: 274.909: [ParNew: 460096K->51072K(460096K), 0.0167257 secs] 1036439K->642935K(2046080K), 0.0168934 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 
2020-08-03T18:25:13.647+0800: 286.560: [GC (Allocation Failure) 2020-08-03T18:25:13.647+0800: 286.560: [ParNew: 460096K->51072K(460096K), 0.0138722 secs] 1051959K->661037K(2046080K), 0.0140455 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:25:20.622+0800: 293.534: [GC (Allocation Failure) 2020-08-03T18:25:20.622+0800: 293.534: [ParNew: 460096K->51072K(460096K), 0.0221201 secs] 1070061K->691522K(2046080K), 0.0222772 secs] [Times: user=0.07 sys=0.03, real=0.03 secs] 
2020-08-03T18:25:33.012+0800: 305.925: [GC (Allocation Failure) 2020-08-03T18:25:33.012+0800: 305.925: [ParNew: 460096K->51072K(460096K), 0.0139183 secs] 1100546K->715453K(2046080K), 0.0140630 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:25:43.467+0800: 316.380: [GC (Allocation Failure) 2020-08-03T18:25:43.467+0800: 316.380: [ParNew: 460096K->51072K(460096K), 0.0136765 secs] 1124477K->730802K(2046080K), 0.0138233 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:25:59.174+0800: 332.087: [GC (Allocation Failure) 2020-08-03T18:25:59.174+0800: 332.087: [ParNew: 460096K->51072K(460096K), 0.0120559 secs] 1139826K->739030K(2046080K), 0.0122184 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:26:05.025+0800: 337.937: [GC (Allocation Failure) 2020-08-03T18:26:05.025+0800: 337.937: [ParNew: 460096K->51072K(460096K), 0.0248839 secs] 1148054K->779469K(2046080K), 0.0250969 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] 
2020-08-03T18:26:21.158+0800: 354.070: [GC (Allocation Failure) 2020-08-03T18:26:21.158+0800: 354.070: [ParNew: 460096K->51072K(460096K), 0.0146199 secs] 1188493K->796633K(2046080K), 0.0148048 secs] [Times: user=0.07 sys=0.01, real=0.02 secs] 
2020-08-03T18:26:26.478+0800: 359.391: [GC (Allocation Failure) 2020-08-03T18:26:26.478+0800: 359.391: [ParNew: 460096K->46992K(460096K), 0.0203490 secs] 1205657K->827436K(2046080K), 0.0205261 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:26:44.243+0800: 377.155: [GC (Allocation Failure) 2020-08-03T18:26:44.243+0800: 377.156: [ParNew: 455985K->45195K(460096K), 0.0093961 secs] 1236429K->832826K(2046080K), 0.0095907 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-08-03T18:26:50.468+0800: 383.380: [GC (Allocation Failure) 2020-08-03T18:26:50.468+0800: 383.380: [ParNew: 454219K->51072K(460096K), 0.0133445 secs] 1241850K->846363K(2046080K), 0.0135048 secs] [Times: user=0.06 sys=0.01, real=0.01 secs] 
2020-08-03T18:27:06.500+0800: 399.412: [GC (Allocation Failure) 2020-08-03T18:27:06.500+0800: 399.412: [ParNew: 460096K->51072K(460096K), 0.0130292 secs] 1255387K->855909K(2046080K), 0.0131759 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2020-08-03T18:27:10.908+0800: 403.820: [GC (Allocation Failure) 2020-08-03T18:27:10.908+0800: 403.820: [ParNew: 460096K->51072K(460096K), 0.0204041 secs] 1264933K->897394K(2046080K), 0.0205806 secs] [Times: user=0.06 sys=0.02, real=0.02 secs] 
2020-08-03T18:27:25.625+0800: 418.537: [GC (Allocation Failure) 2020-08-03T18:27:25.625+0800: 418.537: [ParNew: 460096K->51072K(460096K), 0.0168371 secs] 1306418K->906848K(2046080K), 0.0169973 secs] [Times: user=0.08 sys=0.01, real=0.02 secs] 
2020-08-03T18:27:35.445+0800: 428.357: [GC (Allocation Failure) 2020-08-03T18:27:35.445+0800: 428.357: [ParNew: 460096K->51072K(460096K), 0.0186924 secs] 1315872K->935335K(2046080K), 0.0188661 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:27:48.225+0800: 441.137: [GC (Allocation Failure) 2020-08-03T18:27:48.225+0800: 441.137: [ParNew: 460096K->51072K(460096K), 0.0129585 secs] 1344359K->941802K(2046080K), 0.0131366 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:28:00.771+0800: 453.684: [GC (Allocation Failure) 2020-08-03T18:28:00.771+0800: 453.684: [ParNew: 460096K->51072K(460096K), 0.0130148 secs] 1350826K->955154K(2046080K), 0.0131588 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2020-08-03T18:28:06.410+0800: 459.322: [GC (Allocation Failure) 2020-08-03T18:28:06.410+0800: 459.322: [ParNew: 460096K->51072K(460096K), 0.0213365 secs] 1364178K->992223K(2046080K), 0.0215590 secs] [Times: user=0.08 sys=0.01, real=0.02 secs] 
2020-08-03T18:28:23.924+0800: 476.836: [GC (Allocation Failure) 2020-08-03T18:28:23.924+0800: 476.836: [ParNew: 460096K->51072K(460096K), 0.0127631 secs] 1401247K->994516K(2046080K), 0.0129478 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:28:31.250+0800: 484.162: [GC (Allocation Failure) 2020-08-03T18:28:31.250+0800: 484.162: [ParNew: 460096K->51072K(460096K), 0.0151551 secs] 1403540K->1006221K(2046080K), 0.0153049 secs] [Times: user=0.06 sys=0.01, real=0.02 secs] 
2020-08-03T18:28:44.791+0800: 497.703: [GC (Allocation Failure) 2020-08-03T18:28:44.791+0800: 497.703: [ParNew: 460096K->51072K(460096K), 0.0139552 secs] 1415245K->1015618K(2046080K), 0.0141451 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:28:56.550+0800: 509.462: [GC (Allocation Failure) 2020-08-03T18:28:56.550+0800: 509.462: [ParNew: 460096K->49299K(460096K), 0.0098228 secs] 1424642K->1024642K(2046080K), 0.0100308 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 
2020-08-03T18:29:02.011+0800: 514.923: [GC (Allocation Failure) 2020-08-03T18:29:02.011+0800: 514.923: [ParNew: 458323K->51072K(460096K), 0.0179244 secs] 1433666K->1044868K(2046080K), 0.0181763 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] 
2020-08-03T18:29:17.017+0800: 529.930: [GC (Allocation Failure) 2020-08-03T18:29:17.017+0800: 529.930: [ParNew: 460096K->51072K(460096K), 0.0128674 secs] 1453892K->1056619K(2046080K), 0.0130573 secs] [Times: user=0.07 sys=0.00, real=0.01 secs] 
2020-08-03T18:29:23.844+0800: 536.756: [GC (Allocation Failure) 2020-08-03T18:29:23.844+0800: 536.756: [ParNew: 460096K->51072K(460096K), 0.0124954 secs] 1465643K->1063633K(2046080K), 0.0126914 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:29:34.453+0800: 547.365: [GC (Allocation Failure) 2020-08-03T18:29:34.453+0800: 547.365: [ParNew: 460096K->51072K(460096K), 0.0178454 secs] 1472657K->1081169K(2046080K), 0.0180046 secs] [Times: user=0.07 sys=0.02, real=0.01 secs] 
2020-08-03T18:29:50.612+0800: 563.524: [GC (Allocation Failure) 2020-08-03T18:29:50.612+0800: 563.524: [ParNew: 460096K->51072K(460096K), 0.0101134 secs] 1490193K->1086487K(2046080K), 0.0102949 secs] [Times: user=0.05 sys=0.01, real=0.01 secs] 
2020-08-03T18:29:54.292+0800: 567.204: [GC (Allocation Failure) 2020-08-03T18:29:54.292+0800: 567.204: [ParNew: 460096K->51072K(460096K), 0.0228343 secs] 1495511K->1122559K(2046080K), 0.0229831 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:30:06.975+0800: 579.887: [GC (Allocation Failure) 2020-08-03T18:30:06.975+0800: 579.887: [ParNew: 460096K->51072K(460096K), 0.0249277 secs] 1531583K->1169882K(2046080K), 0.0250682 secs] [Times: user=0.08 sys=0.02, real=0.02 secs] 
2020-08-03T18:30:22.969+0800: 595.882: [GC (Allocation Failure) 2020-08-03T18:30:22.969+0800: 595.882: [ParNew: 460096K->51072K(460096K), 0.0159144 secs] 1578906K->1196690K(2046080K), 0.0160413 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2020-08-03T18:30:27.033+0800: 599.945: [GC (Allocation Failure) 2020-08-03T18:30:27.033+0800: 599.945: [ParNew: 460096K->51072K(460096K), 0.0236009 secs] 1605714K->1235151K(2046080K), 0.0237731 secs] [Times: user=0.09 sys=0.01, real=0.02 secs] 
2020-08-03T18:30:44.048+0800: 616.961: [GC (Allocation Failure) 2020-08-03T18:30:44.049+0800: 616.961: [ParNew: 460096K->51072K(460096K), 0.0128205 secs] 1644175K->1240735K(2046080K), 0.0130338 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:30:49.590+0800: 622.502: [GC (Allocation Failure) 2020-08-03T18:30:49.590+0800: 622.502: [ParNew: 460096K->51072K(460096K), 0.0176904 secs] 1649759K->1265994K(2046080K), 0.0178962 secs] [Times: user=0.07 sys=0.02, real=0.02 secs] 
2020-08-03T18:31:03.284+0800: 636.196: [GC (Allocation Failure) 2020-08-03T18:31:03.284+0800: 636.196: [ParNew: 460096K->51072K(460096K), 0.0141452 secs] 1675018K->1278250K(2046080K), 0.0143308 secs] [Times: user=0.07 sys=0.01, real=0.01 secs] 
2020-08-03T18:31:12.673+0800: 645.585: [GC (Allocation Failure) 2020-08-03T18:31:12.673+0800: 645.585: [ParNew: 460096K->51072K(460096K), 0.0188236 secs] 1687274K->1305763K(2046080K), 0.0190086 secs] [Times: user=0.06 sys=0.01, real=0.02 secs] 
2020-08-03T18:31:27.150+0800: 660.062: [GC (Allocation Failure) 2020-08-03T18:31:27.150+0800: 660.062: [ParNew: 460096K->51072K(460096K), 0.0121003 secs] 1714787K->1316545K(2046080K), 0.0122676 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:31:36.783+0800: 669.695: [GC (Allocation Failure) 2020-08-03T18:31:36.783+0800: 669.696: [ParNew: 460096K->51072K(460096K), 0.0117641 secs] 1725569K->1322074K(2046080K), 0.0119368 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:31:36.796+0800: 669.708: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1271002K(1585984K)] 1324336K(2046080K), 0.0044771 secs] [Times: user=0.01 sys=0.01, real=0.00 secs] 
2020-08-03T18:31:36.800+0800: 669.713: [CMS-concurrent-mark-start]
2020-08-03T18:31:36.893+0800: 669.805: [CMS-concurrent-mark: 0.092/0.092 secs] [Times: user=0.29 sys=0.02, real=0.10 secs] 
2020-08-03T18:31:36.893+0800: 669.805: [CMS-concurrent-preclean-start]
2020-08-03T18:31:36.900+0800: 669.812: [CMS-concurrent-preclean: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
2020-08-03T18:31:36.900+0800: 669.812: [CMS-concurrent-abortable-preclean-start]
2020-08-03T18:31:39.616+0800: 672.528: [CMS-concurrent-abortable-preclean: 0.366/2.715 secs] [Times: user=2.48 sys=0.24, real=2.72 secs] 
2020-08-03T18:31:39.616+0800: 672.529: [GC (CMS Final Remark) [YG occupancy: 283525 K (460096 K)]2020-08-03T18:31:39.616+0800: 672.529: [Rescan (parallel) , 0.0273521 secs]2020-08-03T18:31:39.644+0800: 672.556: [weak refs processing, 0.0009116 secs]2020-08-03T18:31:39.645+0800: 672.557: [class unloading, 0.0940505 secs]2020-08-03T18:31:39.739+0800: 672.651: [scrub symbol table, 0.0185008 secs]2020-08-03T18:31:39.757+0800: 672.670: [scrub string table, 0.0017257 secs][1 CMS-remark: 1271002K(1585984K)] 1554528K(2046080K), 0.1442486 secs] [Times: user=0.26 sys=0.02, real=0.14 secs] 
2020-08-03T18:31:39.761+0800: 672.673: [CMS-concurrent-sweep-start]
2020-08-03T18:31:39.824+0800: 672.736: [CMS-concurrent-sweep: 0.063/0.063 secs] [Times: user=0.20 sys=0.03, real=0.07 secs] 
2020-08-03T18:31:39.824+0800: 672.736: [CMS-concurrent-reset-start]
2020-08-03T18:31:39.828+0800: 672.741: [CMS-concurrent-reset: 0.005/0.005 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
2020-08-03T18:31:41.403+0800: 674.315: [GC (Allocation Failure) 2020-08-03T18:31:41.403+0800: 674.316: [ParNew: 460096K->51072K(460096K), 0.0163698 secs] 564268K->206474K(2046080K), 0.0165286 secs] [Times: user=0.09 sys=0.01, real=0.01 secs] 
2020-08-03T18:31:57.449+0800: 690.361: [GC (Allocation Failure) 2020-08-03T18:31:57.449+0800: 690.361: [ParNew: 460096K->51072K(460096K), 0.0125911 secs] 615498K->219961K(2046080K), 0.0127784 secs] [Times: user=0.06 sys=0.01, real=0.01 secs] 
2020-08-03T18:32:07.497+0800: 700.409: [GC (Allocation Failure) 2020-08-03T18:32:07.497+0800: 700.409: [ParNew: 460096K->49121K(460096K), 0.0096435 secs] 628985K->223159K(2046080K), 0.0098494 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:32:14.846+0800: 707.758: [GC (Allocation Failure) 2020-08-03T18:32:14.846+0800: 707.758: [ParNew: 458145K->51072K(460096K), 0.0122595 secs] 632183K->244034K(2046080K), 0.0123999 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:32:29.583+0800: 722.495: [GC (Allocation Failure) 2020-08-03T18:32:29.583+0800: 722.495: [ParNew: 460096K->51068K(460096K), 0.0093180 secs] 653058K->246134K(2046080K), 0.0094922 secs] [Times: user=0.05 sys=0.01, real=0.01 secs] 
2020-08-03T18:32:35.020+0800: 727.932: [GC (Allocation Failure) 2020-08-03T18:32:35.020+0800: 727.932: [ParNew: 460092K->51072K(460096K), 0.0160105 secs] 655158K->284761K(2046080K), 0.0162105 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 
2020-08-03T18:32:49.982+0800: 742.894: [GC (Allocation Failure) 2020-08-03T18:32:49.982+0800: 742.895: [ParNew: 460096K->51072K(460096K), 0.0115853 secs] 693785K->300831K(2046080K), 0.0118118 secs] [Times: user=0.06 sys=0.01, real=0.01 secs] 
2020-08-03T18:32:55.084+0800: 747.996: [GC (Allocation Failure) 2020-08-03T18:32:55.084+0800: 747.996: [ParNew: 460096K->49986K(460096K), 0.0131491 secs] 709855K->333028K(2046080K), 0.0133519 secs] [Times: user=0.08 sys=0.01, real=0.01 secs] 
2020-08-03T18:33:10.063+0800: 762.975: [GC (Allocation Failure) 2020-08-03T18:33:10.063+0800: 762.975: [ParNew: 459010K->51072K(460096K), 0.0107396 secs] 742052K->338530K(2046080K), 0.0109523 secs] [Times: user=0.05 sys=0.01, real=0.01 secs] 
2020-08-03T18:33:20.341+0800: 773.253: [GC (Allocation Failure) 2020-08-03T18:33:20.341+0800: 773.253: [ParNew: 460096K->51072K(460096K), 0.0097924 secs] 747554K->344628K(2046080K), 0.0099961 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:33:25.454+0800: 778.366: [GC (Allocation Failure) 2020-08-03T18:33:25.454+0800: 778.367: [ParNew: 460096K->51072K(460096K), 0.0129058 secs] 753652K->380342K(2046080K), 0.0130788 secs] [Times: user=0.08 sys=0.00, real=0.01 secs] 
2020-08-03T18:33:42.306+0800: 795.218: [GC (Allocation Failure) 2020-08-03T18:33:42.306+0800: 795.218: [ParNew: 460096K->42012K(460096K), 0.0070617 secs] 789366K->373053K(2046080K), 0.0072149 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 
2020-08-03T18:33:51.883+0800: 804.795: [GC (Allocation Failure) 2020-08-03T18:33:51.883+0800: 804.795: [ParNew: 451036K->35956K(460096K), 0.0074931 secs] 782077K->366997K(2046080K), 0.0076692 secs] [Times: user=0.04 sys=0.01, real=0.00 secs] 
2020-08-03T18:33:56.116+0800: 809.028: [GC (Allocation Failure) 2020-08-03T18:33:56.116+0800: 809.028: [ParNew: 444980K->51072K(460096K), 0.0154367 secs] 776021K->413665K(2046080K), 0.0156164 secs] [Times: user=0.09 sys=0.00, real=0.01 secs] 
2020-08-03T18:34:10.937+0800: 823.849: [GC (Allocation Failure) 2020-08-03T18:34:10.937+0800: 823.849: [ParNew: 460096K->51072K(460096K), 0.0120993 secs] 822689K->430097K(2046080K), 0.0122942 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
2020-08-03T18:34:18.792+0800: 831.704: [GC (Allocation Failure) 2020-08-03T18:34:18.792+0800: 831.705: [ParNew: 460096K->38682K(460096K), 0.0099096 secs] 839121K->439116K(2046080K), 0.0101436 secs] [Times: user=0.04 sys=0.01, real=0.01 secs] 
2020-08-03T18:34:28.798+0800: 841.710: [GC (Allocation Failure) 2020-08-03T18:34:28.798+0800: 841.710: [ParNew: 447706K->51072K(460096K), 0.0165628 secs] 848140K->496941K(2046080K), 0.0167256 secs] [Times: user=0.09 sys=0.01, real=0.02 secs] 
2020-08-03T18:34:45.211+0800: 858.124: [GC (Allocation Failure) 2020-08-03T18:34:45.211+0800: 858.124: [ParNew: 460096K->49742K(460096K), 0.0122819 secs] 905965K->521650K(2046080K), 0.0124663 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 
2020-08-03T18:34:50.227+0800: 863.139: [GC (Allocation Failure) 2020-08-03T18:34:50.227+0800: 863.139: [ParNew: 458766K->51072K(460096K), 0.0156211 secs] 930674K->554766K(2046080K), 0.0158737 secs] [Times: user=0.09 sys=0.00, real=0.02 secs] 

 

问题分析

堆内存设置2G,新生代:500M左右,老年代代1500M左右,新生代中E:S1:S2=8:1:1 也就是400M:50M:50M
结合GC日志和监控图发现,Allocation Failure 新生代内存分配失败,导致ParNew年轻代垃圾回收,持续 70次小GC后
触发小CMS垃圾回收,然后继续ParNew年轻代垃圾回收;


1.并发很高的情况下,应用从Kafka消费数据转换后再入MySQL,单个对象84KB


2.新生代内存不足,申请内存失败持续触发ParNew年轻代垃圾回收,触发了70次后,同时Eden还没来得及回收的对象被持续占满S1,最后一次minGC回收情况如下,只回收了50M,新生代空间占满了。

minGC回收回收的时候,有两个逻辑;第一个:新生代回收为回收的对象晋升到老年代,第二个:并发业务内存的申请请求到新生代发现空间不够,直接内存分配担保失败,对象直接分配到了老年代;这两种情况导致老年代也持续增长

 

3.继续看GC日志;第72次minGC后,.老年代垃圾的占了总的老年代内存80%,触发了一次老年代的CMS回收,CMS回收的过程中又触发了一次年轻代回收,这个时候新生代和老年代都在回收,直接开始Full GC
触发cms回收的过程中,并发继续,老年代剩余空间不足够新的对象分配(新生代升级的对象和直接进入老年代的业务对象) 触发cms分配担保失败,触发串行fullGC

 

最终解决方案:

内存2G不变

  • -XX:NewRatio=1   新生代:老年代=1:1 也就是各占1G
  • -XX:SurvivorRatio=2 新生代 Eden:S1:S2 =2:1:1 也就是 Eden占500M,S1占250M,S2占250M

参数调整后的效果

 

结论:

应用的特点:

1.对象朝生夕灭,且并发非常大,单个Kafka消息对象84KB
2.新生代内存空间严重不足,导致S1持续占满,S1和Eden回收后的对象持续晋升到老年代,导致CMS回收,建议这种类型的场景首先考虑将新生代整个调大,然后考虑将S区也调大

 

GC日志分析工具:gcviewer-1.36.jar

 

 

 

 

  • 0
    点赞
  • 2
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值