Logging improvements from branches/2.1 rev 984259 

git-svn-id: https://svn.apache.org/repos/asf/geronimo/components/txmanager/trunk@984469 13f79535-47bb-0310-9956-ffa450edef68
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolConnectionInterceptor.java
index 73ac5c1..decc924 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolConnectionInterceptor.java
@@ -44,7 +44,7 @@
     protected Semaphore permits;
     protected int blockingTimeoutMilliseconds;
     protected int connectionCount = 0;
-    private long idleTimeoutMilliseconds;
+    protected long idleTimeoutMilliseconds;
     private IdleReleaser idleReleaser;
     protected Timer timer = PoolIdleReleaserTimer.getTimer();
     protected int maxSize = 0;
@@ -68,7 +68,7 @@
     public void getConnection(ConnectionInfo connectionInfo) throws ResourceException {
         if (connectionInfo.getManagedConnectionInfo().getManagedConnection() != null) {
             if (log.isTraceEnabled()) {
-                log.trace("using already assigned connection " + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to pool " + this);
+                log.trace("supplying already assigned connection from pool " + this + " " + connectionInfo);
             }
             return;
         }
@@ -103,7 +103,7 @@
     public void returnConnection(ConnectionInfo connectionInfo,
                                  ConnectionReturnAction connectionReturnAction) {
         if (log.isTraceEnabled()) {
-            log.trace("returning connection " + connectionInfo.getConnectionHandle() + " for MCI " + connectionInfo.getManagedConnectionInfo() + " to pool " + this);
+            log.trace("returning connection " + connectionInfo.getConnectionHandle() + " for MCI " + connectionInfo.getManagedConnectionInfo() + " and MC " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to pool " + this);
         }
 
         // not strictly synchronized with destroy(), but pooled operations in internalReturn() are...
@@ -120,7 +120,9 @@
         try {
             ManagedConnectionInfo mci = connectionInfo.getManagedConnectionInfo();
             if (connectionReturnAction == ConnectionReturnAction.RETURN_HANDLE && mci.hasConnectionHandles()) {
-                log.warn("Return request at pool with connection handles! " + connectionInfo.getConnectionHandle() + " for MCI " + connectionInfo.getManagedConnectionInfo() + " and MC " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to pool " + this, new Exception("Stack trace"));
+                if (log.isTraceEnabled()) {
+                    log.trace("Return request at pool with connection handles! " + connectionInfo.getConnectionHandle() + " for MCI " + connectionInfo.getManagedConnectionInfo() + " and MC " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to pool " + this, new Exception("Stack trace"));
+                }
                 return;
             }
 
@@ -177,6 +179,9 @@
             }
         }
         //we must destroy connection.
+        if (log.isTraceEnabled()) {
+            log.trace("Discarding connection in pool " + this + " " + connectionInfo);
+        }
         next.returnConnection(connectionInfo, connectionReturnAction);
         connectionCount--;
         return releasePermit;
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionHandleInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionHandleInterceptor.java
index fbbf063..232efce 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionHandleInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionHandleInterceptor.java
@@ -74,4 +74,13 @@
     public void destroy() {
         next.destroy();
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("\n");
+        if (next == null) {
+            s.append("<end>");
+        } else {
+            next.info(s);
+        }
+    }
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInfo.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInfo.java
index bebca51..6153cff 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInfo.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInfo.java
@@ -123,6 +123,11 @@
         return trace;
     }
 
-
-
+    @Override
+    public String toString() {
+        StringBuilder b = new StringBuilder();
+        b.append("handle: ").append(connection);
+        b.append(mci);
+        return b.toString();
+    }
 } // ConnectionInfo
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInterceptor.java
index 99ac177..66f791a 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionInterceptor.java
@@ -36,4 +36,6 @@
 
     void destroy();
 
+    void info(StringBuilder s);
+
 } // ConnectionInterceptor
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionTrackingInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionTrackingInterceptor.java
index 0cee78d..607855f 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionTrackingInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ConnectionTrackingInterceptor.java
@@ -123,4 +123,14 @@
             }
         }
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[key=").append(key).append("]\n");
+        if (next == null) {
+            s.append("<end>");
+        } else {
+            next.info(s);
+        }
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/GenericConnectionManager.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/GenericConnectionManager.java
index fddcde0..6c8bc63 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/GenericConnectionManager.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/GenericConnectionManager.java
@@ -38,7 +38,7 @@
  * @version $Rev$ $Date$
  */
 public class GenericConnectionManager extends AbstractConnectionManager {
-    protected static final Logger log = LoggerFactory.getLogger(AbstractSinglePoolConnectionInterceptor.class);
+    protected static final Logger log = LoggerFactory.getLogger(GenericConnectionManager.class);
 
     //default constructor to support externalizable subclasses
     public GenericConnectionManager() {
@@ -155,6 +155,11 @@
             }
             tail.setStack(stack);
             this.stack = stack;
+            if (log.isDebugEnabled()) {
+                StringBuilder s = new StringBuilder("ConnectionManager Interceptor stack;\n");
+                stack.info(s);
+                log.debug(s.toString());
+            }
         }
 
         public ConnectionInterceptor getStack() {
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/LocalXAResourceInsertionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/LocalXAResourceInsertionInterceptor.java
index 6abc484..b6b8184 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/LocalXAResourceInsertionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/LocalXAResourceInsertionInterceptor.java
@@ -53,4 +53,14 @@
     public void destroy() {
         next.destroy();        
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[name=").append(name).append("]\n");
+        if (next == null) {
+            s.append("<end>");
+        } else {
+            next.info(s);
+        }
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MCFConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MCFConnectionInterceptor.java
index 30ea695..a7dec72 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MCFConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MCFConnectionInterceptor.java
@@ -82,4 +82,9 @@
         this.stack = stack;
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[stack=").append(stack).append("]\n");
+        s.append("<end>");
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MultiPoolConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MultiPoolConnectionInterceptor.java
index 3534f73..0408593 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MultiPoolConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/MultiPoolConnectionInterceptor.java
@@ -166,6 +166,12 @@
         }
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[useSubject=").append(useSubject).append(",useCRI=").append(useCRI).append(",pool count=").append(pools.size()).append("]\n");
+        next.info(s);
+    }
+
+
     static class SubjectCRIKey {
         private final Subject subject;
         private final ConnectionRequestInfo cri;
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolConnectionInterceptor.java
index 9a9257e..bcd44a3 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolConnectionInterceptor.java
@@ -69,7 +69,7 @@
                 next.getConnection(connectionInfo);
                 connectionCount++;
                 if (log.isTraceEnabled()) {
-                    log.trace("Supplying new connection MCI: " + connectionInfo.getManagedConnectionInfo() + " from pool: " + this);
+                    log.trace("Supplying new connection MCI: " + connectionInfo.getManagedConnectionInfo() + " MC: " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " from pool: " + this);
                 }
                 return;
             } else {
@@ -81,7 +81,7 @@
             if (selectOneAssumeMatch) {
                 connectionInfo.setManagedConnectionInfo(newMCI);
                 if (log.isTraceEnabled()) {
-                    log.trace("Supplying pooled connection without checking matching MCI: " + connectionInfo.getManagedConnectionInfo() + " from pool: " + this);
+                    log.trace("Supplying pooled connection without checking matching MCI: " + connectionInfo.getManagedConnectionInfo() + " MC: " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " from pool: " + this);
                 }
                 return;
             }
@@ -168,4 +168,14 @@
         }
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName());
+        s.append("[minSize=").append(minSize);
+        s.append(",maxSize=").append(maxSize);
+        s.append(",idleTimeoutMilliseconds=").append(idleTimeoutMilliseconds);
+        s.append(",blockingTimeoutMilliseconds=").append(blockingTimeoutMilliseconds);
+        s.append(".selectOneAssumeMatch=").append(selectOneAssumeMatch).append("]\n");
+        next.info(s);
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolMatchAllConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolMatchAllConnectionInterceptor.java
index 2b4c062..e683e79 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolMatchAllConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SinglePoolMatchAllConnectionInterceptor.java
@@ -67,7 +67,7 @@
                     connectionInfo.setManagedConnectionInfo(pool.get(matchedMC));
                     pool.remove(matchedMC);
                     if (log.isTraceEnabled()) {
-                        log.trace("Returning pooled connection " + connectionInfo.getManagedConnectionInfo());
+                        log.trace("Supplying existing connection from pool " + this + " " + connectionInfo);
                     }
                     if (connectionCount < minSize) {
                         timer.schedule(new FillTask(connectionInfo), 10);
@@ -78,6 +78,7 @@
             //matching failed or pool is empty
             //if pool is at maximum size, pick a cx to kill
             if (connectionCount == maxSize) {
+                log.trace("Pool is at max size but no connections match, picking one to destroy");
                 Iterator iterator = pool.entrySet().iterator();
                 ManagedConnectionInfo kill = (ManagedConnectionInfo) ((Map.Entry) iterator.next()).getValue();
                 iterator.remove();
@@ -87,7 +88,7 @@
             next.getConnection(connectionInfo);
             connectionCount++;
             if (log.isTraceEnabled()) {
-                log.trace("Returning new connection " + connectionInfo.getManagedConnectionInfo());
+                log.trace("Supplying new connection from pool " + this + " " + connectionInfo);
             }
             if (connectionCount < minSize) {
                 timer.schedule(new FillTask(connectionInfo), 10);
@@ -148,4 +149,13 @@
 
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName());
+        s.append("[minSize=").append(minSize);
+        s.append(",maxSize=").append(maxSize);
+        s.append(",idleTimeoutMilliseconds=").append(idleTimeoutMilliseconds);
+        s.append(",blockingTimeoutMilliseconds=").append(blockingTimeoutMilliseconds).append("]\n");
+        next.info(s);
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SubjectInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SubjectInterceptor.java
index ea9954c..cbb62aa 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SubjectInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/SubjectInterceptor.java
@@ -99,4 +99,9 @@
         next.destroy();
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[subjectSource=").append(subjectSource).append("]\n");
+        next.info(s);
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TCCLInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TCCLInterceptor.java
index c32f026..44d908b 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TCCLInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TCCLInterceptor.java
@@ -56,4 +56,10 @@
     public void destroy() {
         this.next.destroy();
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[classLoader=").append(classLoader).append("]\n");
+        next.info(s);
+    }
+    
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ThreadLocalCachingConnectionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ThreadLocalCachingConnectionInterceptor.java
index 295745b..bfa0b74 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ThreadLocalCachingConnectionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/ThreadLocalCachingConnectionInterceptor.java
@@ -85,4 +85,10 @@
     public void destroy() {
         next.destroy();
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[matchConnections=").append(matchConnections).append("]\n");
+        next.info(s);
+    }
+    
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionCachingInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionCachingInterceptor.java
index 62dbf13..14c6ce6 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionCachingInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionCachingInterceptor.java
@@ -65,7 +65,7 @@
         //There can be an inactive transaction context when a connection is requested in
         //Synchronization.afterCompletion().
 
-        // get the current transation and status... if there is a problem just assume there is no transaction present
+        // get the current transaction and status... if there is a problem just assume there is no transaction present
         Transaction transaction = TxUtil.getTransactionIfActive(transactionManager);
         if (transaction != null) {
             ManagedConnectionInfos managedConnectionInfos = ConnectorTransactionContext.get(transaction, this);
@@ -73,6 +73,9 @@
                 if (!managedConnectionInfos.containsUnshared(connectionInfo.getManagedConnectionInfo())) {
                     next.getConnection(connectionInfo);
                     managedConnectionInfos.addUnshared(connectionInfo.getManagedConnectionInfo());
+                    if (log.isTraceEnabled()) {
+                        log.trace("Enlisting connection already associated with handle " + infoString(connectionInfo));
+                    }
                 }
             } else {
                 ManagedConnectionInfo managedConnectionInfo = managedConnectionInfos.getShared();
@@ -83,12 +86,15 @@
                         //enlists connection
                         next.getConnection(connectionInfo);
                         managedConnectionInfos.addUnshared(previousMci);
+                        if (log.isTraceEnabled()) {
+                            log.trace("Enlisting existing connection associated with connection handle with current tx  " + infoString(connectionInfo));
+                        }
                     } else {
                         connectionInfo.setManagedConnectionInfo(managedConnectionInfo);
 
                         //return;
                         if (log.isTraceEnabled()) {
-                            log.trace("supplying connection from tx cache " + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+                            log.trace("supplying connection from tx cache  " + infoString(connectionInfo));
                         }
                     }
                 } else {
@@ -108,7 +114,7 @@
 
         if (connectionReturnAction == ConnectionReturnAction.DESTROY) {
             if (log.isTraceEnabled()) {
-                log.trace("destroying connection" + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+                log.trace("destroying connection " + infoString(connectionInfo));
             }
             next.returnConnection(connectionInfo, connectionReturnAction);
             return;
@@ -119,7 +125,7 @@
             if (transaction != null) {
                 if (TxUtil.isActive(transaction)) {
                     if (log.isTraceEnabled()) {
-                        log.trace("tx active, not returning connection" + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+                        log.trace("tx active, not returning connection  " + infoString(connectionInfo));
                     }
                     return;
                 }
@@ -128,14 +134,14 @@
                 ManagedConnectionInfos managedConnectionInfos = ConnectorTransactionContext.get(transaction, this);
                 managedConnectionInfos.remove(connectionInfo.getManagedConnectionInfo());
                 if (log.isTraceEnabled()) {
-                    log.trace("tx ended, but not removed");
+                    log.trace("tx ended, return during synchronization afterCompletion " + infoString(connectionInfo));
                 }
             }
         } catch (SystemException e) {
             //ignore
         }
         if (log.isTraceEnabled()) {
-            log.trace("tx ended, returning connection" + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+            log.trace("tx ended, returning connection " + infoString(connectionInfo));
         }
         internalReturn(connectionInfo, connectionReturnAction);
     }
@@ -143,14 +149,14 @@
     private void internalReturn(ConnectionInfo connectionInfo, ConnectionReturnAction connectionReturnAction) {
         if (connectionInfo.getManagedConnectionInfo().hasConnectionHandles()) {
             if (log.isTraceEnabled()) {
-                log.trace("not returning connection from tx cache (has handles) " + connectionInfo.getConnectionHandle() + " for managed connection " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+                log.trace("not returning connection from tx cache (has handles) " + infoString(connectionInfo));
             }
             return;
         }
         //No transaction, no handles, we return it.
         next.returnConnection(connectionInfo, connectionReturnAction);
         if (log.isTraceEnabled()) {
-            log.trace("completed return of connection through tx cache " + connectionInfo.getConnectionHandle() + " for MCI: " + connectionInfo.getManagedConnectionInfo() + " and MC " + connectionInfo.getManagedConnectionInfo().getManagedConnection() + " to tx caching interceptor " + this);
+            log.trace("completed return of connection through tx cache " + infoString(connectionInfo));
         }
     }
 
@@ -163,13 +169,13 @@
         ManagedConnectionInfo sharedMCI = managedConnectionInfos.getShared();
         if (sharedMCI != null) {
             if (log.isTraceEnabled()) {
-                log.trace("Transaction completed, attempting to return shared connection MCI: " + sharedMCI + " for managed connection " + sharedMCI.getManagedConnection() + " to tx caching interceptor " + this);
+                log.trace("Transaction completed, attempting to return shared connection MCI: " + infoString(sharedMCI));
             }
             returnHandle(sharedMCI);
         }
         for (ManagedConnectionInfo managedConnectionInfo : managedConnectionInfos.getUnshared()) {
             if (log.isTraceEnabled()) {
-                log.trace("Transaction completed, attempting to return unshared connection MCI: " + managedConnectionInfo + " for managed connection " + managedConnectionInfo.getManagedConnection() + " to tx caching interceptor " + this);
+                log.trace("Transaction completed, attempting to return unshared connection MCI: " + infoString(managedConnectionInfo));
             }
             returnHandle(managedConnectionInfo);
         }
@@ -181,6 +187,15 @@
         internalReturn(connectionInfo, ConnectionReturnAction.RETURN_HANDLE);
     }
 
+    private String infoString(Object connectionInfo) {
+        return "for tx caching interceptor " + this + " " + connectionInfo;
+    }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[transactionManager=").append(transactionManager).append("]\n");
+        next.info(s);
+    }
+    
     public static class ManagedConnectionInfos {
         private ManagedConnectionInfo shared;
         private Set<ManagedConnectionInfo> unshared = new HashSet<ManagedConnectionInfo>(1);
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionEnlistingInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionEnlistingInterceptor.java
index c0e678e..345df16 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionEnlistingInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/TransactionEnlistingInterceptor.java
@@ -23,6 +23,8 @@
 import javax.transaction.Transaction;
 import javax.transaction.TransactionManager;
 import javax.transaction.xa.XAResource;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 /**
  * TransactionEnlistingInterceptor.java
@@ -33,6 +35,7 @@
  * @version 1.0
  */
 public class TransactionEnlistingInterceptor implements ConnectionInterceptor {
+    protected static Logger log = LoggerFactory.getLogger(TransactionEnlistingInterceptor.class);
 
     private final ConnectionInterceptor next;
     private final TransactionManager transactionManager;
@@ -51,7 +54,14 @@
             Transaction transaction = TxUtil.getTransactionIfActive(transactionManager);
             if (transaction != null) {
                 XAResource xares = mci.getXAResource();
+                if (log.isTraceEnabled()) {
+                    log.trace("Enlisting connection " + connectionInfo + " with XAResource " + xares + " in transaction: " + transaction);
+                }
                 transaction.enlistResource(xares);
+            } else {
+                if (log.isTraceEnabled()) {
+                    log.trace("not enlisting connection " + connectionInfo + " with XAResource " + mci.getXAResource() + " no transaction");
+                }
             }
         } catch (SystemException e) {
             returnConnection(connectionInfo, ConnectionReturnAction.DESTROY);
@@ -82,11 +92,19 @@
             Transaction transaction = TxUtil.getTransactionIfActive(transactionManager);
             if (transaction != null) {
                 XAResource xares = mci.getXAResource();
+                if (log.isTraceEnabled()) {
+                    log.trace("Delisting connection " + connectionInfo + " with XAResource " + xares + " in transaction: " + transaction, new Exception("stack trace"));
+                }
                 transaction.delistResource(xares, XAResource.TMSUSPEND);
+            } else {
+                if (log.isTraceEnabled()) {
+                    log.trace("not delisting connection " + connectionInfo + " with XAResource " + mci.getXAResource() + " no transaction");
+                }
             }
 
         } catch (SystemException e) {
             //maybe we should warn???
+            log.info("Could not delist resource: " + connectionInfo  + " with XAResource: " + connectionInfo.getManagedConnectionInfo().getXAResource(), e);
             connectionReturnAction = ConnectionReturnAction.DESTROY;
         } catch (IllegalStateException e) {
             connectionReturnAction = ConnectionReturnAction.DESTROY;
@@ -99,4 +117,9 @@
         next.destroy();
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[transactionManager=").append(transactionManager).append("]\n");
+        next.info(s);
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/XAResourceInsertionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/XAResourceInsertionInterceptor.java
index f2f8d41..e0e3a64 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/XAResourceInsertionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/XAResourceInsertionInterceptor.java
@@ -51,4 +51,9 @@
         next.destroy();
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[name=").append(name).append("]\n");
+        next.info(s);
+    }
+
 }
diff --git a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/transactionlog/LogXAResourceInsertionInterceptor.java b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/transactionlog/LogXAResourceInsertionInterceptor.java
index a3e5850..6152712 100644
--- a/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/transactionlog/LogXAResourceInsertionInterceptor.java
+++ b/geronimo-connector/src/main/java/org/apache/geronimo/connector/outbound/transactionlog/LogXAResourceInsertionInterceptor.java
@@ -59,4 +59,14 @@
     public void destroy() {
         next.destroy();
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("[name=").append(name).append("]\n");
+        if (next == null) {
+            s.append("<end>");
+        } else {
+            next.info(s);
+        }
+    }
+
 }
diff --git a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolTest.java b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolTest.java
index eac2aae..5512b98 100644
--- a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolTest.java
+++ b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/AbstractSinglePoolTest.java
@@ -30,7 +30,7 @@
 import org.apache.geronimo.connector.mock.MockManagedConnectionFactory;
 
 /**
- * @version $Rev:$ $Date:$
+ * @version $Rev$ $Date$
  */
 public class AbstractSinglePoolTest extends TestCase {
 
@@ -268,5 +268,11 @@
         public void destroy() {
             next.destroy();
         }
+
+        public void info(StringBuilder s) {
+            s.append(getClass().getName()).append("\n");
+            next.info(s);
+        }
+
     }
 }
diff --git a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/ConnectionInterceptorTestUtils.java b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/ConnectionInterceptorTestUtils.java
index c03acbf..2bed128 100644
--- a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/ConnectionInterceptorTestUtils.java
+++ b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/ConnectionInterceptorTestUtils.java
@@ -183,4 +183,9 @@
         }
 
     }
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("\n");
+        s.append("<end>");
+    }
+
 }
diff --git a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorProxyTest.java b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorProxyTest.java
index 9a0fc8a..ec431b7 100644
--- a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorProxyTest.java
+++ b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorProxyTest.java
@@ -276,6 +276,10 @@
     public void destroy() {
     }
 
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("\n");
+    }
+
     private ConnectionInfo createConnectionInfo() {
         ConnectionInfo ci = new ConnectionInfo(mci);
         ci.setConnectionHandle(connection);
diff --git a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorTest.java b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorTest.java
index fdaa0aa..76aa906 100644
--- a/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorTest.java
+++ b/geronimo-connector/src/test/java/org/apache/geronimo/connector/outbound/connectiontracking/ConnectionTrackingCoordinatorTest.java
@@ -166,4 +166,10 @@
 
     public void destroy() {        
     }
+
+    public void info(StringBuilder s) {
+        s.append(getClass().getName()).append("\n");
+        s.append("<end>");
+    }
+
 }
diff --git a/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/log/XidImpl2.java b/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/log/XidImpl2.java
index 10cffde..a1c9578 100644
--- a/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/log/XidImpl2.java
+++ b/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/log/XidImpl2.java
@@ -53,6 +53,16 @@
         System.arraycopy(globalId, 0, buffer, HEADER_SIZE + FORMAT_SIZE, Xid.MAXGTRIDSIZE);
 
         //this.hash = hash(buffer);
+        check();
+    }
+
+    private void check() {
+        if (buffer[GLOBALID_SIZE_POS] > Xid.MAXGTRIDSIZE) {
+            throw new IllegalStateException("Global ID too large: " + buffer[GLOBALID_SIZE_POS]);
+        }
+        if (buffer[BRANCHID_SIZE_POS] > Xid.MAXBQUALSIZE) {
+            throw new IllegalStateException("Branch ID too large: " + buffer[GLOBALID_SIZE_POS]);
+        }
     }
 
     /**
@@ -71,6 +81,7 @@
         buffer[BRANCHID_SIZE_POS] = (byte) branch.length;
         System.arraycopy(branch, 0, buffer, HEADER_SIZE + FORMAT_SIZE + Xid.MAXGTRIDSIZE, Xid.MAXBQUALSIZE);
         //hash = hash(buffer);
+        check();
     }
 
     public XidImpl2(int formatId, byte[] globalId, byte[] branch) {
@@ -80,6 +91,7 @@
         buffer[BRANCHID_SIZE_POS] = (byte) branch.length;
         System.arraycopy(branch, 0, buffer, HEADER_SIZE + FORMAT_SIZE + Xid.MAXGTRIDSIZE, Xid.MAXBQUALSIZE);
         //hash = hash(buffer);
+        check();
     }
 
     private int hash(byte[] id) {
@@ -122,7 +134,7 @@
     }
 
     public String toString() {
-        StringBuffer s = new StringBuffer("[formatId=Gero,");
+        StringBuffer s = new StringBuffer("[XidImpl2:formatId=Gero,");
         s.append("globalId=");
         for (int i = FORMAT_SIZE; i < FORMAT_SIZE + Xid.MAXGTRIDSIZE; i++) {
             s.append(Integer.toHexString(buffer[i]));
diff --git a/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/manager/XidImpl.java b/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/manager/XidImpl.java
index b73e24e..e60c8de 100644
--- a/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/manager/XidImpl.java
+++ b/geronimo-transaction/src/main/java/org/apache/geronimo/transaction/manager/XidImpl.java
@@ -42,6 +42,16 @@
         this.globalId = globalId;
         //this.hash = hash(0, globalId);
         branchId = new byte[Xid.MAXBQUALSIZE];
+        check();
+    }
+
+    private void check() {
+        if (globalId.length > Xid.MAXGTRIDSIZE) {
+            throw new IllegalStateException("Global id is too long: " + toString());
+        }
+        if (branchId.length > Xid.MAXBQUALSIZE) {
+            throw new IllegalStateException("Branch id is too long: " + toString());
+        }
     }
 
     /**
@@ -61,12 +71,14 @@
         }
         branchId = branch;
         //this.hash = hash(hash, branchId);
+        check();
     }
 
     public XidImpl(int formatId, byte[] globalId, byte[] branchId) {
         this.formatId = formatId;
         this.globalId = globalId;
         this.branchId = branchId;
+        check();
     }
 
     private int hash(int hash, byte[] id) {
@@ -106,15 +118,18 @@
     }
 
     public String toString() {
-        StringBuffer s = new StringBuffer();
-        s.append("[globalId=");
+        StringBuilder s = new StringBuilder();
+        s.append("[Xid:globalId=");
         for (int i = 0; i < globalId.length; i++) {
             s.append(Integer.toHexString(globalId[i]));
         }
+        s.append(",length=").append(globalId.length);
         s.append(",branchId=");
         for (int i = 0; i < branchId.length; i++) {
             s.append(Integer.toHexString(branchId[i]));
         }
+        s.append(",length=");
+        s.append(branchId.length);
         s.append("]");
         return s.toString();
     }