Skip to content
Permalink
Browse files
Logging improvements from branches/2.1 rev 984259
  • Loading branch information
djencks committed Aug 11, 2010
1 parent 330ae83 commit 81c1e2397da500062529bc4e3b67cd6bf576f4c2
Showing 24 changed files with 220 additions and 25 deletions.
@@ -44,7 +44,7 @@ public abstract class AbstractSinglePoolConnectionInterceptor implements Connect
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 AbstractSinglePoolConnectionInterceptor(final ConnectionInterceptor next,
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 getConnection(ConnectionInfo connectionInfo) throws ResourceExceptio
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 @@ public void returnConnection(ConnectionInfo connectionInfo,
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 @@ protected boolean internalReturn(ConnectionInfo connectionInfo, ConnectionReturn
}
}
//we must destroy connection.
if (log.isTraceEnabled()) {
log.trace("Discarding connection in pool " + this + " " + connectionInfo);
}
next.returnConnection(connectionInfo, connectionReturnAction);
connectionCount--;
return releasePermit;
@@ -74,4 +74,13 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi
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);
}
}
}
@@ -123,6 +123,11 @@ public Exception getTrace() {
return trace;
}



@Override
public String toString() {
StringBuilder b = new StringBuilder();
b.append("handle: ").append(connection);
b.append(mci);
return b.toString();
}
} // ConnectionInfo
@@ -36,4 +36,6 @@ public interface ConnectionInterceptor {

void destroy();

void info(StringBuilder s);

} // ConnectionInterceptor
@@ -123,4 +123,14 @@ public void exit(Collection<ConnectionInfo> connectionInfos)
}
}
}

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);
}
}

}
@@ -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 @@ public InterceptorsImpl(TransactionSupport transactionSupport,
}
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() {
@@ -53,4 +53,14 @@ public void returnConnection(
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);
}
}

}
@@ -82,4 +82,9 @@ public void setStack(ConnectionInterceptor stack) {
this.stack = stack;
}

public void info(StringBuilder s) {
s.append(getClass().getName()).append("[stack=").append(stack).append("]\n");
s.append("<end>");
}

}
@@ -166,6 +166,12 @@ public void setIdleTimeoutMinutes(int idleTimeoutMinutes) {
}
}

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;
@@ -69,7 +69,7 @@ protected void internalGetConnection(ConnectionInfo connectionInfo) throws Resou
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 @@ protected void internalGetConnection(ConnectionInfo connectionInfo) throws Resou
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 @@ protected void getExpiredManagedConnectionInfos(long threshold, List<ManagedConn
}
}

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);
}

}
@@ -67,7 +67,7 @@ protected void internalGetConnection(ConnectionInfo connectionInfo) throws Resou
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 @@ protected void internalGetConnection(ConnectionInfo connectionInfo) throws Resou
//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 @@ protected void internalGetConnection(ConnectionInfo connectionInfo) throws Resou
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 @@ protected void getExpiredManagedConnectionInfos(long threshold, List<ManagedConn

}

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);
}

}
@@ -99,4 +99,9 @@ public void destroy() {
next.destroy();
}

public void info(StringBuilder s) {
s.append(getClass().getName()).append("[subjectSource=").append(subjectSource).append("]\n");
next.info(s);
}

}
@@ -56,4 +56,10 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi
public void destroy() {
this.next.destroy();
}

public void info(StringBuilder s) {
s.append(getClass().getName()).append("[classLoader=").append(classLoader).append("]\n");
next.info(s);
}

}
@@ -85,4 +85,10 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi
public void destroy() {
next.destroy();
}

public void info(StringBuilder s) {
s.append(getClass().getName()).append("[matchConnections=").append(matchConnections).append("]\n");
next.info(s);
}

}
@@ -65,14 +65,17 @@ public void getConnection(ConnectionInfo connectionInfo) throws ResourceExceptio
//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);
if (connectionInfo.isUnshareable()) {
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 @@ public void getConnection(ConnectionInfo connectionInfo) throws ResourceExceptio
//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 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi

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 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi
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,29 +134,29 @@ public void returnConnection(ConnectionInfo connectionInfo, ConnectionReturnActi
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);
}

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 @@ public void afterCompletion(Object stuff) {
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 @@ private void returnHandle(ManagedConnectionInfo managedConnectionInfo) {
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);

0 comments on commit 81c1e23

Please sign in to comment.