Analyzing verbose output | Garbage collection analysis tools

Reading verbosegc output

The verbosegc output from WAS V6.1 is stored in the native_stderr.log file. This file is found in the server directory. Verbosegc content has changed formats from Java 1.4.2 to Java 5.

Verbosegc in Java 5 is outputted as xml. The xml format is more difficult for a person to read, but it provides a better format for monitoring and analysis tools to read.

<af type="tenured" 
          id="7" 
          timestamp="Fri Sep 29 12:27:16 2006" 
          intervalms="6384.924">

  <minimum requested_bytes="4194328" />

  <time exclusiveaccessms="0.823" />

  <tenured freebytes="20754960" 
           totalbytes="104857600" 
           percent="19" >

    <soa freebytes="17609232" 
         totalbytes="101711872" 
         percent="17" />

    <loa freebytes="3145728" 
         totalbytes="3145728" 
         percent="100" />

  </tenured>

  <gc type="global" 
      id="7" 
      totalid="7" 
      intervalms="6385.221">

    <compaction movecount="454417" 
                movebytes="36596648" 
                reason="compact to meet allocation" />

    <classloadersunloaded count="0" 
                          timetakenms="3.112" />

    <refs_cleared soft="133" 
                  weak="77" 
                  phantom="1" />

    <finalization objectsqueued="192" />

    <timesms mark="169.897" 
             sweep="4.660" 
             compact="335.373" 
             total="513.365" />

    <tenured freebytes="68253888" 
             totalbytes="104857600" 
             percent="65" >

      <soa freebytes="64059584" 
           totalbytes="100663296" 
           percent="63" />

      <loa freebytes="4194304" 
           totalbytes="4194304" 
           percent="100" />

    </tenured>

  </gc>

  <tenured freebytes="64059560" totalbytes="104857600" percent="61" >

    <soa freebytes="59865256" totalbytes="100663296" percent="59" />
    <loa freebytes="4194304" totalbytes="4194304" percent="100" />
  </tenured>

  <time totalms="514.485" />

</af>

Common tags found in verbosegc output

The cause of each GC event can be discerned by the first tag; in this case, the tag for an allocation failure is <af>. Other causes of GC events are from either a concurrent collection or from a call to System.gc(). Concurrent GC events begin with <con>, while system GC events begin with the <sys> tag.

Tag	Description
<af>	An allocation failure has occurred
<sys>	A call to System.gc() has occurred
<con>	A concurrent event has taken place; can be contained within an <af>
<time>	Total amount of processor time for a particular event
<minimum>	Number of bytes requested that triggered the allocation failure
<nursery>	Status of the nursery area
<tenured>	Status of the tenured area
<gc>	A garbage collection occurred; can be either global or scavenger
<compaction>	A compaction occurred
<expansion>	Heap expansion occurred

This list of tags is only an overview of the most important ones. For a more detailed description of how to read xml verbosegc, see the Garbage Collector diagnostics in IBM Java 5 Diagnostics Guide.