Memory allocation problem

[tomasz.strzebak]

In our jira instance memory usage is increasing very fast 1 GB in 5 seconds. Temporarily we increased jvm memory. Can someone help us resolve the problem?

Logs from gc: 

2019-02-06T08:11:53.191+0000: 22.098: [GC (Allocation Failure) [PSYoungGen: 1048576K->48303K(1223168K)] 1048576K->48463K(4019712K), 0.1062319 secs] [Times: user=0.16 sys=0.01, real=0.10 secs]

2019-02-06T08:11:53.883+0000: 22.790: [GC (Metadata GC Threshold) [PSYoungGen: 151092K->19045K(1223168K)] 151252K->19213K(4019712K), 0.0409424 secs] [Times: user=0.09 sys=0.01, real=0.04 secs]

2019-02-06T08:11:53.924+0000: 22.832: [Full GC (Metadata GC Threshold) [PSYoungGen: 19045K->0K(1223168K)] [ParOldGen: 168K->18964K(2796544K)] 19213K->18964K(4019712K), [Metaspace: 20755K->20755K(1069056K)], 0.1025681 secs] [Times: user=0.27 sys=0.01, real=0.11 secs]

2019-02-06T08:12:27.539+0000: 56.446: [GC (System.gc()) [PSYoungGen: 544463K->17369K(1223168K)] 563428K->36341K(4019712K), 0.0281722 secs] [Times: user=0.07 sys=0.01, real=0.03 secs]

2019-02-06T08:12:27.567+0000: 56.474: [Full GC (System.gc()) [PSYoungGen: 17369K->0K(1223168K)] [ParOldGen: 18972K->34370K(2796544K)] 36341K->34370K(4019712K), [Metaspace: 33858K->33858K(1079296K)], 0.2436337 secs] [Times: user=0.69 sys=0.01, real=0.24 secs]

2019-02-06T08:12:33.794+0000: 62.701: [GC (Metadata GC Threshold) [PSYoungGen: 529672K->20898K(2066944K)] 564042K->55276K(4863488K), 0.0402550 secs] [Times: user=0.10 sys=0.00, real=0.04 secs]

2019-02-06T08:12:33.834+0000: 62.741: [Full GC (Metadata GC Threshold) [PSYoungGen: 20898K->0K(2066944K)] [ParOldGen: 34378K->46219K(2796544K)] 55276K->46219K(4863488K), [Metaspace: 56524K->56524K(1099776K)], 0.2845084 secs] [Times: user=0.82 sys=0.02, real=0.29 secs]

2019-02-06T08:12:50.491+0000: 79.398: [GC (Allocation Failure) [PSYoungGen: 1931264K->86504K(2105856K)] 1977483K->132751K(4902400K), 0.1968324 secs] [Times: user=0.37 sys=0.06, real=0.20 secs]

2019-02-06T08:13:02.048+0000: 90.955: [GC (Metadata GC Threshold) [PSYoungGen: 1666918K->124574K(2571776K)] 1713164K->170836K(5368320K), 0.3145733 secs] [Times: user=0.87 sys=0.11, real=0.31 secs]

2019-02-06T08:13:02.363+0000: 91.270: [Full GC (Metadata GC Threshold) [PSYoungGen: 124574K->0K(2571776K)] [ParOldGen: 46262K->159013K(2796544K)] 170836K->159013K(5368320K), [Metaspace: 90303K->90296K(1132544K)], 0.6588274 secs] [Times: user=1.84 sys=0.09, real=0.66 secs]

2019-02-06T08:13:14.449+0000: 103.356: [GC (Allocation Failure) [PSYoungGen: 2446848K->111889K(2619392K)] 2605861K->270902K(5415936K), 0.2390343 secs] [Times: user=0.62 sys=0.09, real=0.24 secs]

2019-02-06T08:13:22.126+0000: 111.033: [GC (Metadata GC Threshold) [PSYoungGen: 1381876K->122679K(2615808K)] 1540889K->281701K(5412352K), 0.2010211 secs] [Times: user=0.61 sys=0.02, real=0.20 secs]

2019-02-06T08:13:22.327+0000: 111.234: [Full GC (Metadata GC Threshold) [PSYoungGen: 122679K->0K(2615808K)] [ParOldGen: 159021K->224931K(3352576K)] 281701K->224931K(5968384K), [Metaspace: 145785K->145785K(1185792K)], 0.9573944 secs] [Times: user=2.76 sys=0.03, real=0.95 secs]

2019-02-06T08:13:40.768+0000: 129.675: [GC (Allocation Failure) [PSYoungGen: 2469376K->120638K(2590208K)] 2694307K->345578K(5942784K), 0.2356236 secs] [Times: user=0.64 sys=0.01, real=0.23 secs]

2019-02-06T08:14:26.130+0000: 175.037: [GC (Allocation Failure) [PSYoungGen: 2590014K->158678K(2578944K)] 2814954K->383626K(5931520K), 0.2753684 secs] [Times: user=0.80 sys=0.01, real=0.28 secs]

2019-02-06T08:14:32.894+0000: 181.801: [GC (Allocation Failure) [PSYoungGen: 2563542K->195563K(2600448K)] 2788490K->424478K(5953024K), 0.3282689 secs] [Times: user=1.13 sys=0.00, real=0.33 secs]

2019-02-06T08:14:45.938+0000: 194.845: [GC (Allocation Failure) [PSYoungGen: 2600427K->195582K(2403840K)] 2829342K->538351K(5756416K), 0.5935708 secs] [Times: user=1.70 sys=0.15, real=0.59 secs]

2019-02-06T08:14:54.994+0000: 203.901: [GC (System.gc()) [PSYoungGen: 1024990K->250553K(2459136K)] 1367760K->593330K(5811712K), 0.4629201 secs] [Times: user=1.36 sys=0.00, real=0.46 secs]

2019-02-06T08:14:55.457+0000: 204.364: [Full GC (System.gc()) [PSYoungGen: 250553K->0K(2459136K)] [ParOldGen: 342777K->500701K(3352576K)] 593330K->500701K(5811712K), [Metaspace: 220303K->220274K(1253376K)], 3.1708318 secs] [Times: user=9.13 sys=0.11, real=3.18 secs]

2019-02-06T08:15:51.074+0000: 259.981: [GC (Allocation Failure) [PSYoungGen: 2208256K->64658K(2478592K)] 2708957K->565368K(5831168K), 0.1806413 secs] [Times: user=0.36 sys=0.00, real=0.18 secs]

2019-02-06T08:16:25.903+0000: 294.810: [GC (Allocation Failure) [PSYoungGen: 2217106K->70774K(2223616K)] 2717816K->571491K(5576192K), 0.1739789 secs] [Times: user=0.38 sys=0.01, real=0.17 secs]

2019-02-06T08:16:56.670+0000: 325.577: [GC (Allocation Failure) [PSYoungGen: 2223102K->53106K(2466816K)] 2723820K->553839K(5819392K), 0.1392145 secs] [Times: user=0.32 sys=0.00, real=0.14 secs]

2019-02-06T08:17:36.926+0000: 365.833: [GC (Allocation Failure) [PSYoungGen: 2213234K->51674K(2459136K)] 2713967K->552416K(5811712K), 0.1367638 secs] [Times: user=0.32 sys=0.00, real=0.13 secs]

2019-02-06T08:23:12.183+0000: 701.090: [GC (Allocation Failure) [PSYoungGen: 2211463K->57084K(2486272K)] 2712205K->557833K(5838848K), 0.1456409 secs] [Times: user=0.34 sys=0.00, real=0.15 secs]

770.569: Setting _needs_gc. Thread "VM Thread" 1 locked.

770.569: Thread "http-nio-8080-exec-2" is performing GC after exiting critical section, 0 locked

2019-02-06T08:24:21.663+0000: 770.570: [GC (GCLocker Initiated GC) [PSYoungGen: 2258172K->65894K(2480640K)] 2758922K->566652K(5833216K), 0.1767320 secs] [Times: user=0.47 sys=0.00, real=0.18 secs]

Information about jira configuration:

[Andy Heinzer · Accepted solution]

Sorry, but we can't possible tell you why the memory allocation suddenly jumped 1GB with the information we have here.  I suspect you probably have a plugin in Jira that might be causing this, or you suddenly got a very large number of requests.  

I can see from your settings that your Jira is creating garbage collection logs.  Perhaps you can use those logs and follow the analysis steps in Using Garbage Collection Logs to Analyze JIRA Application Performance.   You could then see the time java does this Full GC event, and perhaps you could then look into the $JIRAHOME/log/atlassian-jira.log to see if there are any other events at or before that timestamp that might have occurred.  This is how I would try to investigate this information if I had all the data from your Jira site.