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 "Kamal Bahadur (JIRA)" <ji...@apache.org> on 2014/09/09 00:02:30 UTC
[jira] [Reopened] (LOG4J2-391) Flume appender crashes when lock
timeout occurs
[ https://issues.apache.org/jira/browse/LOG4J2-391?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Kamal Bahadur reopened LOG4J2-391:
----------------------------------
LockTimeoutException has not been handled for batch. In sendBatch method of FlumePersistentManager.WriterThread, the methods cursor.getFirst and cursor.getNext are not catching LockConflictException. We should catch the LockConflictException and include the retry logic just like we implemented in send method.
> 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.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org