Avoka Blog: Adobe LiveCycle

February 10, 2009

How to read a LiveCycle stack trace

Filed under: Application Servers, LiveCycle, LiveCycle Administration — htreisman @ 11:01 am

When an error occurs in LiveCycle, you’ll usually get some sort of stack trace in the application server log files. It’s very important to be able to read and understand the stack trace, because this is your best opportunity to find out what went wrong.

A typical stack trace often looks quite daunting at first, something like this: (Don’t try to read it, just scroll down…)

javax.ejb.TransactionRolledbackLocalException: Got error 139 from storage engine; CausedByException is:
Got error 139 from storage engine
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:247)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:415)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:88 )
at $Proxy180.writeObject(Unknown Source)
at com.adobe.pof.omapi.POFObjectManagerLocalEJBAdapter.writeObject(POFObjectManagerLocalEJBAdapter.java:135)
at com.adobe.workflow.datatype.POFVariableContainer.write(POFVariableContainer.java:133)
at com.adobe.workflow.pat.service.PATExecutionContextImpl.writeResults(PATExecutionContextImpl.java:108 )
at com.adobe.workflow.engine.ProcessEngineBMTBean.continueBranchAtAction(ProcessEngineBMTBean.java:2944)
at com.adobe.workflow.engine.ProcessEngineBMTBean.asyncContinueBranchCommand(ProcessEngineBMTBean.java:2392)
at sun.reflect.GeneratedMethodAccessor528.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:214)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
at org.jboss.webservice.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:54)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:48 )
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:158 )
at org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:154)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:415)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:88 )
at $Proxy200.asyncContinueBranchCommand(Unknown Source)
at com.adobe.workflow.engine.ProcessCommandControllerBean.doOnMessage(ProcessCommandControllerBean.java:133)
at com.adobe.workflow.engine.ProcessCommandControllerBean.onMessage(ProcessCommandControllerBean.java:94)
at sun.reflect.GeneratedMethodAccessor439.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
at org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:475)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:101)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
at org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:94)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.MessageDrivenContainer.internalInvoke(MessageDrivenContainer.java:389)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:1077)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1379)
at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:256)
at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:904)
at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:160)
at org.jboss.mq.SpySession.run(SpySession.java:333)
at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748 )
at java.lang.Thread.run(Thread.java:595)

Note that there’s a second separate exception here. This line doesn’t start with “at”. This is usually the “caused by” part of the same exception.

java.sql.SQLException: Got error 139 from storage engine
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2928 )
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1571)
at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1124)
at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:676)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1166)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1082)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1067)
at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:81)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:227)
at com.adobe.pof.adapter.JDBCAdapter.updateObject(JDBCAdapter.java:519)
at com.adobe.pof.adapter.JDBCAdapter.updateObject(JDBCAdapter.java:442)
at com.adobe.pof.omapi.POFObjectManagerImpl.writeObject(POFObjectManagerImpl.java:254)
at com.adobe.pof.omapi.POFObjectManagerRemoteBean.writeObject(POFObjectManagerRemoteBean.java:271)
at sun.reflect.GeneratedMethodAccessor381.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:214)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:154)
at org.jboss.webservice.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:54)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:48 )
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:415)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:88 )
at $Proxy180.writeObject(Unknown Source)
at com.adobe.pof.omapi.POFObjectManagerLocalEJBAdapter.writeObject(POFObjectManagerLocalEJBAdapter.java:135)
at com.adobe.workflow.datatype.POFVariableContainer.write(POFVariableContainer.java:133)
at com.adobe.workflow.pat.service.PATExecutionContextImpl.writeResults(PATExecutionContextImpl.java:108 )
at com.adobe.workflow.engine.ProcessEngineBMTBean.continueBranchAtAction(ProcessEngineBMTBean.java:2944)
at com.adobe.workflow.engine.ProcessEngineBMTBean.asyncContinueBranchCommand(ProcessEngineBMTBean.java:2392)
at sun.reflect.GeneratedMethodAccessor528.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:214)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
at org.jboss.webservice.server.ServiceEndpointInterceptor.invoke(ServiceEndpointInterceptor.java:54)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:48 )
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
at org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:158 )
at org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:154)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:153)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:624)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:415)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:88 )
at $Proxy200.asyncContinueBranchCommand(Unknown Source)
at com.adobe.workflow.engine.ProcessCommandControllerBean.doOnMessage(ProcessCommandControllerBean.java:133)
at com.adobe.workflow.engine.ProcessCommandControllerBean.onMessage(ProcessCommandControllerBean.java:94)
at sun.reflect.GeneratedMethodAccessor439.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.invocation.Invocation.performCall(Invocation.java:345)
at org.jboss.ejb.MessageDrivenContainer$ContainerInterceptor.invoke(MessageDrivenContainer.java:475)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:149)
at org.jboss.ejb.plugins.MessageDrivenInstanceInterceptor.invoke(MessageDrivenInstanceInterceptor.java:101)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:106)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:335)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:166)
at org.jboss.ejb.plugins.RunAsSecurityInterceptor.invoke(RunAsSecurityInterceptor.java:94)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:192)
at org.jboss.ejb.MessageDrivenContainer.internalInvoke(MessageDrivenContainer.java:389)
at org.jboss.ejb.Container.invoke(Container.java:873)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:1077)
at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1379)
at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:256)
at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:904)
at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:160)
at org.jboss.mq.SpySession.run(SpySession.java:333)
at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748 )
at java.lang.Thread.run(Thread.java:595)

Usually, if there are two exceptions, the second one, often preceded by “Caused by” gives you more detailed information. So I’m just going to ignore the first exception for now, halving the amount of detail I need to worry about.

Then I typically ignore anything that doesn’t belong to Adobe or the component implementation (i.e. All the “jboss” stuff)

Now that I’ve reduced it down to a manageable amount, I start from the bottom up, trying to work out what’s going on when the error occurred. This helps us both to understand, diagnose, and potentially reproduce the problem. The very top line usually contains the actual error. See annotations below, working from the bottom up:

java.sql.SQLException: Got error 139 from storage engine

4. error 139: We got a strange error from the “storage engine”, meaning the database itself. Let’s go google that. (I’ll leave this as an exercise for the reader.)

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2928 )
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1571)
at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1124)
at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:676)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1166)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1082)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1067)

3. executeUpdate: We seem to be updating a row in the database using the mySQL JDBC driver

at com.adobe.pof.adapter.JDBCAdapter.updateObject(JDBCAdapter.java:519)
at com.adobe.pof.adapter.JDBCAdapter.updateObject(JDBCAdapter.java:442)
at com.adobe.pof.omapi.POFObjectManagerImpl.writeObject(POFObjectManagerImpl.java:254)
at com.adobe.pof.omapi.POFObjectManagerRemoteBean.writeObject(POFObjectManagerRemoteBean.java:271)
at $Proxy180.writeObject(Unknown Source)
at com.adobe.pof.omapi.POFObjectManagerLocalEJBAdapter.writeObject(POFObjectManagerLocalEJBAdapter.java:135)
at com.adobe.workflow.datatype.POFVariableContainer.write(POFVariableContainer.java:133)
at com.adobe.workflow.pat.service.PATExecutionContextImpl.writeResults(PATExecutionContextImpl.java:108 )

2. writeResults: Yup, the engine is now trying to write the results that the component returned back into the process variables

at com.adobe.workflow.engine.ProcessEngineBMTBean.continueBranchAtAction(ProcessEngineBMTBean.java:2944)

1. continueBranchAtAction: a particular step is being “continued” – probably means that the component itself has already been executed, now we need to “continue” it to completion

at com.adobe.workflow.engine.ProcessEngineBMTBean.asyncContinueBranchCommand(ProcessEngineBMTBean.java:2392)

We still don’t know exactly why this failure occurred, but we have a much better idea of where and why it happened, and we’re well placed to diagnose further.

Obviously, every stack trace is different, but hopefully this gives you a technique that will help you to understand what went wrong, and fix it.

Advertisements

3 Comments »

  1. It’s a thing I need. Thank you!

    Comment by Andrew — February 10, 2009 @ 4:25 pm

  2. Howard, does LC write to its own log or does it write only to systemOut.log and systemErr.log? Can we direct LC to write to it’s own log and keep the systemout and systemerr logs reserved for just websphere?

    Comment by Elaine Schmitz — February 13, 2009 @ 3:52 am

    • Hi Elaine
      I’m not an expert on WebSphere, but I’ll give you a couple of things you may want to try.
      LiveCycle uses the app server logging sub-system, which in JBoss is Log4J, and is controlled by a configuration file. WS probably uses something similar.
      C:\Adobe\LiveCycle8.2\jboss\server\all\conf\log4j.xml
      I haven’t tried, but you can probably configure this to set up a second log file in addition to the basic one, and redirect only Livecycle related messages to it.

      Another option is to use an enhanced log file viewer and filter, like BareMetal Software’s BareTailPro.

      Hope this helps…
      howard

      Comment by htreisman — February 21, 2009 @ 4:19 pm


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Create a free website or blog at WordPress.com.

%d bloggers like this: