WebSphere troubshooting-Analysis of GC logs using tools

To perform GC performance tuning, You have to analyze the GC log. When talking about the "human flesh" method, I always feel that the image is not good enough, so that developers or technical directors who do not know about it cannot have an intuitive understanding, this article describes several GC log analysis tools.

First {
Pagetracker. _ trackpageview ('/outbound/article/www-01.ibm.com ');
} "Href =" http://www-01.ibm.com/software/support/isa/download.html "target =" _ blank "> download IBM Support Assistant. After downloading it, you can download the required tools from Update-tools add on ,{
Pagetracker. _ trackpageview ('/outbound/article/www.ibm.com ');
} "Href =" http://www.ibm.com/developerworks/cn/websphere/library/techarticles/0710_pengfei/index.html "target =" _ blank "> ISA usage method. ISA integrates all the tools in one interface, saving the trouble of setting startup parameters and keeping updates in the most timely manner. Analyze garbage collection logs. I mainly use "the IBM monitoring and diagnostic tools for Java-garbage collection and memory visualizer" and "IBM pattern modeling and analysis tool for Java garbage collector (Pmat. I will use actual examples to illustrate how to use this tool.

Use garbage collection and memory visualizer to load native_stderr.log. First, you will see

Click to expand the chart

This is a 500-minute garbage collection curve. You can see the general situation within one day. In general, the blue used heap (after collection) runs in the "parallel channel" and does not go through the "Rising Channel" (Friends of stocks should know what the figure of the Rising Channel is like ). So in the report label, you can see "the memory usage of the application does not indicate any obvious leaks .".

The summary in the report is worth attention. It shows us the number of GC occurrences, the policy used (optthruput), the average pause time is 248 ms, and the average interval is 3.37 minutes, there is also the garbage collection rate (the garbage collection rate is not bad, but a high throughput rate ).

Let's switch back to the line plot view. Now we can select a period to zoom in and select the X axis Coordinate System in the axes on the right. The default value is relative time, in minutes, it applies to problems that occur after your application is started for N hours. If a performance problem occurs at a fixed time every day, use absolute time.

The heap size and used heap (after collection) are enabled for the default curve. You can select the desired curve in VGC pause date, VGC date, and VGC heap data as needed. For example, if you think the program has a long response time, you can check intervals between garbage collection triggers and pause time to see if the previous curve is "too close" to the next one ".

 

 

You can view the recycling information of table mode in tabbed data (you can also select the content mentioned in the previous section to add columns). We can see that GC reason is Af. By viewing the free heap before collection, we found that when some af occurs, there is still a lot of space in the heap.

I covered the Compact times curve and found that it was very consistent. At this time, there were too many fragments in the heap, so even if the remaining space was large, there was no continuous space allocated to new requests, compact occurs ). The second figure with unuseable heap due to fragmentatiion is more obvious. Further, you can view the size of the compressed requested_bytes according to the Collection ID of the first column, and check whether a large space is required (for example, larger than 64 K). Then, combine the number of large objects in all requested_bytes, determine whether to adjust the loa size.

You will find that some curves are gray and cannot be selected, because according to my current GC policy, there is no such curve in GENCON mode.

In general, different combination of curves, appropriate scaling ratio, and different log display methods are used for comparison, we can verify that GC meets some of the "best principles" I have mentioned before-whether the interval between collection is much greater than the duration, and whether the entire collection time is less than 5% of the overall running time, whether the number of compression times accounts for only a small portion (if there are too many compression times, consider setting-XK-XP and adjusting LOA )...... The tuning recommendation in the report label is the content you need to refer to, but do not optimize it as soon as it comes up.

The next example is a problematic garbage collection log.

The whole garbage collection curve contains an outofmemory caused by excessive GC.

The concurrent collector will throw an outofmemoryerror if too much time is being spent in garbage collection: if more than 98% of the total time is spent in garbage collection and less than 2% of the heap is recovered, an outofmemoryerror will be thrown. this feature is designed to prevent applications from running for an extended period of time while making little or no progress because the heap is too small.

Enlarge the curve of the problem

View the original file by ID

<AF Type = "tenured" id = "1030" timestamp = "Tue Nov 04 14:57:26 2008" intervalms = "11.440">
<Minimum requested_bytes = "216"/>
<Time exclusiveaccessms = "0.322"/>
<Tenured freebytes = "0" totalbytes = "1342177280" percent = "0">
<SOA freebytes = "0" totalbytes = "1342177280" percent = "0"/>
<Loa freebytes = "0" totalbytes = "0" percent = "0"/>
</Tenured>
<GC type = "Global" id = "1031" totalid = "1031" intervalms = "11.837">
<Compaction movecount = "3301258" movebytes = "196674784" Reason= "Low free space (less than 4% )"/>
<Refs_cleared soft = "0" weak = "15" Phantom = "7"/>
<Finalization objectsqueued = "40"/>
<Timesms mark = "1753.108" sweep = "10.302" Compact = "1858.390" Total = "3622.032"/>
<Tenured freebytes = "519040" totalbytes = "1342177280" percent = "0">
<SOA freebytes = "519040" totalbytes = "1342177280" percent = "0"/>
<Loa freebytes = "0" totalbytes = "0" percent = "0"/>
</Tenured>
</GC>
<Warning details = "excessive GC Activity Detected"/>
<Tenured freebytes = "518352" totalbytes = "1342177280" percent = "0">
<SOA freebytes = "518352" totalbytes = "1342177280" percent = "0"/>
<Loa freebytes = "0" totalbytes = "0" percent = "0"/>
</Tenured>
<Time totalms = "3623.033"/>
</AF>

<AF Type = "tenured" id = "1031" timestamp = "Tue Nov 04 14:57:30 2008" intervalms = "3.715">
<Minimum requested_bytes = "120"/>
<Time exclusiveaccessms = "0.232"/>
<Tenured freebytes = "0" totalbytes = "1342177280" percent = "0">
<SOA freebytes = "0" totalbytes = "1342177280" percent = "0"/>
<Loa freebytes = "0" totalbytes = "0" percent = "0"/>
</Tenured>
<GC type = "Global" id = "1032" totalid = "1032" intervalms = "4.385">
<Compaction movecount = "3170275" movebytes = "192337800" reason ="Compact to aid heap contraction"/>
<Contraction Type = "tenured" amount = "67108352" newsize = "1275068928" timetaken = "0.001" reason ="Excess free space following GC"/>
<Refs_cleared soft = "0" weak = "0" Phantom = "0"/>
<Finalization objectsqueued = "9"/>
<Timesms mark = "245.373" sweep = "12.272" Compact = "482.748" Total = "745.486"/>
<Tenured freebytes = "1022923992" totalbytes = "1275068928" percent = "80">
<SOA freebytes = "1022923992" totalbytes = "1275068928" percent = "80"/>
<Loa freebytes = "0" totalbytes = "0" percent = "0"/>
</Tenured>
</GC>

Considering that the garbage collection frequency is also high and the space for each request is not large, I will change the garbage collection mode to GENCON, and then there will be no outofmemory. However, my recycle logs are not left behind. Otherwise, you should import the modified logs in the Compare file to compare them and determine the Modification result.

Note:For ibm jdk, simply select "Detailed garbage collection", but for HP or Sun JDK, it is best to use-xverbosegclog: file_name (generate an XML format that can be parsed) to specify, otherwise, the default file contains other information. The tool cannot display the file as an image, and you need to modify the file yourself, which is troublesome.

IBM pattern modeling and analysis tool for Java garbage collector (Pmat) This tool is similar. I personally think that the optimization suggestions provided can be complementary to the above tools. For example, it will calculate a suitable-XK-XP value.

For garbage collection logs generated on the HP-UX, we can also use hpjtune under hpjmeter for analysis.

 

 

Note:

This article Reprinted from: http://www.hashei.me/2009/06/gc-performance-tuning-with-isa.html