APAR status
Closed as program error.
Error description
Error Message: The application appears to hang when using the gencon GC policy and the verbose gc logs indicate endless GC cycles are occurring. The verbose gc logs report the following repeating events: 1. A scavenger gc occurs. The scavenge fails and failure of type "flipped" and warning with detail "aborted collection" is reported. 2. This is followed by a global gc with percolating_collect reason="failed tenure threshold reached". 3. Another scavenger gc occurs, there are failures to flip and the scavenger collection is aborted . Stack Trace: Sample verbose gc logs when the problem occurs: <af type="nursery" id="14851" timestamp="Thu May 08 13:36:53 2008" intervalms="0.344"> <minimum requested_bytes="9330216" /> <time exclusiveaccessms="0.086" /> <nursery freebytes="8357888" totalbytes="8884224" percent="94" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <gc type="scavenger" id="14849" totalid="14888" intervalms="0.566"> <flipped objectcount="83" bytes="70012" /> <tenured objectcount="0" bytes="0" /> <refs_cleared soft="0" weak="0" phantom="0" /> <finalization objectsqueued="0" /> <scavenger tiltratio="72" /> <nursery freebytes="9416704" totalbytes="9809920" percent="95" tenureage="7" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="3.365" /> </gc> <nursery freebytes="86488" totalbytes="9809920" percent="0" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="3.668" /> </af> <af type="nursery" id="14852" timestamp="Thu May 08 13:36:53 2008" intervalms="5.525"> <minimum requested_bytes="24" /> <time exclusiveaccessms="0.110" /> <nursery freebytes="0" totalbytes="9809920" percent="0" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <gc type="scavenger" id="14850" totalid="14889" intervalms="5.763"> <failed type="flipped" objectcount="1" bytes="9330216" /> <warning details="aborted collection" /> <flipped objectcount="102" bytes="71524" /> <tenured objectcount="0" bytes="0" /> <refs_cleared soft="0" weak="0" phantom="0" /> <finalization objectsqueued="0" /> <scavenger tiltratio="72" /> <nursery freebytes="0" totalbytes="9809920" percent="0" tenureage="8" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="9.774" /> </gc> <nursery freebytes="0" totalbytes="9809920" percent="0" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="10.131" /> </af> <af type="nursery" id="14853" timestamp="Thu May 08 13:36:53 2008" intervalms="0.159"> <minimum requested_bytes="24" /> <time exclusiveaccessms="0.110" /> <nursery freebytes="0" totalbytes="9809920" percent="0" /> <tenured freebytes="146979912" totalbytes="254843904" percent="57" > <soa freebytes="146979912" totalbytes="254843904" percent="57" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <percolating_collect reason="failed tenure threshold reached" /> <gc type="global" id="40" totalid="14890" intervalms="597.834"> <refs_cleared soft="6" threshold="32" weak="0" phantom="0" /> <finalization objectsqueued="4" /> <timesms mark="117.336" sweep="2.326" compact="0.000" total="119.931" /> <nursery freebytes="406544" totalbytes="9809920" percent="4" /> <tenured freebytes="151696888" totalbytes="254843904" percent="59" > <soa freebytes="151696888" totalbytes="254843904" percent="59" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> </gc> <nursery freebytes="406520" totalbytes="9809920" percent="4" /> <tenured freebytes="151696888" totalbytes="254843904" percent="59" > <soa freebytes="151696888" totalbytes="254843904" percent="59" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="120.275" /> </af> <af type="nursery" id="14854" timestamp="Thu May 08 13:36:53 2008" intervalms="12.284"> <minimum requested_bytes="24" /> <time exclusiveaccessms="0.155" /> <nursery freebytes="0" totalbytes="9809920" percent="0" /> <tenured freebytes="151696888" totalbytes="254843904" percent="59" > <soa freebytes="151696888" totalbytes="254843904" percent="59" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <gc type="scavenger" id="14851" totalid="14891" intervalms="132.965"> <failed type="flipped" objectcount="1" bytes="9330216" /> <warning details="aborted collection" /> <flipped objectcount="99" bytes="71444" /> <tenured objectcount="0" bytes="0" /> <refs_cleared soft="0" weak="0" phantom="0" /> <finalization objectsqueued="0" /> <scavenger tiltratio="72" /> <nursery freebytes="0" totalbytes="9809920" percent="0" tenureage="8" /> <tenured freebytes="151696888" totalbytes="254843904" percent="59" > <soa freebytes="151696888" totalbytes="254843904" percent="59" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="5.025" /> </gc> <nursery freebytes="0" totalbytes="9809920" percent="0" /> <tenured freebytes="151696888" totalbytes="254843904" percent="59" > <soa freebytes="151696888" totalbytes="254843904" percent="59" /> <loa freebytes="0" totalbytes="0" percent="0" /> </tenured> <time totalms="5.613" /> </af> .
Local fix
This issue can be worked around by adding the command line option "-Xcompactgc". This will cause a compaction of the heap to occur at the end of every GC cycle.
Problem summary
This issue is caused by a problem in the percolate_collect. The GC logs reveal that there is an object which is too large to be flipped, but the object is not being tenured either. This implies that the tenure space is too fragmented to fit the object. The root cause of the problem is that the percolate_collect is not detecting that a compaction is necessary.
Problem conclusion
This defect will be fixed in: 6.0.0 SR2 5.0.0 SR8 . There were two logic errors which were preventing the percolate_collect from forcing a compaction of the heap. These errors have been fixed. . To obtain the fix: Install build 20080522 or later
Temporary fix
Comments
APAR Information
APAR number
IZ22987
Reported component name
J9 COMMON CODE
Reported component ID
620700127
Reported release
600
Status
CLOSED PER
PE
NoPE
HIPER
NoHIPER
Special Attention
NoSpecatt
Submitted date
2008-05-28
Closed date
2008-06-11
Last modified date
2008-06-11
APAR is sysrouted FROM one or more of the following:
APAR is sysrouted TO one or more of the following:
Fix information
Fixed component name
J9 COMMON CODE
Fixed component ID
620700127
Applicable component levels
R600 PSN
UP
[{"Business Unit":{"code":"BU048","label":"IBM Software"},"Product":{"code":"SSCVQ3W","label":"Virtual Machine"},"Component":"","ARM Category":[],"Platform":[{"code":"PF025","label":"Platform Independent"}],"Version":"6.0","Edition":"","Line of Business":{"code":"","label":""}}]
Document Information
Modified date:
11 June 2008