Hi Guys,
Our application is a servlet running in a container in Tomcat
standalone. It uses the following NIO connector definition:
<Connector port="80"
protocol="org.apache.coyote.http11.Http11NioProtocol"
connectionTimeout="65000" keepAliveTimeout="10000"
maxKeepAliveRequests="1000"
redirectPort="443" maxThreads="2000"/>
Lately we've been experiencing a fatal error, related to gc, with Tomcat
that causes it to stop and unload, which I hoped you could give some
advice for.
I'm still unclear on what is causing the cleaner to terminate, but I
guess that's more of a question for the java forums (I cannot find
anything related to tomcat when I cross reference)
Following the gc trail, it looks like an oom situation (maybe a mem leak
in our application, our heapsize is 4GB), is it normal behavior for
tomcat to destroy itsself like this?
Has anyone experienced a similar problem before? What are usual causes
for Tomcat to stop like this?
*Any* advice or feedback is welcome. Either way, thanks in advance.
Debian 4.0
Tomcat 6.0.18
Sun jdk 1.6.0.11
We use the following java options:
OPTS="
-verbose:gc
-Dsun.net.inetaddr.ttl=60
-Dfile.encoding=UTF-8
-Djava.io.tmpdir=$TMP_DIR
-Djava.library.path=/usr/local/lib
-Djava.endorsed.dirs=$CATALINA_BASE/endorsed
-Dcatalina.base=$CATALINA_BASE
-Dcatalina.home=$CATALINA_HOME
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
-Djava.util.logging.config.file="$CATALINA_BASE/conf/logging.properties"
-XX:+UseConcMarkSweepGC
-XX:+UseParNewGC
-XX:+CMSIncrementalMode
-Xms4096M
-Xmx4096M
-Xss128k
-XX:PermSize=256M
-XX:MaxPermSize=256M
--- catalina.out snippet ----
[GC 4052829K->3924296K(4177280K), 0.0519680 secs]
[GC 4060616K->3924100K(4177280K), 0.1517880 secs]
[GC 4060420K->3926867K(4177280K), 0.0883940 secs]
[GC 4062488K->3931589K(4177280K), 0.1008470 secs]
[GC 4067906K->3935097K(4177280K), 0.0931530 secs]
[GC 4071417K->3934946K(4177280K), 0.0787300 secs]
[GC 4029027K(4177280K), 0.1941170 secs]
java.lang.Error: Cleaner terminated abnormally
at sun.misc.Cleaner$1.run(Cleaner.java:130)
at java.security.AccessController.doPrivileged(Native Method)
at sun.misc.Cleaner.clean(Cleaner.java:127)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:124)
Caused by: java.lang.Error: java.io.IOException: Broken pipe
at sun.nio.ch.Util$SelectorWrapper$Closer.run(Util.java:97)
at sun.misc.Cleaner.clean(Cleaner.java:125)
... 1 more
Caused by: java.io.IOException: Broken pipe
at sun.nio.ch.EPollArrayWrapper.interrupt(Native Method)
at
sun.nio.ch.EPollArrayWrapper.interrupt(EPollArrayWrapper.java:242)
at sun.nio.ch.EPollSelectorImpl.wakeup(EPollSelectorImpl.java:170)
at sun.nio.ch.SelectorImpl.implCloseSelector(SelectorImpl.java:92)
at
java.nio.channels.spi.AbstractSelector.close(AbstractSelector.java:91)
at sun.nio.ch.Util$SelectorWrapper$Closer.run(Util.java:95)
... 2 more
Feb 17, 2009 12:10:38 AM org.apache.coyote.http11.Http11NioProtocol pause
INFO: Pausing Coyote HTTP/1.1 on http-80
Feb 17, 2009 12:10:38 AM org.apache.coyote.http11.Http11AprProtocol pause
INFO: Pausing Coyote HTTP/1.1 on http-443
Feb 17, 2009 12:10:38 AM org.apache.coyote.ajp.AjpAprProtocol pause
INFO: Pausing Coyote AJP/1.3 on ajp-8009
[GC 4071265K->3937784K(4177280K), 0.0921220 secs]
Feb 17, 2009 12:10:39 AM org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
Feb 17, 2009 12:10:39 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 28,017 instance(s) to be deallocated
Feb 17, 2009 12:10:41 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 27,669 instance(s) to be deallocated
Feb 17, 2009 12:10:42 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 27,666 instance(s) to be deallocated
Feb 17, 2009 12:10:43 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 3 instance(s) to be deallocated
Feb 17, 2009 12:10:44 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 3 instance(s) to be deallocated
Feb 17, 2009 12:10:45 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 3 instance(s) to be deallocated
360358820 [SocketConnectorIoProcessor-0.0] null
org.apache.mina.common.support.DefaultExceptionMonitor - Unexpected
exception.
java.lang.NullPointerException
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:225)
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:208)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:210)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:198)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProcessor.java:45)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:485)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:619)
360359827 [SocketConnectorIoProcessor-0.0] null
org.apache.mina.common.support.DefaultExceptionMonitor - Unexpected
exception.
java.lang.NullPointerException
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:225)
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:208)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:210)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:198)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProcessor.java:45)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:485)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:619)
Feb 17, 2009 12:11:08 AM org.apache.coyote.http11.Http11NioProtocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-80
log4j:ERROR Error occured while converting date.
java.lang.NullPointerException
at java.lang.System.arraycopy(Native Method)
at
java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:328)
at java.lang.StringBuffer.getChars(StringBuffer.java:201)
at
org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.java:128)
at java.text.DateFormat.format(DateFormat.java:316)
at
org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(PatternParser.java:444)
at
org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:64)
at org.apache.log4j.PatternLayout.format(PatternLayout.java:503)
at
org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:301)
at
org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:234)
at org.apache.log4j.WriterAppender.append(WriterAppender.java:159)
at
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:230)
at
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:65)
at org.apache.log4j.Category.callAppenders(Category.java:203)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.error(Category.java:319)
at
com.emessenger.facebook.FacebookMessenger.getBuddyList(FacebookMessenger.java:677)
at
com.emessenger.facebook.FacebookMessenger$2.run(FacebookMessenger.java:254)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
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)
360361291 [SocketConnectorIoProcessor-0.0] null
org.apache.mina.common.support.DefaultExceptionMonitor - Unexpected
exception.
java.lang.NullPointerException
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:225)
at org.apache.mina.common.ByteBuffer.allocate(ByteBuffer.java:208)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:210)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:198)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor.access$400(SocketIoProcessor.java:45)
at
org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:485)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:619)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]