logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mahesh Dilhan <mail.mahesh...@gmail.com>
Subject Re: Catalina.out trace : memory leak
Date Fri, 11 Apr 2014 02:43:19 GMT
side note ; java version : JDK 1.6.0_10

Remko

Can you share a dummy maven webapp [.tar] some where in
http://logging.apache.org/log4j/2.x/manual/async.html
 , with necessary dependencies  and [*Async]* configuration for log4j2.xml
So ppl can just build and deploy it in a tomcat container [ > 7.0.40 ], and
provide feedback, as this might be a problem in my configuration

steps of test case : deploy/ start/stop, trace catalina.out

Thanks in advance


On Fri, Apr 11, 2014 at 7:49 AM, Mahesh Dilhan <mail.mahesh.lk@gmail.com>wrote:

> Observed followings after
>
>  - removing
>  Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
> from catalina.properties
> - change <Root> .. </Root> tag to
>     <AsyncRoot level="INFO" includeLocation="false">
>         <AppenderRef ref="RollingFile-${web:contextPath}"/>
>     </AsyncRoot>
>
>
> On start-up
>
> 014-04-11 07:43:03,640 ERROR An exception occurred processing Appender
> RollingFile-/app java.lang.NullPointerException
>        at java.lang.StringBuilder.<init>(StringBuilder.java:92)
>        at
> org.apache.logging.log4j.core.pattern.NameAbbreviator$PatternAbbreviator.abbreviate(NameAbbreviator.java:286)
>        at
> org.apache.logging.log4j.core.pattern.NamePatternConverter.abbreviate(NamePatternConverter.java:53)
>        at
> org.apache.logging.log4j.core.pattern.LoggerPatternConverter.format(LoggerPatternConverter.java:64)
>        at
> org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:36)
>        at
> org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:172)
>        at
> org.apache.logging.log4j.core.layout.PatternLayout.toSerializable(PatternLayout.java:52)
>        at
> org.apache.logging.log4j.core.layout.AbstractStringLayout.toByteArray(AbstractStringLayout.java:45)
>        at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:118)
>        at
> org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:96)
>        at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:97)
>        at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:425)
>        at
> org.apache.logging.log4j.core.async.AsyncLoggerConfig.asyncCallAppenders(AsyncLoggerConfig.java:117)
>        at
> org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigHelper.java:222)
>        at
> org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigHelper.java:207)
>        at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
>        at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>        at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>        at java.lang.Thread.run(Thread.java:619)
>
>
> Also Console
> Apr 11, 2014 7:42:49 AM org.apache.catalina.loader.WebappClassLoader
> checkThreadLocalMapForLeaks
> SEVERE: The web application [/clearing-newcdev10] created a ThreadLocal
> with key of type [java.lang.ThreadLocal] (value
> [java.lang.ThreadLocal@131d70a]) and a value of type [
> org.apache.logging.log4j.core.async.AsyncLogger.Info] (value
> [org.apache.logging.log4j.core.async.AsyncLogger$Info@11cd743]) but
> failed to remove it when the web application was stopped. Threads are going
> to be renewed over time to try and avoid a probable memory leak.
>
>
>
> *Now JConsole has two thread *
>
> *Name: AsyncLoggerConfig-1*
> State: TIMED_WAITING
> Total blocked: 0  Total waited: 307,234
>
> Stack trace:
> sun.misc.Unsafe.park(Native Method)
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
>
> com.lmax.disruptor.SleepingWaitStrategy.applyWaitMethod(SleepingWaitStrategy.java:78)
>
> com.lmax.disruptor.SleepingWaitStrategy.waitFor(SleepingWaitStrategy.java:51)
>
> com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> java.lang.Thread.run(Thread.java:619)
>
>
> *Name: AsyncLogger-1*
> State: TIMED_WAITING
> Total blocked: 0  Total waited: 325,479
>
> Stack trace:
> sun.misc.Unsafe.park(Native Method)
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
>
> com.lmax.disruptor.SleepingWaitStrategy.applyWaitMethod(SleepingWaitStrategy.java:78)
>
> com.lmax.disruptor.SleepingWaitStrategy.waitFor(SleepingWaitStrategy.java:51)
>
> com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)
>
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> java.lang.Thread.run(Thread.java:619)
>
>
>
>
> On Thu, Apr 10, 2014 at 8:45 PM, Remko Popma <remko.popma@gmail.com>wrote:
>
>> OK, One more thing you can try is, instead of making all loggers async by
>> setting system property
>> Log4jContextSelector=org.apache.logging.log4j.core.async.
>> AsyncLoggerContextSelector,
>>
>> instead remove that property
>> and replace the <Root></Root> elements in your log4j2.xml config with
>> <AsyncRoot></AsyncRoot> elements. This will also use the disruptor but
>> uses
>> a slightly different mechanism.
>>
>> Do you still see the problem after these changes?
>>
>>
>>
>> On Thu, Apr 10, 2014 at 6:58 PM, Mahesh Dilhan <mail.mahesh.lk@gmail.com
>> >wrote:
>>
>> > HI
>> >
>> > Answers are in blue
>> >
>> > This may be caused by the LoggerContext.stop() method not being called.
>> >
>> > Which version of Tomcat are you using?  Special care is needed for
>> Tomcat
>> > 7.0.40 and older.
>> > *apache-tomcat-7.0.47*
>> >
>> > A similar issue, LOG4J2-578 seemed to be caused by a config issue where
>> the
>> > version number in web.xml was incorrect.
>> > Can you check this?
>> >
>> > *<web-app xmlns="http://java.sun.com/xml/ns/javaee
>> > <http://java.sun.com/xml/ns/javaee>"
>> >  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance
>> > <http://www.w3.org/2001/XMLSchema-instance>"
>> >  xsi:schemaLocation="http://java.sun.com/xml/ns/javaee
>> > <http://java.sun.com/xml/ns/javaee>*
>> > *    http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd
>> > <http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd>"   version="3.0"
>> >  metadata-complete="true">*
>> >
>> > *WEB-INF/lib does not contains any servlet-api, [tomcat container
>> provides
>> > the servlet-api.jar] *
>> > Also, are the log4j jars under the shared Catalina lib? No
>> > I suspect the problem goes away if you put the log4j jars under your
>> > webapp's WEB-INF/lib folder.
>> >
>> > *Dependencies are located in WEB-INF/lib ,*
>> > *<dependency>*
>> > *            <groupId>com.lmax</groupId>*
>> > *            <artifactId>disruptor</artifactId>*
>> > *            <version>3.2.1</version>*
>> > *        </dependency> *
>> > *        <dependency>*
>> > *            <groupId>org.apache.logging.log4j</groupId>*
>> > *            <artifactId>log4j-api</artifactId>*
>> > *            <version>2.0-rc1</version>*
>> > *        </dependency>*
>> > *        <dependency>*
>> > *            <groupId>org.apache.logging.log4j</groupId>*
>> > *            <artifactId>log4j-core</artifactId>*
>> > *            <version>2.0-rc1</version>*
>> > *        </dependency>*
>> > *        <dependency>*
>> > *            <groupId>org.apache.logging.log4j</groupId>*
>> > *            <artifactId>log4j-slf4j-impl</artifactId>*
>> > *            <version>2.0-rc1</version>*
>> > *        </dependency>*
>> > *        <dependency>*
>> > *            <groupId>org.apache.logging.log4j</groupId>*
>> > *            <artifactId>log4j-1.2-api</artifactId>*
>> > *            <version>2.0-rc1</version>*
>> > *        </dependency>*
>> >
>> >
>> > *For test 1 Configurations are  in -catalina.properties  & for test 2
>> that
>> > is in -catalina.sh [CATALINA_OPTS] , in both occation, it worked*
>> >
>> >
>> *Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector*
>> > *log4j2.disable.jmx=true*
>> >
>> > But I still get following console out
>> >
>> >
>> > 2014-04-10 12:56:09,120 DEBUG Shutting down OutputStreamManager
>> SYSTEM_OUT
>> > 2014-04-10 12:56:09,123 DEBUG JMX disabled for log4j2. Not registering
>> > MBeans.
>> > 2014-04-10 12:56:09,168 DEBUG Using default SystemClock for timestamps
>> > 2014-04-10 12:56:09,169 DEBUG AsyncLogger.ThreadNameStrategy=CACHED
>> > 2014-04-10 12:56:09,171 DEBUG property AsyncLogger.WaitStrategy=null
>> > 2014-04-10 12:56:09,173 DEBUG disruptor event handler uses
>> > SleepingWaitStrategy
>> > 2014-04-10 12:56:09,197 DEBUG No AsyncLogger.ExceptionHandler specified
>> > 2014-04-10 12:56:09,203 DEBUG Starting AsyncLogger disruptor with
>> > ringbuffer size 262144...
>> >
>> > SEVERE: The web application [/app] created a ThreadLocal with key of
>> type
>> > [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@17b3a1e]) and a
>> > value
>> > of type [org.apache.logging.log4j.core.async.AsyncLogger.Info] (value
>> > [org.apache.logging.log4j.core.async.AsyncLogger$Info@1aca2de]) but
>> failed
>> > to remove it when the web application was stopped. Threads are going to
>> be
>> > renewed over time to try and avoid a probable memory leak.
>> > Apr 10, 2014 2:53:28 PM org.apache.catalina.loader.WebappClassLoader
>> > checkThreadLocalMapForLeaks
>> >
>> >
>> >
>> > *Also JConsole*
>> >
>> > *Name: AsyncLogger-1*
>> > *State: TIMED_WAITING*
>> > *Total blocked: 1  Total waited: 228,630 [ this number getting
>> increased ]*
>> >
>> > *Stack trace: *
>> > *sun.misc.Unsafe.park(Native Method)*
>> > *java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)*
>> >
>> >
>> *com.lmax.disruptor.SleepingWaitStrategy.applyWaitMethod(SleepingWaitStrategy.java:78)*
>> >
>> >
>> *com.lmax.disruptor.SleepingWaitStrategy.waitFor(SleepingWaitStrategy.java:51)*
>> >
>> >
>> *com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)*
>> >
>> *com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)*
>> >
>> >
>> *java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)*
>> >
>> >
>> *java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)*
>> > *java.lang.Thread.run(Thread.java:619)*
>> >
>> >
>> > On Thu, Apr 10, 2014 at 9:51 AM, Remko Popma <remko.popma@gmail.com>
>> > wrote:
>> >
>> > > This may be caused by the LoggerContext.stop() method not being
>> called.
>> > >
>> > > Which version of Tomcat are you using? Special care is needed for
>> Tomcat
>> > > 7.0.40 and older.
>> > >
>> > > A similar issue, LOG4J2-578 seemed to be caused by a config issue
>> where
>> > > the version number in web.xml was incorrect. Can you check this?
>> > >
>> > > Also, are the log4j jars under the shared Catalina lib? I suspect the
>> > > problem goes away if you put the log4j jars under your webapp's
>> > WEB-INF/lib
>> > > folder.
>> > >
>> > > Remko
>> > >
>> > > Sent from my iPhone
>> > >
>> > > > On 2014/04/10, at 11:24, Mahesh Dilhan <mail.mahesh.lk@gmail.com>
>> > wrote:
>> > > >
>> > > > HI
>> > > >
>> > > > I got following catalina console out continuously  when I try to
>> stop
>> > the
>> > > > web application.
>> > > >
>> > > > Brief  on configuration
>> > > > *version : rc1*
>> > > >
>> > > > *Log4j2.xml*
>> > > >
>> > > > <Configuration status="OFF" >
>> > > >  <Appenders>
>> > > >    <RollingRandomAccessFile name="RollingFile-${web:contextPath}"
>> > > > fileName="${sys:catalina.home}/logs/current/${web:contextPath}.log"
>> > > > immediateFlush="false" append="false"
>> > > >
>> > > >
>> > >
>> >
>> filePattern="${sys:catalina.home}/logs/archived/%d{yyyy-MM-dd}${contextName}-%d{yyyy-MM-dd}.log.gz">
>> > > >      <PatternLayout>
>> > > >        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
>> > > >      </PatternLayout>
>> > > >      <Policies>
>> > > >        <TimeBasedTriggeringPolicy />
>> > > >      </Policies>
>> > > >    </RollingRandomAccessFile>
>> > > >  </Appenders>
>> > > >  <Loggers>
>> > > >    <Root level="INFO" includeLocation="false">
>> > > >      <AppenderRef ref="RollingFile-${web:contextPath}"/>
>> > > >
>> > > >    </Root>
>> > > >  </Loggers>
>> > > > </Configuration>
>> > > >
>> > > > *Tomcat properties :*
>> > > > Asysnc logger [tomcat is configured with the property
>> > > >
>> > >
>> >
>> {Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
>> > > > }
>> > > >
>> > > >
>> > > >
>> > > >
>> > > >
>> > > > Apr 08, 2014 12:32:17 PM
>> org.apache.catalina.loader.WebappClassLoader
>> > > > clearReferencesThreads
>> > > > SEVERE: The web application [/app] appears to have started a thread
>> > named
>> > > > [AsyncLogger-1] but has failed to stop it. *This is very likely to
>> > > create a
>> > > > memory leak.*
>> > > > Apr 08, 2014 12:32:17 PM
>> org.apache.catalina.loader.WebappClassLoader
>> > > > checkThreadLocalMapForLeaks
>> > > > SEVERE: The web application [/app] created a ThreadLocal with key
of
>> > type
>> > > > [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@e8d7057])
>> and a
>> > > value
>> > > > of type [org.apache.logging.log4j.core.async.AsyncLogger.Info]
>> (value
>> > > > [org.apache.logging.log4j.core.async.AsyncLogger$Info@67ca6737])
>> but
>> > > failed
>> > > > to remove it when the web application was stopped. Threads are
>> going to
>> > > be
>> > > > renewed over time to try and avoid a probable memory leak.
>> > > >
>> > > >
>> > > >
>> > > > What could be missing in my configuration to run into a such console
>> > > trace ?
>> > > > What are the fixes I should look-into ?
>> > > >
>> > > >
>> > > > Thanks
>> > >
>> > > ---------------------------------------------------------------------
>> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
>> > >
>> > >
>> >
>>
>
>
>
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message