scalar-labs/btm

Getting this error suddenly in one of tomcat instance

vka255 opened this issue · 5 comments

I am not sure what caused below issue. I have two tomcat instances with the same configuration. but I am only seeing below issue in one of the instance.

org.springframework.transaction.CannotCreateTransactionException: JTA failure on begin; nested exception is bitronix.tm.internal.BitronixSystemException: error logging status
at org.springframework.transaction.jta.JtaTransactionManager.doBegin(JtaTransactionManager.java:845)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:427)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:276)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
at com.sun.proxy.$Proxy331.processPayment(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:817)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:731)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:968)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:870)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:844)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:121)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:120)
at org.springframework.boot.context.web.ErrorPageFilter.access$000(ErrorPageFilter.java:61)
at org.springframework.boot.context.web.ErrorPageFilter$1.doFilterInternal(ErrorPageFilter.java:95)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.springframework.boot.context.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:113)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:516)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1086)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:659)
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1558)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1515)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:724)
Caused by: bitronix.tm.internal.BitronixSystemException: error logging status
at bitronix.tm.BitronixTransaction.setStatus(BitronixTransaction.java:400)
at bitronix.tm.BitronixTransaction.setStatus(BitronixTransaction.java:379)
at bitronix.tm.BitronixTransaction.setActive(BitronixTransaction.java:367)
at bitronix.tm.BitronixTransactionManager.begin(BitronixTransactionManager.java:126)
at org.springframework.transaction.jta.JtaTransactionManager.doJtaBegin(JtaTransactionManager.java:875)
at org.springframework.transaction.jta.JtaTransactionManager.doBegin(JtaTransactionManager.java:832)
... 70 more
Caused by: bitronix.tm.journal.CorruptedTransactionLogException: corrupted log found at position 1246411 (no record terminator found)
at bitronix.tm.journal.TransactionLogCursor.readLog(TransactionLogCursor.java:102)
at bitronix.tm.journal.TransactionLogCursor.readLog(TransactionLogCursor.java:67)
at bitronix.tm.journal.DiskJournal.collectDanglingRecords(DiskJournal.java:363)
at bitronix.tm.journal.DiskJournal.copyDanglingRecords(DiskJournal.java:337)
at bitronix.tm.journal.DiskJournal.swapJournalFiles(DiskJournal.java:300)
at bitronix.tm.journal.DiskJournal.log(DiskJournal.java:101)
at bitronix.tm.BitronixTransaction.setStatus(BitronixTransaction.java:389)

I can only think of two reasons that can cause logs to corrupt themselves:

  1. Have two instances of BTM use the exact same log files. Normally this is prevented by the use of file locks, but there are way around that, like storing the files on NFS. Don't do that: each JVM must have its unique pair of log files, and they should be on a locally-attached disk.

  2. Hardware failure. It's way more common that most people think, and unless you tell me that your files are sitting on ZFS and the latter isn't reporting any error this can never be ruled out.

I just deleted the btm1.btm and btm2.btm files under work folder of tomcat instance and then my problem seems to be resolved, I am not sure if this is the right way to do?

You've just thrown your atomicity out the window by doing that. Those files are as critical as your data itself, you should store them on a reliable and backed up disk.

The BTM jar does contain a swing UI you can use to analyse the contents of the log files, maybe you could start with that?

I dint knew that the BTM jar has swing UI to analyse the contents of the log files, Thats great, How can I access that?

Your best starting point is to read the code of this class: https://github.com/bitronix/btm/blob/master/btm/src/main/java/bitronix/tm/gui/Console.java

This is a quick an dirty tool I wrote to help me analyze the raw contents of the log files, and it's very bare bones: don't expect a nice polished tool that will do some magic to give you some precise answer but rather a clunky one that will point you to where in the files is the corruption. It's then up to you to understand the format and other implementation details (there are quite some comments in the source describing that) to try to figure out what happened.

It's tedious but rewarding once you know your way.