You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Ralph Goers (JIRA)" <ji...@apache.org> on 2014/03/09 23:17:43 UTC

[jira] [Commented] (LOG4J2-391) Flume appender crashes when lock timeout occurs

    [ https://issues.apache.org/jira/browse/LOG4J2-391?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13925344#comment-13925344 ] 

Ralph Goers commented on LOG4J2-391:
------------------------------------

I am having a hard time looking into this.  The stack trace above is definitely not for beta9 - nothing lines up.  I understand you believe you verified checksums but somehow you are not running beta9. 

> Flume appender crashes when lock timeout occurs
> -----------------------------------------------
>
>                 Key: LOG4J2-391
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-391
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Appenders
>    Affects Versions: 2.0-beta9
>         Environment: Rhel 5
>            Reporter: Kamal Bahadur
>             Fix For: 2.0-beta9
>
>         Attachments: log4j2-391_patch.txt
>
>
> Flume appender seems to crash when it can't acquire the lock on the embeded Berkeley DB before the timeout period. The flume appender should retry when this happens. Here is the stack trace:
> 2013-08-20 22:40:36,315 -0700 level=INFO  class=STDOUT              2013-08-20 22:40:36,314 ERROR Error reading database com.sleepycat.je.LockTimeoutException: (JE 5.0.73) Lock expired. Locker 988835149 -1_Thread-12_ThreadLocker: waited for lock on database=FlumePersistent[pprdgblas30i.ie.intuit.net:8800,pprdgblas30c.ie.intuit.net:8800,pprdgblas30b.ie.intuit.net:8800] /usr/local/whp-jboss-ws-5/server/default/flumeData LockAddr:2123888757 LSN=0x93/0x2d3184 type=READ grant=WAIT_NEW timeoutMillis=5000 startTime=1377063631308 endTime=1377063636310
> Owners: [<LockInfo locker="1275407544 1268918_DaemonPool-1-thread-2902_Txn" type="WRITE"/>]
> Waiters: []
> 	at com.sleepycat.je.txn.LockManager.newLockTimeoutException(LockManager.java:664)
> 	at com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:623)
> 	at com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:97)
> 	at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:390)
> 	at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
> 	at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:118)
> 	at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
> 	at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2621)
> 	at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2422)
> 	at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2253)
> 	at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1466)
> 	at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1593)
> 	at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:2924)
> 	at com.sleepycat.je.Cursor.retrieveNextNoDups(Cursor.java:2801)
> 	at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:2775)
> 	at com.sleepycat.je.Cursor.getNext(Cursor.java:1128)
> 	at org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread.sendBatch(FlumePersistentManager.java:568)
> 	at org.apache.logging.log4j.flume.appender.FlumePersistentManager$WriterThread.run(FlumePersistentManager.java:473)
> 2013-08-20 22:40:56,947 -0700 level=INFO  class=STDOUT       2ba4851d-0a24-11e3-9b42-005056b5071b       2013-08-20 22:40:56,946 ERROR An exception occurred processing Appender flume org.apache.logging.log4j.LoggingException: Unable to record event
> 	at org.apache.logging.log4j.flume.appender.FlumePersistentManager.send(FlumePersistentManager.java:172)
> 	at org.apache.logging.log4j.flume.appender.FlumeAppender.append(FlumeAppender.java:102)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:92)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:426)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:407)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:368)
> 	at org.apache.logging.log4j.core.Logger.log(Logger.java:110)
> 	at org.apache.logging.log4j.spi.AbstractLoggerWrapper.log(AbstractLoggerWrapper.java:55)
> 	at org.apache.logging.log4j.EventLogger.logEvent(EventLogger.java:56)
> 	at com.intuit.ifs.globallogging.dto.LogEventFactory$AuditProxy.invoke(LogEventFactory.java:242)
> 	at $Proxy161.logEvent(Unknown Source)
> 	at com.intuit.ifs.globallogging.fakeapp.LoggingController.startLogging(LoggingController.java:157)
> 	at sun.reflect.GeneratedMethodAccessor179.invoke(Unknown Source)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:436)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:424)
> 	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
> 	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
> 	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
> 	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
> 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> 	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
> 	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> 	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:383)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.internalProcess(ActiveRequestResponseCacheValve.java:74)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:47)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
> 	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
> 	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:599)
> 	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:451)
> 	at java.lang.Thread.run(Thread.java:662)
> 2013-08-20 22:40:57,559 -0700 level=INFO  class=STDOUT       2be29f90-0a24-11e3-9b42-005056b5071b       2013-08-20 22:40:57,557 ERROR An exception occurred processing Appender flume org.apache.logging.log4j.LoggingException: Unable to record event
> 	at org.apache.logging.log4j.flume.appender.FlumePersistentManager.send(FlumePersistentManager.java:172)
> 	at org.apache.logging.log4j.flume.appender.FlumeAppender.append(FlumeAppender.java:102)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:92)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:426)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:407)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:368)
> 	at org.apache.logging.log4j.core.Logger.log(Logger.java:110)
> 	at org.apache.logging.log4j.spi.AbstractLoggerWrapper.log(AbstractLoggerWrapper.java:55)
> 	at org.apache.logging.log4j.EventLogger.logEvent(EventLogger.java:56)
> 	at com.intuit.ifs.globallogging.dto.LogEventFactory$AuditProxy.invoke(LogEventFactory.java:242)
> 	at $Proxy199.logEvent(Unknown Source)
> 	at com.intuit.ifs.globallogging.fakeapp.LoggingController.startLogging(LoggingController.java:157)
> 	at sun.reflect.GeneratedMethodAccessor179.invoke(Unknown Source)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:436)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:424)
> 	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
> 	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
> 	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
> 	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
> 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> 	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
> 	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> 	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:383)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.internalProcess(ActiveRequestResponseCacheValve.java:74)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:47)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
> 	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
> 	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:599)
> 	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:451)
> 	at java.lang.Thread.run(Thread.java:662)
> 2013-08-20 22:40:58,641 -0700 level=INFO  class=STDOUT       3060d4b8-0a24-11e3-9b42-005056b5071b       2013-08-20 22:40:58,639 ERROR An exception occurred processing Appender flume org.apache.logging.log4j.LoggingException: Unable to record event
> 	at org.apache.logging.log4j.flume.appender.FlumePersistentManager.send(FlumePersistentManager.java:172)
> 	at org.apache.logging.log4j.flume.appender.FlumeAppender.append(FlumeAppender.java:102)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:92)
> 	at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:426)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:407)
> 	at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:368)
> 	at org.apache.logging.log4j.core.Logger.log(Logger.java:110)
> 	at org.apache.logging.log4j.spi.AbstractLoggerWrapper.log(AbstractLoggerWrapper.java:55)
> 	at org.apache.logging.log4j.EventLogger.logEvent(EventLogger.java:56)
> 	at com.intuit.ifs.globallogging.dto.LogEventFactory$AuditProxy.invoke(LogEventFactory.java:242)
> 	at $Proxy162.logEvent(Unknown Source)
> 	at com.intuit.ifs.globallogging.fakeapp.LoggingController.startLogging(LoggingController.java:157)
> 	at sun.reflect.GeneratedMethodAccessor179.invoke(Unknown Source)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> 	at java.lang.reflect.Method.invoke(Method.java:597)
> 	at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:436)
> 	at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:424)
> 	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
> 	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
> 	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
> 	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
> 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> 	at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183)
> 	at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
> 	at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> 	at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:383)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.internalProcess(ActiveRequestResponseCacheValve.java:74)
> 	at org.jboss.web.tomcat.service.request.ActiveRequestResponseCacheValve.invoke(ActiveRequestResponseCacheValve.java:47)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
> 	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
> 	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:599)
> 	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:451)
> 	at java.lang.Thread.run(Thread.java:662)



--
This message was sent by Atlassian JIRA
(v6.2#6252)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org