PQ95614: USING CUSTOM FINDER METHODS IN CMP 1.1 BEANS MAY LEAD TO JAVA.LANG.OUTOFMEMORYERROR OR A SLOWDOWN OF THE APPSERVER | |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
![]() |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
![]() APAR status Closed as program error. Error description When using custom finder methods for CMP 1.1 EJBs can lead to either a memory issue or a AppServer performance issue. . The primary symptoms of this problem would be either a java.lang.OutOfMemoryError OR a slowdown in the AppServer. The java.lang.OutOfMemoryError would likely show the following in the verboseGC (on AIX, Linux, or Windows) <AF[12636]: Allocation Failure. need 3444936 bytes, 7 ms since last AF> ... <GC(15975): freed 297064 bytes, 29% free (312636544/1073674752), in 3230 ms> ... <AF[12636]: totally out of heap space> It is essentially similar to a fragmented heap problem. . However, these symptoms are very generic. The deeper symptoms are not as easy problem to describe. Some of the symptoms of this problem are: 1. javacores or thread dumps would have many threads with a stack similar to this one: "Servlet.Engine.Transports : 8" (TID:0x54901710, sys_thread_t: 0x898D4E8, state:MW, native ID:0xFC38) prio=5 at java.lang.String.<init>(String.java(Inlined Compiled Code)) at java.lang.Integer.toUnsignedString(Integer.java(Inlined Compiled Code at java.lang.Integer.toHexString(Integer.java(Inlined Compiled Code)) at com.ibm.ejs.ras.RasEvent.<init>(RasEvent.java(Compiled Code)) at com.ibm.ejs.ras.StreamEvent.<init>(StreamEvent.java(Inlined Compiled com.ibm.ejs.ras.SystemOutStream.createEvent(SystemOutStream.java (Compile at com.ibm.ejs.ras.SystemStream.doPrintLine(SystemStream.java(Compi led C at com.ibm.ejs.ras.SystemStream.println(SystemStream.java(Compiled Code) at java.lang.Throwable.printStackTrace0(Native Method) at java.lang.Throwable.printStackTrace(Throwable.java:206) at com.ibm.ws.util.WSThreadLocal.<init>(WSThreadLocal.java:23) . This should lead back to a custom finde3 method in the stack. The com.ibm.ws.util.WSThreadLocal would also likely be in the stack trace. . 2. The verbose GC might show that a somewhat large object, possibly 330K to 3M is the cause of the Allocation Failure; the object will frequently be the same size many size and when it does change in size, it will increment by 8 bytes. <AF[12775]: Allocation Failure. need 3445224 bytes, 236 ms since last AF> <AF[12775]: managing allocation failure, action=2 (316640944/1073674752)> <GC(16154): Concurrent ABORTED. Target=885218511 Traced=66964 (0+66964) Free=314058424> <GC(16154): mark stack overflow[4761]> <GC(16154): GC cycle started Wed Sep 15 12:33:58 2004 <GC(16154): freed 40642816 bytes, 33% free (357283760/1073674752), in 846 ms> <GC(16154): mark: 809 ms, sweep: 37 ms, compact: 0 ms> <GC(16154): refs: soft 0 (age >= 32), weak 0, final 27, phantom 0> <AF[12775]: completed in 849 ms> <CONCURRENT GC Free= 110020352 Expected free space= 110009672 Kickoff=110013579> < Initial Trace rate is 8.00> <AF[12776]: Allocation Failure. need 3445224 bytes, 3242 ms since last AF> <AF[12776]: managing allocation failure, action=2 (60320992/1073674752)> <GC(16155): Concurrent HALTED (state=128). Target=880108635 Traced=414154177 (212010961+202143216) Free=57738472> <GC(16155): No Dirty Cards cleaned (Factor 0.200)> <GC(16155): GC cycle started Wed Sep 15 12:34:02 2004 <GC(16155): freed 337967200 bytes, 37% free (398288192/1073674752), in 342 ms> <GC(16155): mark: 304 ms, sweep: 38 ms, compact: 0 ms> <GC(16155): In mark: Final dirty Cards scan: 98 ms 25936 cards (total:67881 ms) <GC(16155): refs: soft 0 (age >= 32), weak 0, final 814, phantom 0> <AF[12776]: completed in 344 ms> <CONCURRENT GC Free= 108290912 Expected free space= 108247216 Kickoff=108272459> < Initial Trace rate is 8.00> <AF[12777]: Allocation Failure. need 3445232 bytes, 7061 ms since last AF> <AF[12777]: managing allocation failure, action=1 (49989712/1070529024) (3145728/3145728)> <GC(16156): Concurrent HALTED (state=128). Target=866179675 Traced=402330103 (91084895+311245208) Free=49989712> <GC(16156): Cards cleaning Active. cleaned:918 (418486 skipped or not reached yet). estimation 419404 (Factor 0.200)> <GC(16156): GC cycle started Wed Sep 15 12:34:09 2004 . 3. The heap dump would show that the objects with the size identified above are array of java.lang.Object and that its parent class is WSThreadLocal.Local fix Problem summary **************************************************************** * USERS AFFECTED: Developers of CMP1.1 enterprise java beans * **************************************************************** * PROBLEM DESCRIPTION: The primary symptoms of this problem * * would be either a * * java.lang.OutOfMemoryError OR a * * slowdown in the Application Server. * * The java.lang.OutOfMemoryError would * * likely show the following * * in the verboseGC (on AIX, Linux, or * * Windows) Allocation Failure. * **************************************************************** * RECOMMENDATION: * **************************************************************** Applications which are utilizing CMP1.1 EJBs are only affected.Problem conclusion Problem fixed by modifying use of WSThreadLocal SPI.Temporary fix Comments
APAR is sysrouted FROM one or more of the following: APAR is sysrouted TO one or more of the following: PQ98081 Modules/Macros
Publications Referenced
|
Product categories: Software > Application Servers >
Distributed Application & Web Servers > WebSphere Application
Server > General
Operating system(s):
Software version: 00I
Software edition:
Reference #: PQ95614
IBM Group: Software Group
Modified date: Jan 27, 2005
(C) Copyright IBM Corporation 2000, 2008. All Rights Reserved.