Garbage Collector acting up
I have this strange issue where
the young generation garbage collector will run relatively stable and then all of a sudden I start getting spikes in the amount of time that the garbage collector takes to garbarge collect, after that spike, then my heap memory then steps up.
This memory steps up without any particular change in the number of users logged on to my application. This carries on until my application runs out of memory.
Here are my settings for the garbage collector:
-XX:+UseConcMarkSweepGC
-XX:+UseParNewGC
-XX:+CMSParallelRemarkEnabled
-XX:+DisableExplicitGC
-XX:NewRatio=5
-XX:+CMSClassUnloadingEnabled
-XX:+CMSPermGenSweepingEnabled
-XX:MaxPermSize=256m
-XX:PermSize=256m
-XX:+PrintGCDetails
-XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCTimeStamps
-XX:+PrintClassHistogram
Here are my gcverbose results
17.580: [GC 17.580: [ParNew: 42432K->0K(42496K), 0.0215580 secs] 82628K->44811K(2097088K), 0.0217790 secs]
Total time for which application threads were stopped: 0.0227310 seconds
Application time: 5.5160500 seconds
Total time for which application threads were stopped: 0.0022780 seconds
Application time: 9.3648450 seconds
107.680: [GC 107.680: [ParNew: 42432K->0K(42496K), 0.0195600 secs] 87243K->47376K(2097088K), 0.0198420 secs]
Total time for which application threads were stopped: 0.0233310 seconds
Application time: 0.0000690 seconds
110.716: [GC [1 CMS-initial-mark: 47376K(2054592K)] 79156K(2097088K), 0.0646700 secs]
Total time for which application threads were stopped: 0.0655250 seconds
110.781: [CMS-concurrent-mark-start]
111.109: [CMS-concurrent-mark: 0.311/0.328 secs]
111.109: [CMS-concurrent-preclean-start]
111.109: [CMS-concurrent-preclean: 0.000/0.000 secs]
111.131: [CMS-concurrent-abortable-preclean-start]
111.131: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs]
Application time: 0.3636200 seconds
111.146: [GC 111.146: [ParNew: 42432K->0K(42496K), 0.0516670 secs] 89808K->56612K(2097088K), 0.0518910 secs]
Total time for which application threads were stopped: 0.0537220 seconds
Application time: 0.3591860 seconds
Total time for which application threads were stopped: 0.0036680 seconds
Application time: 0.0013640 seconds
Total time for which application threads were stopped: 0.0093000 seconds
Application time: 0.5565030 seconds
113.142: [GC[YG occupancy: 22469 K (42496 K)]113.142: [Rescan (parallel) , 0.0274580 secs]113.169: [weak refs processing, 0.0092690 secs]113.179: [class unloading, 0.0120310 secs]113.191: [scrub symbol & string tables, 0.0134300 secs] [1 CMS-remark: 56612K(2054592K)] 79081K(2097088K), 0.0665750 secs]
Total time for which application threads were stopped: 0.0689550 seconds
113.208: [CMS-concurrent-sweep-start]
113.327: [CMS-concurrent-sweep: 0.118/0.118 secs]
113.327: [CMS-concurrent-reset-start]
113.354: [CMS-concurrent-reset: 0.027/0.027 secs]
Application time: 1.0317060 seconds
114.629: [GC 114.629: [ParNew: 42432K->0K(42496K), 0.0801980 secs] 97939K->67024K(2097088K), 0.0804280 secs]
Total time for which application threads were stopped: 0.0901380 seconds
Application time: 0.2626330 seconds
151.057: [GC 151.057: [ParNew: 42432K->0K(42496K), 0.0185890 secs] 109456K->70104K(2097088K), 0.0188130 secs]
Total time for which application threads were stopped: 0.0198380 seconds
Application time: 1.5281340 seconds
157.634: [GC 157.635: [ParNew: 42388K->0K(42496K), 0.0117010 secs] 112492K->71753K(2097088K), 0.0119210 secs]
Total time for which application threads were stopped: 0.0143500 seconds
Application time: 24.1571800 seconds
187.838: [GC 187.838: [ParNew: 42432K->0K(42496K), 0.0074590 secs] 114185K->72129K(2097088K), 0.0076680 secs]
Total time for which application threads were stopped: 0.0118190 seconds
Application time: 0.4754670 seconds
370.718: [GC 370.718: [ParNew: 42432K->0K(42496K), 0.0439000 secs] 114561K->80042K(2097088K), 0.0441300 secs]
Total time for which application threads were stopped: 0.0464790 seconds
Application time: 0.0452170 seconds
466.019: [GC 466.019: [ParNew: 42432K->0K(42496K), 0.0255300 secs] 122474K->88254K(2097088K), 0.0257610 secs]
Total time for which application threads were stopped: 0.0367150 seconds
Application time: 0.6975240 seconds
470.782: [GC 470.782: [ParNew: 42384K->0K(42496K), 0.0112810 secs] 130638K->89211K(2097088K), 0.0115160 secs]
Total time for which application threads were stopped: 0.0128740 seconds
Application time: 1.5091860 seconds
476.362: [GC 476.362: [ParNew: 42376K->0K(42496K), 0.0097560 secs] 131588K->90301K(2097088K), 0.0100030 secs]
Total time for which application threads were stopped: 0.0487770 seconds
Application time: 1.1098380 seconds
480.544: [GC 480.544: [ParNew: 42419K->0K(42496K), 0.0218910 secs] 132721K->95452K(2097088K), 0.0221570 secs]
Total time for which application threads were stopped: 0.0629710 seconds
Application time: 2.8262510 seconds
486.416: [GC 486.416: [ParNew: 42399K->0K(42496K), 0.0075800 secs] 137852K->95762K(2097088K), 0.0078130 secs]
Total time for which application threads were stopped: 0.0185480 seconds
Application time: 0.6256430 seconds
492.119: [GC 492.119: [ParNew: 42385K->0K(42496K), 0.0079840 secs] 138147K->96157K(2097088K), 0.0082230 secs]
Total time for which application threads were stopped: 0.0183040 seconds
Application time: 0.2366930 seconds
497.499: [GC 497.499: [ParNew: 42425K->0K(42496K), 0.0082640 secs] 138582K->96804K(2097088K), 0.0085080 secs]
Total time for which application threads were stopped: 0.0679420 seconds
Application time: 1.3717060 seconds
502.890: [GC 502.890: [ParNew: 42361K->0K(42496K), 0.0088880 secs] 139166K->97100K(2097088K), 0.0091300 secs]
Total time for which application threads were stopped: 0.0098200 seconds
Application time: 1.1652000 seconds
509.075: [GC 509.076: [ParNew: 42407K->0K(42496K), 0.0077870 secs] 139508K->97393K(2097088K), 0.0080050 secs]
Total time for which application threads were stopped: 0.0087100 seconds
Application time: 0.5108720 seconds
515.612: [GC 515.613: [ParNew: 42419K->0K(42496K), 0.0078420 secs] 139812K->97733K(2097088K), 0.0080550 secs]
Total time for which application threads were stopped: 0.0120880 seconds
Application time: 4.1544050 seconds
522.858: [GC 522.859: [ParNew: 42387K->0K(42496K), 0.0073200 secs] 140121K->97894K(2097088K), 0.0075240 secs]
Total time for which application threads were stopped: 0.0750940 seconds
Application time: 0.2757870 seconds
527.155: [GC 527.155: [ParNew: 42432K->0K(42496K), 0.0320710 secs] 140326K->103747K(2097088K), 0.0323320 secs]
Total time for which application threads were stopped: 0.0358400 seconds
Application time: 1.4711720 seconds
528.668: [GC 528.668: [ParNew: 42427K->0K(42496K), 0.0916280 secs] 146174K->115816K(2097088K), 0.0919210 secs]
Total time for which application threads were stopped: 0.1019390 seconds
Application time: 0.5533540 seconds
535.391: [GC 535.391: [ParNew: 42429K->0K(42496K), 0.0188970 secs] 158246K->120054K(2097088K), 0.0191740 secs]
Total time for which application threads were stopped: 0.0208940 seconds
Application time: 0.3514440 seconds
544.863: [GC 544.863: [ParNew: 42409K->0K(42496K), 0.0074710 secs] 162464K->120069K(2097088K), 0.0076830 secs]
Total time for which application threads were stopped: 0.0113280 seconds
Application time: 8.1362510 seconds
553.017: [GC 553.018: [ParNew: 42379K->0K(42496K), 0.0075020 secs] 162449K->120124K(2097088K), 0.0077510 secs]
Total time for which application threads were stopped: 0.0178720 seconds
Application time: 9.3105270 seconds
562.402: [GC 562.402: [ParNew: 42388K->0K(42496K), 0.0076760 secs] 162513K->120177K(2097088K), 0.0079370 secs]
Total time for which application threads were stopped: 0.0744880 seconds
Application time: 0.2322450 seconds
569.662: [GC 569.662: [ParNew: 42423K->0K(42496K), 0.0073750 secs] 162600K->120209K(2097088K), 0.0075710 secs]
Total time for which application threads were stopped: 0.0110060 seconds
Application time: 7.1814450 seconds
579.930: [GC 579.930: [ParNew: 42424K->0K(42496K), 0.0075510 secs] 162633K->120289K(2097088K), 0.0077900 secs]
Total time for which application threads were stopped: 0.0718150 seconds
Application time: 6.5578540 seconds
588.505: [GC 588.505: [ParNew: 42409K->0K(42496K), 0.0073690 secs] 162698K->120341K(2097088K), 0.0076010 secs]
Total time for which application threads were stopped: 0.0116230 seconds
Application time: 7.8242660 seconds
597.413: [GC 597.413: [ParNew: 42368K->0K(42496K), 0.0077620 secs] 162709K->120393K(2097088K), 0.0080020 secs]
Total time for which application threads were stopped: 0.0724050 seconds
Application time: 8.7199090 seconds
606.142: [GC 606.142: [ParNew: 42359K->0K(42496K), 0.0072020 secs] 162753K->120408K(2097088K), 0.0074420 secs]
Total time for which application threads were stopped: 0.0081880 seconds
Application time: 6.4045020 seconds
613.557: [GC 613.557: [ParNew: 42432K->0K(42496K), 0.0073660 secs] 162840K->120425K(2097088K), 0.0075960 secs]
Total time for which application threads were stopped: 0.0083990 seconds
Application time: 3.3837360 seconds
621.959: [GC 621.960: [ParNew: 42426K->0K(42496K), 0.0074040 secs] 162851K->120447K(2097088K), 0.0076290 secs]
Total time for which application threads were stopped: 0.0082570 seconds
Application time: 8.2292610 seconds
630.197: [GC 630.197: [ParNew: 42398K->0K(42496K), 0.0072320 secs] 162846K->120458K(2097088K), 0.0074710 secs]
Total time for which application threads were stopped: 0.0082540 seconds
Application time: 2.1770020 seconds
639.395: [GC 639.395: [ParNew: 42346K->0K(42496K), 0.0074520 secs] 162804K->120466K(2097088K), 0.0076710 secs]
Total time for which application threads were stopped: 0.0083380 seconds
Application time: 1.9057240 seconds
648.323: [GC 648.324: [ParNew: 42410K->0K(42496K), 0.0072910 secs] 162877K->120520K(2097088K), 0.0075080 secs]
Total time for which application threads were stopped: 0.0083250 seconds
Application time: 7.5699630 seconds
655.902: [GC 655.902: [ParNew: 42413K->0K(42496K), 0.0075430 secs] 162934K->120584K(2097088K), 0.0077280 secs]
Total time for which application threads were stopped: 0.0084790 seconds
Application time: 1.8521420 seconds
665.777: [GC 665.777: [ParNew: 42416K->0K(42496K), 0.0073860 secs] 163001K->120592K(2097088K), 0.0076030 secs]
Total time for which application threads were stopped: 0.0080980 seconds
Application time: 9.7296780 seconds
675.515: [GC 675.515: [ParNew: 42383K->0K(42496K), 0.0071860 secs] 162976K->120609K(2097088K), 0.0074170 secs]
Total time for which application threads were stopped: 0.0081600 seconds
Application time: 6.5283690 seconds
685.060: [GC 685.060: [ParNew: 42429K->0K(42496K), 0.0072750 secs] 163038K->120628K(2097088K), 0.0075140 secs]
Total time for which application threads were stopped: 0.0082850 seconds
Application time: 8.6247490 seconds
693.693: [GC 693.693: [ParNew: 42432K->0K(42496K), 0.0073320 secs] 163060K->120648K(2097088K), 0.0075500 secs]
Total time for which application threads were stopped: 0.0082780 seconds
Application time: 8.6770310 seconds
702.378: [GC 702.378: [ParNew: 42425K->0K(42496K), 0.0075490 secs] 163074K->120732K(2097088K), 0.0077640 secs]
Total time for which application threads were stopped: 0.0083950 seconds
Application time: 1.1906110 seconds
711.592: [GC 711.592: [ParNew: 42430K->0K(42496K), 0.0075270 secs] 163162K->120829K(2097088K), 0.0077580 secs]
Total time for which application threads were stopped: 0.0084010 seconds
Application time: 7.6420210 seconds
720.245: [GC 720.245: [ParNew: 42430K->0K(42496K), 0.0072620 secs] 163259K->120839K(2097088K), 0.0074850 secs]
Total time for which application threads were stopped: 0.0080590 seconds
Application time: 9.7283290 seconds
729.982: [GC 729.982: [ParNew: 42359K->0K(42496K), 0.0073820 secs] 163198K->120847K(2097088K), 0.0076190 secs]
Total time for which application threads were stopped: 0.0082420 seconds
Application time: 10.7635240 seconds
740.754: [GC 740.754: [ParNew: 42396K->0K(42496K), 0.0074670 secs] 163243K->120868K(2097088K), 0.0076780 secs]
Total time for which application threads were stopped: 0.0084180 seconds
Application time: 8.4111850 seconds
749.173: [GC 749.173: [ParNew: 42430K->0K(42496K), 0.0074610 secs] 163298K->120946K(2097088K), 0.0076810 secs]
Total time for which application threads were stopped: 0.0084210 seconds
Application time: 8.6986620 seconds
757.880: [GC 757.880: [ParNew: 42426K->0K(42496K), 0.0074490 secs] 163372K->120953K(2097088K), 0.0076230 secs]
Total time for which application threads were stopped: 0.0082660 seconds
Application time: 6.8305250 seconds
766.723: [GC 766.723: [ParNew: 42384K->0K(42496K), 0.0072970 secs] 163337K->120999K(2097088K), 0.0074780 secs]
Total time for which application threads were stopped: 0.0080160 seconds
Application time: 7.7509800 seconds
774.482: [GC 774.482: [ParNew: 42423K->0K(42496K), 0.0075290 secs] 163423K->121062K(2097088K), 0.0077610 secs]
Total time for which application threads were stopped: 0.0085110 seconds
Application time: 10.5079240 seconds
784.998: [GC 784.999: [ParNew: 42401K->0K(42496K), 0.0072180 secs] 163464K->121068K(2097088K), 0.0074470 secs]
Total time for which application threads were stopped: 0.0082060 seconds
Application time: 9.8203090 seconds
794.827: [GC 794.827: [ParNew: 42425K->0K(42496K), 0.0073370 secs] 163494K->121171K(2097088K), 0.0075610 secs]
Total time for which application threads were stopped: 0.0082050 seconds
Application time: 3.9443860 seconds
802.787: [GC 802.787: [ParNew: 42371K->0K(42496K), 0.0072670 secs] 163542K->121191K(2097088K), 0.0075260 secs]
Total time for which application threads were stopped: 0.0080990 seconds
Application time: 8.7973050 seconds
811.592: [GC 811.593: [ParNew: 42386K->0K(42496K), 0.0072010 secs] 163577K->121199K(2097088K), 0.0073730 secs]
Total time for which application threads were stopped: 0.0080840 seconds
Application time: 9.3248640 seconds
820.925: [GC 820.925: [ParNew: 42390K->0K(42496K), 0.0072780 secs] 163590K->121209K(2097088K), 0.0074550 secs]
Total time for which application threads were stopped: 0.0081780 seconds
Application time: 9.9347130 seconds
830.868: [GC 830.868: [ParNew: 42404K->0K(42496K), 0.0073990 secs] 163613K->121305K(2097088K), 0.0076170 secs]
Total time for which application threads were stopped: 0.0081850 seconds
Application time: 8.2200650 seconds
839.096: [GC 839.097: [ParNew: 42431K->0K(42496K), 0.0072310 secs] 163736K->121387K(2097088K), 0.0074430 secs]
Total time for which application threads were stopped: 0.0080890 seconds
Application time: 9.3640890 seconds
848.469: [GC 848.469: [ParNew: 42432K->0K(42496K), 0.0073950 secs] 163819K->121399K(2097088K), 0.0076250 secs]
Total time for which application threads were stopped: 0.0084340 seconds
Application time: 6.7684590 seconds
Total time for which application threads were stopped: 0.0017450 seconds
Application time: 0.0093970 seconds
Total time for which application threads were stopped: 0.0029210 seconds
Application time: 0.0625230 seconds
Total time for which application threads were stopped: 0.0041530 seconds
Application time: 0.0080290 seconds
Total time for which application threads were stopped: 0.0014830 seconds
Application time: 0.0077600 seconds
Total time for which application threads were stopped: 0.0032360 seconds
Application time: 0.0096770 seconds
Total time for which application threads were stopped: 0.0050800 seconds
Application time: 0.2609250 seconds
855.627: [GC 855.627: [ParNew: 42430K->0K(42496K), 0.0168920 secs] 163829K->123676K(2097088K), 0.0171860 secs]
If anyone cal help please. I just want to understand why there are such jumps in gc times as well as why the memory usage increases after the spikes.