I just looked at my heap dump in YourKit profiler and saw the following reachable/unreachable statistics.
I'm not quite sure about this. Does it mean that almost all my heap consists of some garbage data and I need to strongly tune my G1. Or this is usual statistic?
Problem: GC time is about 10% of the application running time.
Is my understanding correct about that unreachable objects are ones which can be Garbage Collected or YourKit meant something different about it? Here is the piece of GC log (Using CMS):
2.823: [GC (Metadata GC Threshold) [PSYoungGen: 420257K->52400K(564736K)] 420257K->52488K(1854976K), 0.0607756 secs] [Times: user=0.18 sys=0.01, real=0.06 secs]
2.884: [Full GC (Metadata GC Threshold) [PSYoungGen: 52400K->0K(564736K)] [ParOldGen: 88K->51480K(903680K)] 52488K->51480K(1468416K), [Metaspace: 20809K->20809K(1067008K)], 0.1990115 secs] [Times: user=0.59 sys=0.01, real=0.20 secs]
5.760: [GC (Metadata GC Threshold) [PSYoungGen: 287353K->65545K(664576K)] 338833K->117033K(1568256K), 0.0571198 secs] [Times: user=0.13 sys=0.02, real=0.06 secs]
5.818: [Full GC (Metadata GC Threshold) [PSYoungGen: 65545K->0K(664576K)] [ParOldGen: 51488K->103745K(1605120K)] 117033K->103745K(2269696K), [Metaspace: 34820K->34772K(1079296K)], 0.1841317 secs] [Times: user=0.51 sys=0.02, real=0.18 secs]
9.099: [GC (Allocation Failure) [PSYoungGen: 598528K->61614K(796672K)] 702273K->165367K(2401792K), 0.0557993 secs] [Times: user=0.23 sys=0.03, real=0.06 secs]
9.965: [GC (Allocation Failure) [PSYoungGen: 796334K->33251K(969216K)] 900087K->173388K(2574336K), 0.0492724 secs] [Times: user=0.22 sys=0.04, real=0.05 secs]
11.085: [GC (Allocation Failure) [PSYoungGen: 969187K->49292K(1016320K)] 1109324K->189430K(2621440K), 0.0904503 secs] [Times: user=0.40 sys=0.00, real=0.09 secs]
11.855: [GC (Allocation Failure) [PSYoungGen: 985228K->64233K(1375232K)] 1125366K->204379K(2980352K), 0.1003579 secs] [Times: user=0.38 sys=0.06, real=0.10 secs]
12.625: [GC (Allocation Failure) [PSYoungGen: 1363689K->75774K(1375232K)] 1503835K->227247K(2980352K), 0.0790738 secs] [Times: user=0.37 sys=0.16, real=0.08 secs]
13.341: [GC (Allocation Failure) [PSYoungGen: 1375230K->87028K(2066944K)] 1526703K->249534K(3672064K), 0.1147762 secs] [Times: user=0.55 sys=0.09, real=0.12 secs]
14.375: [GC (Allocation Failure) [PSYoungGen: 2066932K->98795K(2078720K)] 2229438K->284557K(3683840K), 0.1174134 secs] [Times: user=0.57 sys=0.18, real=0.12 secs]
15.465: [GC (Allocation Failure) [PSYoungGen: 2078699K->117243K(2798080K)] 2264461K->317809K(4403200K), 0.1130871 secs] [Times: user=0.76 sys=0.19, real=0.11 secs]
16.769: [GC (Allocation Failure) [PSYoungGen: 2798075K->134647K(2815488K)] 2998641K->363601K(4420608K), 0.1855432 secs] [Times: user=1.05 sys=0.29, real=0.19 secs]
18.117: [GC (Allocation Failure) [PSYoungGen: 2815479K->133511K(3842560K)] 3044433K->411609K(5447680K), 0.2329040 secs] [Times: user=0.81 sys=0.13, real=0.23 secs]
19.965: [GC (Allocation Failure) [PSYoungGen: 3816327K->117907K(3852288K)] 4094425K->476525K(5457408K), 0.1902845 secs] [Times: user=1.06 sys=0.33, real=0.19 secs]
21.745: [GC (Allocation Failure) [PSYoungGen: 3800723K->70957K(4020224K)] 4159341K->541079K(5625344K), 0.1766376 secs] [Times: user=1.02 sys=0.33, real=0.17 secs]
23.425: [GC (Allocation Failure) [PSYoungGen: 3924781K->73249K(4021760K)] 4394903K->607715K(5626880K), 0.1285575 secs] [Times: user=0.70 sys=0.18, real=0.13 secs]
25.186: [GC (Allocation Failure) [PSYoungGen: 3927073K->73147K(4021248K)] 4461539K->674821K(5626368K), 0.1243413 secs] [Times: user=0.69 sys=0.21, real=0.12 secs]
26.906: [GC (Allocation Failure) [PSYoungGen: 3936187K->72831K(4022272K)] 4537861K->741865K(5627392K), 0.1476289 secs] [Times: user=0.85 sys=0.29, real=0.15 secs]
28.644: [GC (Allocation Failure) [PSYoungGen: 3935871K->74110K(4028928K)] 4604905K->811056K(5634048K), 0.1401820 secs] [Times: user=0.58 sys=0.38, real=0.14 secs]
30.420: [GC (Allocation Failure) [PSYoungGen: 3954046K->74890K(4030464K)] 4690992K->880140K(5635584K), 0.1217263 secs] [Times: user=1.02 sys=0.14, real=0.12 secs]
32.119: [GC (Allocation Failure) [PSYoungGen: 3954826K->74036K(4038656K)] 4760076K->947726K(5643776K), 0.1349601 secs] [Times: user=0.79 sys=0.17, real=0.14 secs]
33.844: [GC (Allocation Failure) [PSYoungGen: 3971892K->74611K(4039680K)] 4845582K->1016221K(5644800K), 0.1579372 secs] [Times: user=1.31 sys=0.18, real=0.16 secs]
35.604: [GC (Allocation Failure) [PSYoungGen: 3972467K->73896K(4047360K)] 4914077K->1084130K(5652480K), 0.1553432 secs] [Times: user=0.89 sys=0.09, real=0.16 secs]
37.416: [GC (GCLocker Initiated GC) [PSYoungGen: 3988648K->73759K(4048384K)] 4998892K->1152107K(5653504K), 0.1948397 secs] [Times: user=0.94 sys=0.18, real=0.19 secs]
39.315: [GC (Allocation Failure) [PSYoungGen: 3988511K->74582K(4056064K)] 5066932K->1221883K(5661184K), 0.1410819 secs] [Times: user=0.83 sys=0.34, real=0.14 secs]
41.105: [GC (Allocation Failure) [PSYoungGen: 4005206K->76174K(4057088K)] 5152507K->1292051K(5662208K), 0.1966487 secs] [Times: user=0.96 sys=0.23, real=0.19 secs]
42.866: [GC (Allocation Failure) [PSYoungGen: 4006798K->75063K(4064768K)] 5222675K->1361707K(5669888K), 0.1755286 secs] [Times: user=0.77 sys=0.13, real=0.17 secs]
44.841: [GC (Allocation Failure) [PSYoungGen: 4020535K->76560K(4064768K)] 5307179K->1432324K(5669888K), 0.1492622 secs] [Times: user=0.93 sys=0.23, real=0.15 secs]
46.652: [GC (Allocation Failure) [PSYoungGen: 4022032K->76593K(4071936K)] 5377796K->1503428K(5677056K), 0.1457041 secs] [Times: user=0.92 sys=0.07, real=0.15 secs]
48.803: [GC (Allocation Failure) [PSYoungGen: 4035377K->72513K(4071424K)] 5462212K->1570356K(5676544K), 0.1883641 secs] [Times: user=1.09 sys=0.18, real=0.19 secs]
48.992: [Full GC (Ergonomics) [PSYoungGen: 72513K->0K(4071424K)] [ParOldGen: 1497843K->1521336K(3507200K)] 1570356K->1521336K(7578624K), [Metaspace: 41385K->41378K(1085440K)], 2.5937473 secs] [Times: user=23.36 sys=0.04, real=2.60 secs]
A heap dump can contain unreachable objects, e.g. objects which should be garbage collected but stay around for various reasons. Usually this is due to optimizations in the garbage collection algorithm. The Memory Analyzer removes these objects by default from the object graph.
Heap space is used for the dynamic memory allocation of Java objects and JRE classes at runtime. New objects are always created in heap space, and the references to these objects are stored in stack memory. These objects have global access and we can access them from anywhere in the application.
First and foremost, having unreachable objects inside heap at any given time is perfectly normal. Garbage Collection will clean the unreachable objects during the next run and will clean the heap from them. So, seeing unreachable data structures in heap dump is not evil nor abnormal.
Eclipse Memory Analyzer Tool ( MAT ) is used for analyzing heap dump files which contain objects in memory. Each heap dump file can be thought of as a snapshot in time and details the memory occupied by specific JVM threads.
Your application creates a lot of temporary objects. That is why GC takes so much time. Please take a look at article "Excessive garbage allocation" https://www.yourkit.com/docs/java/help/excessive_gc.jsp You will be able to find places that create temporary objects.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With