Merged V3.3-BUG-FIX to HEAD

23430: Merged V3.3 to V3.3-BUG-FIX
      23429: Merged PATCHES/V3.2.0 to V3.3
         23428: ALF-5141: Further refinement of transaction limiting behaviour
            - Once accepted a transaction will be retried until it succeeds or the retry limit is exceeded. No limiting of retries by time as otherwise likelihood of any transaction succeeding under load is small
            - Default web transaction threshold is now 20 seconds to avoid problems on non-loaded systems
            - Record stack traces of tracked transactions to help debug slow transactions


git-svn-id: https://svn.alfresco.com/repos/alfresco-enterprise/alfresco/HEAD/root@23431 c4b6b30b-aa2e-2d43-bbcb-ca4b014f7261
This commit is contained in:
Dave Ward
2010-11-03 19:28:21 +00:00
parent 1ef56dbc83
commit 6e66b9ad06
3 changed files with 24 additions and 60 deletions

View File

@@ -20,5 +20,5 @@ server.setup.transaction.min-retry-wait-ms=15000
server.setup.transaction.max-retry-wait-ms=15000
server.setup.transaction.wait-increment-ms=10
# Try to limit web transactions to a maximum of 10 seconds
server.web.transaction.max-duration-ms=10000
# Try to limit web transactions to a maximum of 20 seconds
server.web.transaction.max-duration-ms=20000

View File

@@ -21,6 +21,8 @@ package org.alfresco.repo.transaction;
import java.lang.reflect.Method;
import java.sql.BatchUpdateException;
import java.sql.SQLException;
import java.util.LinkedList;
import java.util.List;
import java.util.Random;
import java.util.SortedMap;
import java.util.TreeMap;
@@ -130,8 +132,8 @@ public class RetryingTransactionHelper
*/
private long maxExecutionMs;
/** Map of transaction start times to counts. Only maintained when maxExecutionMs is set. */
private SortedMap <Long, Integer> txnsInProgress = new TreeMap<Long, Integer>();
/** Map of transaction start times to thread stack traces. Only maintained when maxExecutionMs is set. */
private SortedMap <Long, List<Throwable>> txnsInProgress = new TreeMap<Long, List<Throwable>>();
/** The number of concurrently exeucting transactions. Only maintained when maxExecutionMs is set. */
private int txnCount;
@@ -321,7 +323,8 @@ public class RetryingTransactionHelper
}
// If we are time limiting, set ourselves a time limit and maintain the count of concurrent transactions
long startTime = 0, endTime = 0, txnStartTime = 0;
long startTime = 0;
Throwable stackTrace = null;
if (startingNew && maxExecutionMs > 0)
{
startTime = System.currentTimeMillis();
@@ -330,17 +333,24 @@ public class RetryingTransactionHelper
if (txnCount > 0)
{
// If this transaction would take us above our ceiling, reject it
long oldestDuration = startTime - txnsInProgress.firstKey();
long oldestStart = txnsInProgress.firstKey();
long oldestDuration = startTime - oldestStart;
if (oldestDuration > maxExecutionMs)
{
throw new TooBusyException("Too busy: " + txnCount + " transactions. Oldest " + oldestDuration + " milliseconds");
throw new TooBusyException("Too busy: " + txnCount + " transactions. Oldest " + oldestDuration + " milliseconds", txnsInProgress.get(oldestStart).get(0));
}
}
Integer count = txnsInProgress.get(startTime);
txnsInProgress.put(startTime, count == null ? 1 : count + 1);
// Record the start time and stack trace of the starting thread
List<Throwable> traces = txnsInProgress.get(startTime);
if (traces == null)
{
traces = new LinkedList<Throwable>();
txnsInProgress.put(startTime, traces);
}
stackTrace = new Exception("Stack trace");
traces.add(stackTrace);
++txnCount;
}
endTime = startTime + maxExecutionMs;
}
try
@@ -355,12 +365,6 @@ public class RetryingTransactionHelper
{
if (startingNew)
{
// Monitor duration of each retry so that we can project an end time
if (maxExecutionMs > 0)
{
txnStartTime = System.currentTimeMillis();
}
txn = requiresNew ? txnService.getNonPropagatingUserTransaction(readOnly) : txnService
.getUserTransaction(readOnly);
txn.begin();
@@ -471,25 +475,6 @@ public class RetryingTransactionHelper
int sleepIntervalRandom = (count > 0 && retryWaitIncrementMs > 0)
? random.nextInt(count * retryWaitIncrementMs)
: minRetryWaitMs;
int maxRetryWaitMs;
// If we are time limiting only continue if we have enough time, based on the last duration
if (maxExecutionMs > 0)
{
long txnEndTime = System.currentTimeMillis();
long projectedEndTime = txnEndTime + (txnEndTime - txnStartTime);
if (projectedEndTime > endTime)
{
// Reject the retry
throw new TooBusyException("Too busy to retry", e);
}
// Limit the wait duration to fit into the time we have left
maxRetryWaitMs = Math.min(this.maxRetryWaitMs, (int)(endTime - projectedEndTime));
}
else
{
maxRetryWaitMs = this.maxRetryWaitMs;
}
int sleepInterval = Math.min(maxRetryWaitMs, sleepIntervalRandom);
sleepInterval = Math.max(sleepInterval, minRetryWaitMs);
if (logger.isInfoEnabled() && !logger.isDebugEnabled())
@@ -531,16 +516,16 @@ public class RetryingTransactionHelper
synchronized (this)
{
txnCount--;
Integer count = txnsInProgress.get(startTime);
if (count != null)
List<Throwable> traces = txnsInProgress.get(startTime);
if (traces != null)
{
if (count == 1)
if (traces.size() == 1)
{
txnsInProgress.remove(startTime);
}
else
{
txnsInProgress.put(startTime, count-1);
traces.remove(stackTrace);
}
}
}

View File

@@ -571,27 +571,6 @@ public class RetryingTransactionHelperTest extends TestCase
{
throw new RuntimeException("Unexpected exception", caughtExceptions.get(0));
}
// Check retry limitation
long startTime = System.currentTimeMillis();
try
{
txnHelper.doInTransaction(new RetryingTransactionCallback<Void>()
{
public Void execute() throws Throwable
{
Thread.sleep(1000);
throw new ConcurrencyFailureException("Fake concurrency failure");
}
});
fail("Expected TooBusyException");
}
catch (TooBusyException e)
{
assertNotNull("Expected cause", e.getCause());
assertTrue("Too long", System.currentTimeMillis() < startTime + 5000);
}
}
private void runThreads(final RetryingTransactionHelper txnHelper, final List<Throwable> caughtExceptions,