Debugging Transaction is not Active

Problems like this happen occasionally and are quite bedeviling.

Caused by: java.lang.RuntimeException: CONTAINER:atg.repository.RepositoryException; SOURCE:org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >)
    at atg.adapter.gsa.GSAItemDescriptor.loadProperty(GSAItemDescriptor.java:5479)
    at atg.adapter.gsa.GSAItem.getPersistentPropertyValue(GSAItem.java:1101)
    at atg.adapter.gsa.GSAItem.getPropertyValue(GSAItem.java:994)
    at atg.adapter.gsa.GSAItem.getPropertyValue(GSAItem.java:1272)
    at atg.repository.RepositoryItemImpl.getPropertyValue(RepositoryItemImpl.java:128)
    at atg.commerce.order.processor.ProcLoadHandlingInstructionObjects.runProcess(ProcLoadHandlingInstructionObjects.java:183)
    at atg.service.pipeline.PipelineLink.runProcess(PipelineLink.java:233)
    at atg.service.pipeline.PipelineChain.runProcess(PipelineChain.java:343)
    ... 17 more
Caused by: CONTAINER:atg.repository.RepositoryException; SOURCE:org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >)
    at atg.adapter.gsa.GSAItemDescriptor.loadProperties(GSAItemDescriptor.java:5431)
    at atg.adapter.gsa.GSAItemDescriptor.loadProperty(GSAItemDescriptor.java:5471)
    ... 24 more
Caused by: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >)
    at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:96)
    at atg.service.jdbc.WatcherDataSource.getConnection(WatcherDataSource.java:801)
    at atg.service.jdbc.WatcherDataSource.getConnection(WatcherDataSource.java:782)
    at atg.adapter.gsa.GSATransaction.getConnection(GSATransaction.java:744)
    at atg.adapter.gsa.GSAItemDescriptor.getConnection(GSAItemDescriptor.java:2365)
    at atg.adapter.gsa.GSAItemDescriptor.loadProperties(GSAItemDescriptor.java:5345)
    ... 25 more
Caused by: javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:c525:503e32fb:2f2c status: ActionStatus.ABORT_ONLY >
    at org.jboss.resource.connectionmanager.TxConnectionManager.getManagedConnection(TxConnectionManager.java:319)
    at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:403)
    at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:850)
    at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:90)
    ... 30 more

I tweeted about issues like this over two years ago.

As I said in the tweet this almost always is not a transaction issue but actually an application issue. The tweet references an excellent article Transaction is not active: tx=TransactionImple < ac, BasicAction in which the author found in his case that the problem was a NullPointerException which caused the transaction to end.

Today I had to debug this issue again. First I checked the transaction in ProcLoadHandlingInstructionObjects before it called getPropertyValue on the shipping group repository item.

GSAItem item = (GSAItem) sgMutItem;
ItemTransactionState state = item.getItemTransactionState(false);
logDebug("state=" + state.mGSATransaction);

I saw in the logs that the status of the transaction was ActionStatus.ABORT_ONLY which meant the transaction was already aborted before getting the property value from the repository which is why the Transaction is not active exception happened.

Next I checked the transaction at the beginning of ProcLoadHandlingInstructionObjects using the order repository item.

GSAItem item = (GSAItem) orderItem;
ItemTransactionState state = item.getItemTransactionState(false);
logDebug("state=" + state.mGSATransaction);

When I confirmed that the status of the transaction was ActionStatus.ABORT_ONLY at the beginning of the processor I went backwards through the pipeline checking all the processors in the same way.

After doing that and confirming the transaction was ActionStatus.ABORT_ONLY at the beginning of the pipeline process I began checking the code that called the pipeline using code like this.

GSAItem orderItem = (GSAItem) order.getRepositoryItem();
ItemTransactionState state = orderItem.getItemTransactionState(false);
try {
  int status = state.mGSATransaction.getTransaction().getStatus();
  if (status == Status.STATUS_MARKED_ROLLBACK) {
    logError("Oh-oh, marked for rollback.");
  }
} catch (SystemException exc) {}

I finally found the problem was that in a previous call to another pipeline an error had occurred and the transaction was marked for rollback. However the code did not check the result of the pipeline call and had continued.

The moral of the story is always check your return values and don’t go down the rat hole of believing it’s a transaction issue.

Alice in front of the rabbit hole

How to Debug an InvalidVersionException from Updating an ATG Order

I thought I saw a puddy cat.... on Flickr

If you ever update an order outside of a transaction then the next time you update it within a transaction you will get the infamous, dreaded InvalidVersionException.

WARN  atg.commerce.order.ShoppingCartModifier
atg.commerce.order.InvalidVersionException: This order (o3830002) is out of date. Changes have been made to the order and the operation should be resubmitted. Order version 333, Repository item version 334.
   at atg.commerce.order.OrderManager.updateOrder(OrderManager.java:2557)

For example this could happen if you update your order in your JSP page.

<dsp:setvalue bean=”order.foo” value=”bar” />

To fix this problem you must always make sure to update an order within a transaction like this.

Transaction tr = null;
try {
  tr = ensureTransaction();
  synchronized (getOrder()) {
    getOrder().setFoo("bar");
    try {
      getOrderManager().updateOrder(order);
    }
    catch (Exception exc) {
      processException(exc, MSG_ERROR_UPDATE_ORDER, pRequest, pResponse);
    }
  }
}
finally {
  if (tr != null) commitTransaction(tr);
}

In some cases you might find a method is called within a transaction by another method and in other cases it is not.

public boolean handleFoo(DynamoHttpServletRequest req, DynamoHttpServletResponse res) {
  Transaction tr = null;
  try {
    tr = ensureTransaction();
    synchronized (getOrder()) {
      setFoo("bar");
      try {
        getOrderManager().updateOrder(order);
      }
      catch (Exception exc) {
        processException(exc, MSG_ERROR_UPDATE_ORDER, pRequest, pResponse);
      }
    }
    return checkFormRedirect(getSuccessUrl(), getErrorUrl(), req, res);
  }
  finally {
    if (tr != null) commitTransaction(tr);
  }
}

public void setFoo(String foo) {
  getOrder().setFoo(foo);
}

In the above example the handleFoo method properly updates the order within the transaction.  However calling the setFoo method directly will cause a problem since the order is not updated within a transaction.  To fix this you use the same pattern again to ensure the order is updated within a transaction.  It is okay to do this more than once during a request.

To debug this problem you can use Eclipse to make sure that wherever you update an order is always within a transaction. You can use the debugger to find which methods are called and/or you can use the call hierarchy to find out how methods are called.

Another way to help debug this is adding JSP code similar to the one I list below. It outputs the version of the order that the form handler has and the version that is in the repository.  If there is a difference then you know that the action you took before at some point updated the order outside of a transaction.

<dspel:getvalueof bean="ShoppingCartModifier.order.id" var="orderId" />
FORM HANDLER ORDER ID: ${orderId}<br/>
FORM HANDLER ORDER VERSION: <dsp:valueof bean="ShoppingCartModifier.order.version" /><br/>
<dsp:droplet name="/atg/dynamo/droplet/RQLQueryForEach">
  <dsp:param name="queryRQL" value="ID IN { \"${orderId}\" }"/>
  <dsp:param name="repository" value="/atg/commerce/order/OrderRepository"/>
  <dsp:param name="itemDescriptor" value="order"/>
  <dsp:oparam name="output">
    REPOSITORY ORDER VERSION: <dsp:valueof param="element.version"/><br/>
  </dsp:oparam>
</dsp:droplet>

For further reading please see Nabble – ATG Dynamo – Commerce Assist Returns and the Transaction Management section in the ATG Programming Guide.