5

Please what memory tuning advise would you suggest given the GC log below with a system currently running on these params, taking into consideration the Machine recieves high frequency data that takes a about 6ms to process.

Thanks in Advance.

java -Xms4144m -Xmx4144m -XX:+UseParNewGC -XX:+CMSClassUnloadingEnabled -XX:CMSFullGCsBeforeCompaction=1 -XX:+PrintGCDetails -Xloggc:gc.log -verbose:gc -XX:SurvivorRatio=4 -XX:+UseCompressedOop

GC Logs

198.341: [GC 198.341: [ParNew: 1178752K->235712K(1178752K), 0.7930435 secs] 2653227K->1913561K(4007744K), 0.7931001 secs] [Times: user=1.36 sys=0.03, real=0.79 secs] 
219.946: [GC 219.946: [ParNew: 1178752K->235712K(1178752K), 0.6662757 secs] 2856601K->2095809K(4007744K), 0.6663335 secs] [Times: user=1.23 sys=0.03, real=0.67 secs] 
230.170: [GC 230.170: [ParNew: 1178752K->235712K(1178752K), 0.7158400 secs] 3038849K->2235472K(4007744K), 0.7158940 secs] [Times: user=1.39 sys=0.02, real=0.72 secs] 
242.243: [GC 242.243: [ParNew: 1178752K->235712K(1178752K), 0.8650113 secs] 3178512K->2538982K(4007744K), 0.8650603 secs] [Times: user=1.64 sys=0.06, real=0.87 secs] 
257.200: [GC 257.200: [ParNew: 1178752K->235712K(1178752K), 0.6999034 secs] 3482022K->2698292K(4007744K), 0.6999583 secs] [Times: user=1.30 sys=0.03, real=0.70 secs] 
271.794: [GC 271.794: [ParNew: 1178752K->235712K(1178752K), 0.8674328 secs] 3641332K->2929779K(4007744K), 0.8674890 secs] [Times: user=1.53 sys=0.08, real=0.87 secs] 
285.540: [GC 285.540: [ParNew: 1178752K->1178752K(1178752K), 0.0000200 secs]285.541: [Tenured: 2694067K->2687296K(2828992K), 8.3795756 secs] 3872819K->2687296K(4007744K), [Perm : 75186K->75186K(75328K)], 8.3796871 secs] [Times: user=8.36 sys=0.00, real=8.38 secs] 
307.287: [GC 307.287: [ParNew: 943040K->943040K(1178752K), 0.0000216 secs]307.287: [Tenured: 2687296K->2828991K(2828992K), 8.8158385 secs] 3630336K->2875360K(4007744K), [Perm : 75195K->75195K(75328K)], 8.8159306 secs] [Times: user=8.78 sys=0.03, real=8.82 secs] 
331.624: [Full GC 331.624: [Tenured: 2828991K->2828991K(2828992K), 9.6792290 secs] 4007743K->2956484K(4007744K), [Perm : 75197K->75193K(75328K)], 9.6792896 secs] [Times: user=9.64 sys=0.03, real=9.68 secs] 
355.683: [Full GC 355.683: [Tenured: 2828991K->2828991K(2828992K), 8.6649544 secs] 4007743K->3189624K(4007744K), [Perm : 75195K->75195K(75328K)], 8.6650138 secs] [Times: user=8.63 sys=0.00, real=8.66 secs] 
375.500: [Full GC 375.500: [Tenured: 2828991K->2828991K(2828992K), 9.0546364 secs] 4007743K->3369414K(4007744K), [Perm : 75195K->75195K(75328K)], 9.0546949 secs] [Times: user=9.03 sys=0.02, real=9.05 secs] 
394.217: [Full GC 394.217: [Tenured: 2828991K->2828991K(2828992K), 9.3253515 secs] 4007743K->3502795K(4007744K), [Perm : 75197K->75197K(75328K)], 9.3254103 secs] [Times: user=9.23 sys=0.05, real=9.32 secs] 
411.511: [Full GC 411.511: [Tenured: 2828991K->2828991K(2828992K), 11.2295533 secs] 4007743K->3544789K(4007744K), [Perm : 75199K->75199K(75328K)], 11.2296119 secs] [Times: user=11.24 sys=0.02, real=11.23 secs] 
429.802: [Full GC 429.802: [Tenured: 2828991K->2828991K(2828992K), 9.7181375 secs] 4007743K->3649219K(4007744K), [Perm : 75199K->75199K(75328K)], 9.7182127 secs] [Times: user=9.69 sys=0.02, real=9.72 secs] 
445.271: [Full GC 445.271: [Tenured: 2828991K->2828991K(2828992K), 9.8961275 secs] 4007743K->3725989K(4007744K), [Perm : 75200K->75200K(75328K)], 9.8961886 secs] [Times: user=9.86 sys=0.02, real=9.90 secs] 
459.824: [Full GC 459.824: [Tenured: 2828992K->2828992K(2828992K), 9.9093299 secs] 4007743K->3788320K(4007744K), [Perm : 75200K->75200K(75264K)], 9.9093896 secs] [Times: user=9.84 sys=0.03, real=9.91 secs] 
472.905: [Full GC 472.905: [Tenured: 2828992K->2828991K(2828992K), 11.9256624 secs] 4007743K->3820926K(4007744K), [Perm : 75200K->75125K(75264K)], 11.9257166 secs] [Times: user=11.91 sys=0.00, real=11.93 secs] 
488.573: [Full GC 488.573: [Tenured: 2828991K->2828991K(2828992K), 10.0481444 secs] 4007743K->3858495K(4007744K), [Perm : 75126K->75126K(75264K)], 10.0482011 secs] [Times: user=10.03 sys=0.02, real=10.05 secs] 
501.588: [Full GC 501.588: [Tenured: 2828991K->2828991K(2828992K), 10.0523092 secs] 4007743K->3894229K(4007744K), [Perm : 75126K->75126K(75264K)], 10.0523631 secs] [Times: user=10.02 sys=0.05, real=10.05 secs] 
513.358: [Full GC 513.358: [Tenured: 2828991K->2828991K(2828992K), 10.4441345 secs] 4007743K->3922499K(4007744K), [Perm : 75126K->75126K(75264K)], 10.4441888 secs] [Times: user=10.41 sys=0.05, real=10.44 secs] 
525.149: [Full GC 525.149: [Tenured: 2828991K->2828992K(2828992K), 12.3326697 secs] 4007743K->3933477K(4007744K), [Perm : 75127K->75123K(75264K)], 12.3327241 secs] [Times: user=12.30 sys=0.02, real=12.33 secs] 
538.518: [Full GC 538.518: [Tenured: 2828992K->2828992K(2828992K), 10.1793883 secs] 4007744K->3951837K(4007744K), [Perm : 75124K->75124K(75264K)], 10.1794431 secs] [Times: user=10.16 sys=0.00, real=10.18 secs] 
549.421: [Full GC 549.421: [Tenured: 2828992K->2828992K(2828992K), 10.2044623 secs] 4007743K->3966013K(4007744K), [Perm : 75124K->75124K(75264K)], 10.2045185 secs] [Times: user=10.16 sys=0.03, real=10.20 secs] 
560.138: [Full GC 560.138: [Tenured: 2828992K->2828992K(2828992K), 10.2487167 secs] 4007743K->3977058K(4007744K), [Perm : 75125K->75125K(75264K)], 10.2487719 secs] [Times: user=10.22 sys=0.03, real=10.25 secs] 
570.809: [Full GC 570.809: [Tenured: 2828992K->2828991K(2828992K), 12.3747337 secs] 4007743K->3982653K(4007744K), [Perm : 75125K->75125K(75264K)], 12.3747909 secs] [Times: user=12.34 sys=0.03, real=12.37 secs] 
583.616: [Full GC 583.616: [Tenured: 2828991K->2828991K(2828992K), 10.2968728 secs] 4007743K->3989103K(4007744K), [Perm : 75125K->75125K(75264K)], 10.2969323 secs] [Times: user=10.22 sys=0.05, real=10.30 secs] 
594.116: [Full GC 594.116: [Tenured: 2828991K->2828991K(2828992K), 10.2502126 secs] 4007743K->3994344K(4007744K), [Perm : 75126K->75126K(75264K)], 10.2502671 secs] [Times: user=10.24 sys=0.02, real=10.25 secs] 
604.508: [Full GC 604.508: [Tenured: 2828991K->2828991K(2828992K), 10.3733315 secs] 4007743K->3998499K(4007744K), [Perm : 75127K->75127K(75264K)], 10.3733868 secs] [Times: user=10.30 sys=0.06, real=10.37 secs] 
614.984: [Full GC 614.984: [Tenured: 2828991K->2828991K(2828992K), 12.4043694 secs] 4007743K->4000611K(4007744K), [Perm : 75127K->75118K(75264K)], 12.4044216 secs] [Times: user=12.36 sys=0.02, real=12.40 secs] 
627.474: [Full GC 627.474: [Tenured: 2828991K->2828991K(2828992K), 10.4267471 secs] 4007743K->4002564K(4007744K), [Perm : 75118K->75118K(75264K)], 10.4268039 secs] [Times: user=10.31 sys=0.05, real=10.43 secs] 
637.975: [Full GC 637.975: [Tenured: 2828991K->2828991K(2828992K), 10.2774899 secs] 4007743K->4004685K(4007744K), [Perm : 75118K->75118K(75264K)], 10.2775510 secs] [Times: user=10.19 sys=0.05, real=10.28 secs] 
648.284: [Full GC 648.284: [Tenured: 2828991K->2828991K(2828992K), 10.2766971 secs] 4007736K->4005877K(4007744K), [Perm : 75118K->75118K(75264K)], 10.2767509 secs] [Times: user=10.22 sys=0.03, real=10.28 secs] 
658.585: [Full GC 658.585: [Tenured: 2828991K->2828991K(2828992K), 12.4831705 secs] 4007743K->4005966K(4007744K), [Perm : 75118K->75118K(75264K)], 12.4832232 secs] [Times: user=12.42 sys=0.03, real=12.48 secs] 
671.090: [Full GC 671.090: [Tenured: 2828991K->2828991K(2828992K), 10.4432966 secs] 4007743K->4006356K(4007744K), [Perm : 75118K->75118K(75264K)], 10.4433494 secs] [Times: user=10.31 sys=0.03, real=10.44 secs] 
681.555: [Full GC 681.555: [Tenured: 2828991K->2828991K(2828992K), 10.7448251 secs] 4007743K->4006368K(4007744K), [Perm : 75119K->75119K(75264K)], 10.7448778 secs] [Times: user=10.72 sys=0.02, real=10.74 secs] 
692.316: [Full GC 692.316: [Tenured: 2828991K->2828991K(2828992K), 10.2663540 secs] 4007743K->4006774K(4007744K), [Perm : 75136K->75136K(75264K)], 10.2664250 secs] [Times: user=10.25 sys=0.00, real=10.27 secs] 
702.608: [Full GC 702.608: [Tenured: 2828991K->2828992K(2828992K), 12.4610859 secs] 4007743K->4006891K(4007744K), [Perm : 75140K->75140K(75264K)], 12.4611370 secs] [Times: user=12.42 sys=0.03, real=12.46 secs] 
715.087: [Full GC 715.087: [Tenured: 2828992K->2828992K(2828992K), 10.3067777 secs] 4007743K->4007227K(4007744K), [Perm : 75140K->75140K(75264K)], 10.3068309 secs] [Times: user=10.22 sys=0.03, real=10.31 secs] 
725.402: [Full GC 725.402: [Tenured: 2828992K->2828992K(2828992K), 10.2705306 secs] 4007743K->4007320K(4007744K), [Perm : 75152K->75152K(75264K)], 10.2706022 secs] [Times: user=10.20 sys=0.11, real=10.27 secs] 
735.678: [Full GC 735.678: [Tenured: 2828992K->2828992K(2828992K), 10.3012637 secs] 4007744K->4007310K(4007744K), [Perm : 75152K->75152K(75264K)], 10.3013231 secs] [Times: user=10.28 sys=0.00, real=10.30 secs] 
745.986: [Full GC 745.986: [Tenured: 2828992K->2828991K(2828992K), 12.5238366 secs] 4007744K->4007281K(4007744K), [Perm : 75152K->75152K(75264K)], 12.5238903 secs] [Times: user=12.45 sys=0.01, real=12.52 secs] 
758.516: [Full GC 758.516: [Tenured: 2828991K->2828991K(2828992K), 10.2712146 secs] 4007743K->4007484K(4007744K), [Perm : 75152K->75152K(75264K)], 10.2712660 secs] [Times: user=10.27 sys=0.02, real=10.27 secs] 
768.792: [Full GC 768.792: [Tenured: 2828991K->2828991K(2828992K), 10.2586840 secs] 4007743K->4007470K(4007744K), [Perm : 75152K->75152K(75264K)], 10.2587353 secs] [Times: user=10.19 sys=0.03, real=10.26 secs] 
779.064: [Full GC 779.064: [Tenured: 2828991K->2828991K(2828992K), 10.4511437 secs] 4007743K->4007399K(4007744K), [Perm : 75152K->75152K(75264K)], 10.4511969 secs] [Times: user=10.34 sys=0.02, real=10.45 secs] 
789.525: [Full GC 789.525: [Tenured: 2828991K->2828991K(2828992K), 12.4538596 secs] 4007743K->4007551K(4007744K), [Perm : 75152K->75152K(75264K)], 12.4539062 secs] [Times: user=12.41 sys=0.03, real=12.45 secs] 
801.997: [Full GC 801.997: [Tenured: 2828991K->2828991K(2828992K), 10.3025233 secs] 4007743K->4007417K(4007744K), [Perm : 75152K->75152K(75264K)], 10.3025765 secs] [Times: user=10.27 sys=0.00, real=10.30 secs]
jmj
  • 237,923
  • 42
  • 401
  • 438
Krazibit312
  • 380
  • 2
  • 12
  • most of those data lives for short period of time or they stays for longer time ? – jmj Mar 28 '14 at 18:34
  • Try to generate less garbage? – assylias Mar 28 '14 at 18:46
  • The data live for considerable amount of time, they are stored in an concurrent linked queue for later processing, processing of each data takes appprox 6ms, but new data is received at a much higher frequency. – Krazibit312 Mar 28 '14 at 22:37

1 Answers1

2

Your application leaks memory (amount of free space after collection decreases monotonously). If it is to a leak, when you should increase memory, try 8GiB to begin with.

In addition -XX:+CMSClassUnloadingEnabled -XX:CMSFullGCsBeforeCompaction=1 are applicable to CMS collector, but you are using ParNew + Single threaded MSC collector.

If your want to use CMS (Concurrent Mark Sweep) add -XX:+UseConcMarkSweepGC.

Take a look at JVM GC options cheatsheet to see more details about available tuning options.

Alexey Ragozin
  • 8,081
  • 1
  • 23
  • 23