Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-12738

Improve logging of transaction errors

This issue belongs to an archived project. You can view it, but you can't modify it. Learn more

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Obsolete
    • Icon: Major Major
    • None
    • 12.0.1.Final
    • Core
    • None
    • Undefined

      When useSynchronization=true and a prepare command fails, 3 ERROR and 3 WARN messages are logged:

      10:49:45,394 ERROR (jgroups-7,Test-NodeD:[]) [InvocationContextInterceptor] ISPN000136: Error executing command PrepareCommand on Cache 'defaultcache', writing keys []
      org.infinispan.commons.CacheListenerException: ISPN000280: Caught exception [java.lang.IllegalArgumentException] while invoking method [public void org.infinispan.notifications.cachelistener.ListenerExceptionWithSynchronizationTest$ErrorInducingListener.entryCreated(org.infinispan.notifications.cachelistener.event.CacheEntryEvent) throws java.lang.Exception] on listener instance: org.infinispan.notifications.cachelistener.ListenerExceptionWithSynchronizationTest$ErrorInducingListener@17a626ea
      
      10:49:45,399 WARN  (jgroups-7,Test-NodeD:[]) [CLUSTER] ISPN000071: Caught exception when handling command PrepareCommand {modifications=[PutKeyValueCommand{key=k0-testPostOpExceptionListenerOnCreate, value=v0-testPostOpExceptionListenerOnCreate, flags=[], commandInvocationId=CommandInvocation:local:0, putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedExpirableMetadata{version=null, lifespan=-1, maxIdle=-1}, successful=true, topologyId=17}], onePhaseCommit=true, retried=false, gtx=GlobalTransaction{id=1, addr=Test-NodeA, remote=true, xid=null, internalId=-1}, cacheName='defaultcache', topologyId=17}
      org.infinispan.commons.CacheListenerException: ISPN000280: Caught exception [java.lang.IllegalArgumentException] while invoking method [public void org.infinispan.notifications.cachelistener.ListenerExceptionWithSynchronizationTest$ErrorInducingListener.entryCreated(org.infinispan.notifications.cachelistener.event.CacheEntryEvent) throws java.lang.Exception] on listener instance: org.infinispan.notifications.cachelistener.ListenerExceptionWithSynchronizationTest$ErrorInducingListener@17a626ea
      
      10:49:45,405 ERROR (jgroups-5,Test-NodeA:[]) [InvocationContextInterceptor] ISPN000136: Error executing command PrepareCommand on Cache 'defaultcache', writing keys [k0-testPostOpExceptionListenerOnCreate]
      org.infinispan.remoting.RemoteException: ISPN000217: Received exception from Test-NodeD, see cause for remote stack trace
      
      10:49:45,406 ERROR (jgroups-5,Test-NodeA:[]) [TransactionCoordinator] ISPN000097: Error while processing a prepare in a single-phase transaction
      org.infinispan.remoting.RemoteException: ISPN000217: Received exception from Test-NodeD, see cause for remote stack trace
      
      10:49:48,466 WARN  (testng-Test:[]) [jta] ARJUNA016029: SynchronizationImple.afterCompletion - failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=[Test-NodeE, Test-NodeD], isMarkedForRollback=false, lockedKeys=[], backupKeyLocks=[], topologyId=17, stateTransferFlag=null} org.infinispan.transaction.synchronization.SyncLocalTransaction@1} org.infinispan.transaction.synchronization.SynchronizationAdapter@20 with exception
      java.util.concurrent.CompletionException: org.infinispan.commons.CacheException: Could not commit.
      
      10:49:48,468 WARN  (testng-Test:[]) [arjuna] ARJUNA012127: TwoPhaseCoordinator.afterCompletion - returned failure for SynchronizationImple< 0:ffff7f000001:9b93:602cd8a5:1, SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=[Test-NodeE, Test-NodeD], isMarkedForRollback=false, lockedKeys=[], backupKeyLocks=[], topologyId=17, stateTransferFlag=null} org.infinispan.transaction.synchronization.SyncLocalTransaction@1} org.infinispan.transaction.synchronization.SynchronizationAdapter@20 >
      ~[classes/:?]
      

      Two of the messages are from Arjuna, but the contents are still determined by SynchronizationAdapter.toString(), and we could even eliminate them by catching the exception in SynchronizationAdapter.afterCompletion().

      None of the ERROR messages include the global transaction id, and the InvocationContextInterceptor ERROR message on the remote node doesn't even include the affected keys. Instead we get trace-level details about the modifications in the transaction, and the identity hash codes of various internal objects.

      Other transaction configurations need to be checked as well: XA vs. NON_XA, 1PC vs. 2PC.

              Unassigned Unassigned
              dberinde@redhat.com Dan Berindei (Inactive)
              Archiver:
              rhn-support-adongare Amol Dongare

                Created:
                Updated:
                Resolved:
                Archived: