PQ95614: USING CUSTOM FINDER METHODS IN CMP 1.1 BEANS MAY LEAD TO JAVA.LANG.OUTOFMEMORYERROR OR A SLOWDOWN OF THE APPSERVER

 Fixes are available

5.1.1.8: WebSphere Application Server 5.1.1 Cumulative Fix 8 for AIX
5.1.1.8: WebSphere Application Server 5.1.1 Cumulative Fix 8 for Windows
5.1.1.8: WebSphere Application Server 5.1.1 Cumulative Fix 8 for HP-UX
5.1.1.8: WebSphere Application Server 5.1.1 Cumulative Fix 8 for Solaris
5.1.1.6: WebSphere Application Server Version 5.1.1 Cumulative Fix 6
5.1.1.7: WebSphere Application Server Version 5.1.1 Cumulative Fix 7
5.1.1.4: WebSphere Application Server Version 5.1.1 Cumulative Fix 4
5.1.1.8: WebSphere Application Server 5.1.1 Cumulative Fix 8 for Linux



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 information
APAR number PQ95614
Reported component name WAS BASE 5.0
Reported component ID 5630A3600
Reported release 00I
Status CLOSED PER
PE NoPE
HIPER NoHIPER
Special Attention NoSpecatt
Submitted date 2004-10-12
Closed date 2004-10-22
Last modified date 2005-01-27

APAR is sysrouted FROM one or more of the following:

APAR is sysrouted TO one or more of the following:
PQ98081

Modules/Macros
EJBCONTR          

Publications Referenced

Fix information

Applicable component levels
R003 PSY    UP
R00A PSY    UP
R00H PSY    UP
R00I PSY    UP
R00P PSY    UP
R00S PSY    UP
R00W PSY    UP
R103 PSY    UP
R10A PSY    UP
R10H PSY    UP
R10I PSY    UP
R10P PSY    UP
R10S PSY    UP
R10W PSY    UP


Document Information


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