Bug 53345 - OutOfMemory Error from Appender
Summary: OutOfMemory Error from Appender
Status: NEW
Alias: None
Product: Log4j - Now in Jira
Classification: Unclassified
Component: Appender (show other bugs)
Version: 1.2
Hardware: Other Linux
: P2 major
Target Milestone: ---
Assignee: log4j-dev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-06-01 13:52 UTC by Mallikarjun Channappagoudar
Modified: 2012-06-04 14:41 UTC (History)
0 users



Attachments
Config file. (479 bytes, application/octet-stream)
2012-06-01 15:12 UTC, Mallikarjun Channappagoudar
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Mallikarjun Channappagoudar 2012-06-01 13:52:59 UTC
Seeing the below OutOfMemoryError error associated with Log4j ver log4j-1.2.15.jar.

Caused by: java.lang.OutOfMemoryError
	at java.util.Arrays.copyOfRange(Arrays.java:4078)
	at java.util.Arrays.copyOf(Arrays.java:3810)
	at java.io.ByteArrayOutputStream.write(ByteArrayOutputStream.java:108)
	at java.io.PrintStream.write(PrintStream.java:443)
	at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:343)
	at sun.nio.cs.StreamEncoder$CharsetSE.implFlushBuffer(StreamEncoder.java:413)
	at sun.nio.cs.StreamEncoder$CharsetSE.implFlush(StreamEncoder.java:417)
	at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:161)
	at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:263)
	at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:58)
	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:316)
	at org.apache.log4j.WriterAppender.append(WriterAppender.java:160)
	at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
	at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
	at org.apache.log4j.Category.callAppenders(Category.java:206)
	at org.apache.log4j.Category.forcedLog(Category.java:391)
	at org.apache.log4j.Category.debug(Category.java:260)
	at com.bcbsma.adapter.util.TPS837_D_Utils.getTransformed837DXmls(TPS837_D_Utils.java:119)
	at com.bcbsma.adapter.impl.TPS837AdapterImpl.processRequest(TPS837AdapterImpl.java:239)
	at sun.reflect.GeneratedMethodAccessor1768.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:600)
	at org.apache.tuscany.sca.implementation.java.invocation.JavaImplementationInvoker.invoke(JavaImplementationInvoker.java:158)
	at com.ibm.ws.soa.sca.observer.integration.ObserverInterceptor.invoke(ObserverInterceptor.java:199)
	at com.ibm.ws.soa.sca.binding.jms.provider.JMSInterceptor.invoke(JMSInterceptor.java:64)
	at com.ibm.ws.soa.sca.runtime.impl.RuntimeExtensionManager.invokeNextInterceptor(RuntimeExtensionManager.java:237)
	at com.ibm.ws.soa.sca.runtime.impl.RuntimeExtensionManager.processMessage(RuntimeExtensionManager.java:98)
	at com.ibm.ws.soa.sca.runtime.impl.RuntimeTuscanyInterceptor.invoke(RuntimeTuscanyInterceptor.java:209)
	at org.apache.tuscany.sca.core.databinding.wire.DataTransformationInterceptor.invoke(DataTransformationInterceptor.java:67)
	at org.apache.tuscany.sca.core.invocation.RuntimeWireInvoker.invoke(RuntimeWireInvoker.java:129)
	... 24 more
Comment 1 grobmeier 2012-06-01 14:02:06 UTC
Hello,

can you provide more information?

Could you for example look how the log statement looks like:
om.bcbsma.adapter.util.TPS837_D_Utils.getTransformed837DXmls(TPS837_D_Utils.java:119)

Is it a String? How big is it?

Also can you probably show us your configuration?

Thanks!
Comment 2 Mallikarjun Channappagoudar 2012-06-01 14:52:33 UTC
(In reply to comment #1)
> Hello,
> 
> can you provide more information?
> 
> Could you for example look how the log statement looks like:
> om.bcbsma.adapter.util.TPS837_D_Utils.getTransformed837DXmls(TPS837_D_Utils.
> java:119)
> 
> Is it a String? How big is it?
> 
> Also can you probably show us your configuration?
> 
> Thanks!

Surprisingly the line of code at TPS837_D_Utils.java:119 is not a debug statement, but for some reason the error stack has the following lines.

	at org.apache.log4j.Category.forcedLog(Category.java:391)
	at org.apache.log4j.Category.debug(Category.java:260)
	at com.bcbsma.adapter.util.TPS837_D_Utils.getTransformed837DXmls(TPS837_D_Utils.java:119)

But there are other instances where the line of code is actually a logger.debug statement and have caused OutOfMemory errors.

This has happened for small as well as large strings.

The configuration and env info is as follows.

The OS is Linux 2.6.18-164.el5 x86_64 GNU/Linux.
The application is deployed on WAS ND 7.0 with SCA Feature pack 1.0.1

I tried to attach the native_stderr.log file to the bug but may be due to file size it was not getting attached.
Comment 3 grobmeier 2012-06-01 14:58:42 UTC
Can you try to attach the configuration at least?
We should look into what appenders you are using.

Do you also use MDC or FilewatchDog or something like that?
Comment 4 Mallikarjun Channappagoudar 2012-06-01 15:10:31 UTC
(In reply to comment #3)
> Can you try to attach the configuration at least?
> We should look into what appenders you are using.
> 
> Do you also use MDC or FilewatchDog or something like that?

We use MDC. Find attached the config file.
Comment 5 Mallikarjun Channappagoudar 2012-06-01 15:12:09 UTC
Created attachment 28875 [details]
Config file.
Comment 6 grobmeier 2012-06-01 15:17:53 UTC
Probably you are running into MDC problems.
Do you remove all the key appropriate after you have added them to MDC?

The config does not look as it would cause problems, so I suspect MDC.

With 1.2.17 a nasty MDC related fix has been applied. Please see the conversation around it here:
https://issues.apache.org/bugzilla/show_bug.cgi?id=50486

At the bottom is some example code how to proper use MDC (and clean it up).

Please let me know if an upgrade to 1.2.17 and the recommendations from this issue helped you.
Comment 7 Mallikarjun Channappagoudar 2012-06-01 20:05:20 UTC
(In reply to comment #6)
> Probably you are running into MDC problems.
> Do you remove all the key appropriate after you have added them to MDC?
> 
> The config does not look as it would cause problems, so I suspect MDC.
> 
> With 1.2.17 a nasty MDC related fix has been applied. Please see the
> conversation around it here:
> https://issues.apache.org/bugzilla/show_bug.cgi?id=50486
> 
> At the bottom is some example code how to proper use MDC (and clean it up).
> 
> Please let me know if an upgrade to 1.2.17 and the recommendations from this
> issue helped you.

We will try the version 1.2.17.
We use MDC in the following way, we do not remove the keys.

		// Add set MDC at the beginning of Adapter transaction
		try {
			MDC.put(com.bcbsma.service.extendedmodel.Constants.MDC_CONTEXT, resp.getSubmitClaimRequest().getContext().getRequestId());
		} catch (Exception ex) {
			logger.error(ex);
			// ignore the Error
		}
Comment 8 grobmeier 2012-06-01 20:10:29 UTC
OK then this will cause the trouble.

Basically MDC puts its values to ThreadLocalMap:
http://svn.apache.org/repos/asf/logging/log4j/trunk/src/main/java/org/apache/log4j/MDC.java

It seems that your thread is putting so much values that at some point of time the memory is full. To prevent this, you need to clean up MDC like for example:

try {
    MDC.put(myKey);
    chain.doFilter(request, response);
} finally {
    MDC.remove(myKey);
}        

Or you can clear the whole MDC with: MDC.clear();

it would be nice if you would try that out and let us know if your issue is solved then.

Thanks!
Comment 9 Mallikarjun Channappagoudar 2012-06-04 14:41:55 UTC
(In reply to comment #8)
> OK then this will cause the trouble.
> 
> Basically MDC puts its values to ThreadLocalMap:
> http://svn.apache.org/repos/asf/logging/log4j/trunk/src/main/java/org/apache/
> log4j/MDC.java
> 
> It seems that your thread is putting so much values that at some point of
> time the memory is full. To prevent this, you need to clean up MDC like for
> example:
> 
> try {
>     MDC.put(myKey);
>     chain.doFilter(request, response);
> } finally {
>     MDC.remove(myKey);
> }        
> 
> Or you can clear the whole MDC with: MDC.clear();
> 
> it would be nice if you would try that out and let us know if your issue is
> solved then.
> 
> Thanks!

Thanks for your blazing fast responses.
We will incorporate the suggested changes and let you know of the outcome.