I am seeing some abnormal behavior in our prod environment that is causing us high thread count on server that is running Tomcat. The heap size of 10,092,544K is divided between new generation and tenure generation as 2,752,512K + 7,340,032K = 10,092,544K.
I am confused as to why GC is running itself multiple times when there is enough memory available on heap (new and old gen both) (Full GC [PSYoungGen: 0K->0K(2752512K)] [ParOldGen: 2748534K->2748529K(7340032K)] )
As you can see 0K->0K for young gen and .27G -> .27G for old gen means hardly any objects are getting gc'd and there is so much of memory available. (heap size is 10G).
Since Full GC is running multiple times during short interval, it is causing slow performance and hence application can't handle the incoming user requests and hence high threads on server and eventually we have to restart server to come out of this situation.
Can you please explain what is happening here.
Here is output on gc.log.
. .
more...... . .
Jul 18 14:52:38 fwprodcontent03 gc.log: 3172.122: [GC [PSYoungGen: 0K->0K(2752512K)] 2750855K->2750855K(10092544K), 0.0515920 secs] [Times: user=0.32 sys=0.01, real=0.06 secs]
Jul 18 14:52:42 fwprodcontent03 gc.log: 3172.174: [Full GC [PSYoungGen: 0K->0K(2752512K)] [ParOldGen: 2750855K->2749937K(7340032K)] 2750855K->2749937K(10092544K) [PSPermGen: 262143K->262115K(262144K)], 4.1571260 secs] [Times: user=44.29 sys=0.06, real=4.15 secs]
Jul 18 14:52:42 fwprodcontent03 gc.log: 3176.361: [GC [PSYoungGen: 9071K->1280K(2752512K)] 2759008K->2751217K(10092544K), 0.0989600 secs] [Times: user=0.64 sys=0.01, real=0.10 secs]
Jul 18 14:52:46 fwprodcontent03 gc.log: 3176.461: [Full GC [PSYoungGen: 1280K->0K(2752512K)] [ParOldGen: 2749937K->2748847K(7340032K)] 2751217K->2748847K(10092544K) [PSPermGen: 262143K->262121K(262144K)], 3.1331910 secs] [Tim es: user=31.25 sys=0.01, real=3.14 secs]
Jul 18 14:52:46 fwprodcontent03 gc.log: 3179.616: [GC [PSYoungGen: 2161K->288K(2752512K)] 2751008K->2749135K(10092544K), 0.0688890 secs] [Times: user=0.42 sys=0.02, real=0.07 secs]
Jul 18 14:52:49 fwprodcontent03 gc.log: 3179.686: [Full GC [PSYoungGen: 288K->0K(2752512K)] [ParOldGen: 2748847K->2748930K(7340032K)] 2749135K->2748930K(10092544K) [PSPermGen: 262143K->262143K(262144K)], 3.2369940 secs] [Time s: user=32.23 sys=0.02, real=3.23 secs]
Jul 18 14:52:49 fwprodcontent03 gc.log: 3182.923: [GC [PSYoungGen: 0K->0K(2752512K)] 2748930K->2748930K(10092544K), 0.0607190 secs] [Times: user=0.39 sys=0.01, real=0.06 secs]
Jul 18 14:52:57 fwprodcontent03 gc.log: 3182.984: [Full GC [PSYoungGen: 0K->0K(2752512K)] [ParOldGen: 2748930K->2748528K(7340032K)] 2748930K->2748528K(10092544K) [PSPermGen: 262143K->262141K(262144K)], 8.5377730 secs] [Times: user=98.30 sys=0.57, real=8.54 secs]
Jul 18 14:52:58 fwprodcontent03 gc.log: 3191.533: [GC [PSYoungGen: 202K->128K(2752512K)] 2748731K->2748656K(10092544K), 0.1088430 secs] [Times: user=0.67 sys=0.00, real=0.11 secs]
Jul 18 14:53:02 fwprodcontent03 gc.log: 3191.642: [Full GC [PSYoungGen: 128K->0K(2752512K)] [ParOldGen: 2748528K->2748534K(7340032K)] 2748656K->2748534K(10092544K) [PSPermGen: 262143K->262143K(262144K)], 3.1761780 secs] [Time s: user=31.11 sys=0.02, real=3.18 secs]
Jul 18 14:53:02 fwprodcontent03 gc.log: 3194.820: [GC [PSYoungGen: 0K->0K(2752512K)] 2748534K->2748534K(10092544K), 0.0589010 secs] [Times: user=0.38 sys=0.01, real=0.06 secs]
Jul 18 14:53:05 fwprodcontent03 gc.log: 3194.879: [Full GC [PSYoungGen: 0K->0K(2752512K)] [ParOldGen: 2748534K->2748529K(7340032K)] 2748534K->2748529K(10092544K) [PSPermGen: 262143K->262143K(262144K)], 3.0554520 secs] [Times: user=30.72 sys=0.03, real=3.05 secs] . . .more.....
Thanks in advance.
