Uploaded image for project: 'Application Server 3  4  5 and 6'
  1. Application Server 3 4 5 and 6
  2. JBAS-9455

StackOverflowError from SMTPAppender error loop

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • 6.0.0.Final
    • Logging
    • None

      What happened:

      JBoss AS 6.0.0.Final crashed with java.lang.StackOverflowError. Before the crash the following line is repeated dozens of times:

      ERROR [STDERR] (http-0.0.0.0-8443-15) log4j:ERROR Error occured while sending e-mail notification.

      This has happened for me once before, with the same server. The smtp server runs on the same computer and is exclusively used by the JBoss AS. The application uses MySQL 5.1.53, connector version 5.1.13 and com.mysql.jdbc.jdbc2.optional.MysqlXADataSource.

      See below for stack trace.

      What I think happened:

      I have JBoss AS 6.0.0.Final set up to send error messages via email to developers using SMTPAppender. This caused the server to crash with java.lang.StackOverflowError due to the SMTPAppender getting stuck in a loop. For some reason sending email failed, and the SMTPAppender tried sending the resulting error message via email. This caused the above error message, which again triggered SMTPAppender to forward it via email.

      SMTPAppender should detect said loop, and moreso the error message shouldn't be printed to STDERR. If it were printed directly via the logger, I could work around this by setting log level to FATAL for the specific class. The culprit for that is most likely in javamail, though.

      I sadly don't have a lot that could help figuring out why email sending fails. This issue is not repeated when I just simply shut down the smtp service. Right before the spam to STDERR started, there was a transaction rollback (included below, see above for MySQL version info). It isn't the most critical issue here, though.

      Stacktraces:

      ...

      2011-12-06 03:39:45,453 ERROR [STDERR] (http-0.0.0.0-8443-15) log4j:ERROR Error occured while sending e-mail notification.
      2011-12-06 03:39:45,467 ERROR [STDERR] (http-0.0.0.0-8443-15) log4j:ERROR Error occured while sending e-mail notification.
      2011-12-06 03:39:45,481 ERROR [STDERR] (http-0.0.0.0-8443-15) log4j:ERROR Error occured while sending e-mail notification.
      2011-12-06 03:39:45,495 ERROR [STDERR] (http-0.0.0.0-8443-15) log4j:ERROR Error occured while sending e-mail notification.
      2011-12-06 03:39:45,505 ERROR [org.apache.coyote.http11.Http11Protocol] (http-0.0.0.0-8443-15) Error reading request, ignored: java.lang.StackOverflowError
      at sun.nio.cs.UTF_8$Encoder.encodeLoop(UTF_8.java:447) [:1.6.0_14]
      at java.nio.charset.CharsetEncoder.encode(CharsetEncoder.java:544) [:1.6.0_14]
      at java.lang.StringCoding$StringEncoder.encode(StringCoding.java:240) [:1.6.0_14]
      at java.lang.StringCoding.encode(StringCoding.java:272) [:1.6.0_14]
      at java.lang.String.getBytes(String.java:946) [:1.6.0_14]
      at java.net.Inet4AddressImpl.lookupAllHostAddr(Native Method) [:1.6.0_14]
      at java.net.InetAddress$1.lookupAllHostAddr(InetAddress.java:849) [:1.6.0_14]
      at java.net.InetAddress.getAddressFromNameService(InetAddress.java:1200) [:1.6.0_14]
      at java.net.InetAddress.getLocalHost(InetAddress.java:1350) [:1.6.0_14]
      at javax.mail.internet.InternetAddress.getLocalAddress(InternetAddress.java:523) [:1.4.2]
      at javax.mail.internet.UniqueValue.getUniqueMessageIDValue(UniqueValue.java:95) [:1.4.2]
      at javax.mail.internet.MimeMessage.updateMessageID(MimeMessage.java:2050) [:1.4.2]
      at javax.mail.internet.MimeMessage.updateHeaders(MimeMessage.java:2073) [:1.4.2]
      at javax.mail.internet.MimeMessage.saveChanges(MimeMessage.java:2039) [:1.4.2]
      at javax.mail.Transport.send(Transport.java:119) [:1.4.2]
      at org.apache.log4j.net.SMTPAppender.sendBuffer(SMTPAppender.java:416) [:]
      at org.apache.log4j.net.SMTPAppender.append(SMTPAppender.java:256) [:]
      at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) [:]
      at org.jboss.logmanager.log4j.handlers.Log4jAppenderHandler.doPublish(Log4jAppenderHandler.java:111) [:]
      at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:64) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:283) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:291) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.logRaw(Logger.java:649) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.log(Logger.java:434) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71) [:6.0.0.Final]
      at org.jboss.stdio.WriterOutputStream.finish(WriterOutputStream.java:133) [:6.0.0.Final]
      at org.jboss.stdio.WriterOutputStream.write(WriterOutputStream.java:114) [:6.0.0.Final]
      at java.io.PrintStream.write(PrintStream.java:430) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:263) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:106) [:1.6.0_14]
      at java.io.OutputStreamWriter.write(OutputStreamWriter.java:190) [:1.6.0_14]
      at java.io.BufferedWriter.flushBuffer(BufferedWriter.java:111) [:1.6.0_14]
      at java.io.BufferedWriter.write(BufferedWriter.java:212) [:1.6.0_14]
      at java.io.Writer.write(Writer.java:140) [:1.6.0_14]
      at java.io.PrintStream.write(PrintStream.java:475) [:1.6.0_14]
      at java.io.PrintStream.print(PrintStream.java:619) [:1.6.0_14]
      at java.io.PrintStream.println(PrintStream.java:756) [:1.6.0_14]
      at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:297) [:6.0.0.Final]
      at org.apache.log4j.helpers.LogLog.error(LogLog.java:143) [:]
      at org.apache.log4j.net.SMTPAppender.sendBuffer(SMTPAppender.java:418) [:]
      at org.apache.log4j.net.SMTPAppender.append(SMTPAppender.java:256) [:]
      at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) [:]
      at org.jboss.logmanager.log4j.handlers.Log4jAppenderHandler.doPublish(Log4jAppenderHandler.java:111) [:]
      at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:64) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:283) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:291) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.logRaw(Logger.java:649) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.log(Logger.java:434) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71) [:6.0.0.Final]
      at org.jboss.stdio.WriterOutputStream.finish(WriterOutputStream.java:133) [:6.0.0.Final]
      at org.jboss.stdio.WriterOutputStream.write(WriterOutputStream.java:114) [:6.0.0.Final]
      at java.io.PrintStream.write(PrintStream.java:430) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:263) [:1.6.0_14]
      at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:106) [:1.6.0_14]
      at java.io.OutputStreamWriter.write(OutputStreamWriter.java:190) [:1.6.0_14]
      at java.io.BufferedWriter.flushBuffer(BufferedWriter.java:111) [:1.6.0_14]
      at java.io.BufferedWriter.write(BufferedWriter.java:212) [:1.6.0_14]
      at java.io.Writer.write(Writer.java:140) [:1.6.0_14]
      at java.io.PrintStream.write(PrintStream.java:475) [:1.6.0_14]
      at java.io.PrintStream.print(PrintStream.java:619) [:1.6.0_14]
      at java.io.PrintStream.println(PrintStream.java:756) [:1.6.0_14]
      at org.jboss.stdio.StdioContext$DelegatingPrintStream.println(StdioContext.java:297) [:6.0.0.Final]
      at org.apache.log4j.helpers.LogLog.error(LogLog.java:143) [:]
      at org.apache.log4j.net.SMTPAppender.sendBuffer(SMTPAppender.java:418) [:]
      at org.apache.log4j.net.SMTPAppender.append(SMTPAppender.java:256) [:]
      at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) [:]
      at org.jboss.logmanager.log4j.handlers.Log4jAppenderHandler.doPublish(Log4jAppenderHandler.java:111) [:]
      at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:64) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:283) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:291) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.logRaw(Logger.java:649) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]
      at org.jboss.logmanager.Logger.log(Logger.java:434) [jboss-logmanager.jar:1.2.0.CR10-SNAPSHOT]

      ...

      The stacktrace continues similarly, repeating the same calls...

      The following appears immediate before the spam to STDERR:

      2011-12-06 03:39:25,286 WARN [com.arjuna.ats.arjuna] (http-0.0.0.0-8443-15) ARJUNA-12077 Abort called on already aborted ato
      mic action 0:ffffd970f1c0:126a:4ed5e753:e5766
      2011-12-06 03:39:25,286 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 34) ARJUNA-12113 TransactionReaper::doCancel
      lations worker Thread[Transaction Reaper Worker 34,5,jboss] missed interrupt when cancelling TX 0:ffffd970f1c0:126a:4ed5e753:
      e5766 – exiting as zombie (zombie count decremented to 0)
      2011-12-06 03:39:25,286 ERROR [org.jboss.webservices.integration.invocation.InvocationHandlerEJB3] (http-0.0.0.0-8443-15) Met
      hod invocation failed with exception: Transaction rolled back: javax.ejb.EJBTransactionRolledbackException: Transaction rolle
      d back
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:115) [:0.0.1]
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:87) [:0.0.1]
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:255) [:0.0.1]
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.required(CMTTxInterceptor.java:349) [:0.0.1]
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.invoke(CMTTxInterceptor.java:209) [:0.0.1]
      at org.jboss.ejb3.tx2.aop.CMTTxInterceptorWrapper.invoke(CMTTxInterceptorWrapper.java:52) [:0.0.1]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76) [:1.0.0.GA]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.security.RunAsSecurityInterceptorv2.invoke(RunAsSecurityInterceptorv2.java:94) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.security.RoleBasedAuthorizationInterceptorv2.invoke(RoleBasedAuthorizationInterceptorv2.java:201) [
      :1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:182) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:41) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.core.context.CurrentInvocationContextInterceptor.invoke(CurrentInvocationContextInterceptor.java:47
      ) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67) [:1.0.1]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.interceptor.EJB3TCCLInterceptor.invoke(EJB3TCCLInterceptor.java:86) [:1.7.17]
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102) [jboss-aop.jar:2.2.1.GA]
      at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:272) [:1.7.17]
      at org.jboss.ejb3.stateless.StatelessContainer.invokeEndpoint(StatelessContainer.java:617) [:1.7.17]
      at org.jboss.webservices.integration.invocation.InvocationHandlerEJB3.invoke(InvocationHandlerEJB3.java:137) [:6.0.0.Final]
      at org.jboss.ws.core.server.ServiceEndpointInvoker.invoke(ServiceEndpointInvoker.java:241) [:3.4.1.GA]
      at org.jboss.wsf.stack.jbws.RequestHandlerImpl.processRequest(RequestHandlerImpl.java:527) [:3.4.1.GA]
      at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleRequest(RequestHandlerImpl.java:316) [:3.4.1.GA]
      at org.jboss.wsf.stack.jbws.RequestHandlerImpl.doPost(RequestHandlerImpl.java:222) [:3.4.1.GA]
      at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:147) [:3.4.1.GA]
      at org.jboss.wsf.common.servlet.AbstractEndpointServlet.service(AbstractEndpointServlet.java:87) [:1.4.1.GA]
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [:1.0.0.Final]
      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:324) [:6.0.0.Final]
      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:242) [:6.0.0.Final]
      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [:6.0.0.Final]
      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [:6.0.0.Final]
      at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:181) [:6.0.0.Final]
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:593) [:6.0.0.Final]
      at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.event(CatalinaContext.java:285) [:1.1.0.Final]
      at org.jboss.modcluster.catalina.CatalinaContext$RequestListenerValve.invoke(CatalinaContext.java:261) [:1.1.0.Final]
      at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:88) [:6.0.0.Final]
      at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:100) [:6.0.0.Final]
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [:6.0.0.Final]
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [:6.0.0.Final]
      at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158) [:6.0.0.Final]
      at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:567) [:6.0.0.Final]
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [:6.0.0.Final]
      at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:53) [:6.0.0.Final]
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:362) [:6.0.0.Final]
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) [:6.0.0.Final]
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [:6.0.0.Final]
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:951) [:6.0.0.Final]
      at java.lang.Thread.run(Thread.java:619) [:1.6.0_14]
      Caused by: javax.transaction.RollbackException: ARJUNA-16063 The transaction is not active!
      at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1148) [:6.0.0.Final]
      at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:119) [:6.0.0.Final]
      at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) [:6.0.0.Final]
      at org.jboss.ejb3.tx2.impl.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:82) [:0.0.1]
      ... 54 more

            Unassigned Unassigned
            gargan_jira Antti Kuusela (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Created:
              Updated: