Skip to content

Commit

Permalink
Transactions that takes too long to evaluate, during block creation, …
Browse files Browse the repository at this point in the history
…are dropped from the txpool (hyperledger#6163)

Signed-off-by: Fabio Di Fabio <[email protected]>
Signed-off-by: Justin Florentine <[email protected]>
  • Loading branch information
fab-10 authored and jflo committed Nov 20, 2023
1 parent 3cc1e46 commit 3f9f0a5
Show file tree
Hide file tree
Showing 5 changed files with 125 additions and 44 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@

### Additions and Improvements
- Implement debug_traceCall [#5885](https://github.com/hyperledger/besu/pull/5885)
- Transactions that takes too long to evaluate, during block creation, are dropped from the txpool [#6163](https://github.com/hyperledger/besu/pull/6163)

## 23.10.2

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@

import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.BLOCK_SELECTION_TIMEOUT;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.SELECTED;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.TX_EVALUATION_TOO_LONG;

import org.hyperledger.besu.datatypes.Address;
import org.hyperledger.besu.datatypes.Wei;
Expand Down Expand Up @@ -95,6 +96,7 @@ public class BlockTransactionSelector {
private final BlockAwareOperationTracer pluginOperationTracer;
private final EthScheduler ethScheduler;
private final AtomicBoolean isTimeout = new AtomicBoolean(false);
private final long blockTxsSelectionMaxTime;
private WorldUpdater blockWorldStateUpdater;

public BlockTransactionSelector(
Expand Down Expand Up @@ -133,6 +135,7 @@ public BlockTransactionSelector(
this.pluginTransactionSelector = pluginTransactionSelector;
this.pluginOperationTracer = pluginTransactionSelector.getOperationTracer();
blockWorldStateUpdater = worldState.updater();
blockTxsSelectionMaxTime = miningParameters.getUnstable().getBlockTxsSelectionMaxTime();
}

private List<AbstractTransactionSelector> createTransactionSelectors(
Expand Down Expand Up @@ -168,8 +171,6 @@ public TransactionSelectionResults buildTransactionListForBlock() {
}

private void timeLimitedSelection() {
final long blockTxsSelectionMaxTime =
blockSelectionContext.miningParameters().getUnstable().getBlockTxsSelectionMaxTime();
final var txSelection =
ethScheduler.scheduleBlockCreationTask(
() ->
Expand Down Expand Up @@ -226,9 +227,11 @@ private TransactionSelectionResult evaluateTransaction(
final PendingTransaction pendingTransaction) {
checkCancellation();

final long evaluationStartedAt = System.currentTimeMillis();

TransactionSelectionResult selectionResult = evaluatePreProcessing(pendingTransaction);
if (!selectionResult.selected()) {
return handleTransactionNotSelected(pendingTransaction, selectionResult);
return handleTransactionNotSelected(pendingTransaction, selectionResult, evaluationStartedAt);
}

final WorldUpdater txWorldStateUpdater = blockWorldStateUpdater.updater();
Expand All @@ -239,10 +242,14 @@ private TransactionSelectionResult evaluateTransaction(
evaluatePostProcessing(pendingTransaction, processingResult);

if (postProcessingSelectionResult.selected()) {
return handleTransactionSelected(pendingTransaction, processingResult, txWorldStateUpdater);
return handleTransactionSelected(
pendingTransaction, processingResult, txWorldStateUpdater, evaluationStartedAt);
}
return handleTransactionNotSelected(
pendingTransaction, postProcessingSelectionResult, txWorldStateUpdater);
pendingTransaction,
postProcessingSelectionResult,
txWorldStateUpdater,
evaluationStartedAt);
}

/**
Expand Down Expand Up @@ -326,12 +333,14 @@ private TransactionProcessingResult processTransaction(
* @param pendingTransaction The pending transaction.
* @param processingResult The result of the transaction processing.
* @param txWorldStateUpdater The world state updater.
* @param evaluationStartedAt when the evaluation of this tx started
* @return The result of the transaction selection process.
*/
private TransactionSelectionResult handleTransactionSelected(
final PendingTransaction pendingTransaction,
final TransactionProcessingResult processingResult,
final WorldUpdater txWorldStateUpdater) {
final WorldUpdater txWorldStateUpdater,
final long evaluationStartedAt) {
final Transaction transaction = pendingTransaction.getTransaction();

final long gasUsedByTransaction =
Expand All @@ -347,7 +356,8 @@ private TransactionSelectionResult handleTransactionSelected(
// this need to be done synchronously to avoid that a concurrent timeout
// could start packing a block while we are updating the state here
synchronized (isTimeout) {
if (!isTimeout.get()) {
tooLate = isTimeout.get();
if (!tooLate) {
txWorldStateUpdater.commit();
blockWorldStateUpdater.commit();
final TransactionReceipt receipt =
Expand All @@ -356,30 +366,47 @@ private TransactionSelectionResult handleTransactionSelected(

transactionSelectionResults.updateSelected(
pendingTransaction.getTransaction(), receipt, gasUsedByTransaction, blobGasUsed);
tooLate = false;
} else {
tooLate = true;
}
}

final long evaluationTime = System.currentTimeMillis() - evaluationStartedAt;
if (tooLate) {
// even if this tx passed all the checks, it is too late to include it in this block,
// so we need to treat it as not selected
LOG.atTrace()
.setMessage("{} processed too late for block creation")
.addArgument(transaction::toTraceLog)
.log();

// check if this tx took too much to evaluate, and in case remove it from the pool
final TransactionSelectionResult timeoutSelectionResult;
if (evaluationTime > blockTxsSelectionMaxTime) {
LOG.atWarn()
.setMessage(
"Transaction {} is too late for inclusion, evaluated in {}ms that is over the max limit of {}"
+ ", removing it from the pool")
.addArgument(transaction::toTraceLog)
.addArgument(evaluationTime)
.addArgument(blockTxsSelectionMaxTime)
.log();
timeoutSelectionResult = TX_EVALUATION_TOO_LONG;
} else {
LOG.atTrace()
.setMessage("Transaction {} is too late for inclusion")
.addArgument(transaction::toTraceLog)
.addArgument(evaluationTime)
.log();
timeoutSelectionResult = BLOCK_SELECTION_TIMEOUT;
}

// do not rely on the presence of this result, since by the time it is added, the code
// reading it could have been already executed by another thread
return handleTransactionNotSelected(
pendingTransaction, BLOCK_SELECTION_TIMEOUT, txWorldStateUpdater);
pendingTransaction, timeoutSelectionResult, txWorldStateUpdater, evaluationStartedAt);
}

pluginTransactionSelector.onTransactionSelected(pendingTransaction, processingResult);
blockWorldStateUpdater = worldState.updater();
LOG.atTrace()
.setMessage("Selected {} for block creation")
.setMessage("Selected {} for block creation, evaluated in {}ms")
.addArgument(transaction::toTraceLog)
.addArgument(evaluationTime)
.log();
return SELECTED;
}
Expand All @@ -391,24 +418,34 @@ private TransactionSelectionResult handleTransactionSelected(
*
* @param pendingTransaction The unselected pending transaction.
* @param selectionResult The result of the transaction selection process.
* @param evaluationStartedAt when the evaluation of this tx started
* @return The result of the transaction selection process.
*/
private TransactionSelectionResult handleTransactionNotSelected(
final PendingTransaction pendingTransaction,
final TransactionSelectionResult selectionResult) {
final TransactionSelectionResult selectionResult,
final long evaluationStartedAt) {

transactionSelectionResults.updateNotSelected(
pendingTransaction.getTransaction(), selectionResult);
pluginTransactionSelector.onTransactionNotSelected(pendingTransaction, selectionResult);
LOG.atTrace()
.setMessage("Not selected {} for block creation with result {}, evaluated in {}ms")
.addArgument(pendingTransaction::toTraceLog)
.addArgument(selectionResult)
.addArgument(() -> System.currentTimeMillis() - evaluationStartedAt)
.log();

return selectionResult;
}

private TransactionSelectionResult handleTransactionNotSelected(
final PendingTransaction pendingTransaction,
final TransactionSelectionResult selectionResult,
final WorldUpdater txWorldStateUpdater) {
final WorldUpdater txWorldStateUpdater,
final long evaluationStartedAt) {
txWorldStateUpdater.revert();
return handleTransactionNotSelected(pendingTransaction, selectionResult);
return handleTransactionNotSelected(pendingTransaction, selectionResult, evaluationStartedAt);
}

private void checkCancellation() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,10 @@
import static org.assertj.core.api.Assertions.entry;
import static org.awaitility.Awaitility.await;
import static org.hyperledger.besu.ethereum.core.MiningParameters.Unstable.DEFAULT_NON_POA_BLOCK_TXS_SELECTION_MAX_TIME;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.BLOCK_SELECTION_TIMEOUT;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.PRIORITY_FEE_PER_GAS_BELOW_CURRENT_MIN;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.SELECTED;
import static org.hyperledger.besu.plugin.data.TransactionSelectionResult.TX_EVALUATION_TOO_LONG;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyBoolean;
import static org.mockito.ArgumentMatchers.eq;
Expand Down Expand Up @@ -582,15 +586,15 @@ public TransactionSelectionResult evaluateTransactionPreProcessing(
return TransactionSelectionResult.invalidTransient("transient");
if (pendingTransaction.getTransaction().equals(notSelectedInvalid))
return TransactionSelectionResult.invalid("invalid");
return TransactionSelectionResult.SELECTED;
return SELECTED;
}

@Override
public TransactionSelectionResult evaluateTransactionPostProcessing(
final PendingTransaction pendingTransaction,
final org.hyperledger.besu.plugin.data.TransactionProcessingResult
processingResult) {
return TransactionSelectionResult.SELECTED;
return SELECTED;
}
};

Expand Down Expand Up @@ -640,7 +644,7 @@ public void transactionSelectionPluginShouldWork_PostProcessing() {
@Override
public TransactionSelectionResult evaluateTransactionPreProcessing(
final PendingTransaction pendingTransaction) {
return TransactionSelectionResult.SELECTED;
return SELECTED;
}

@Override
Expand All @@ -652,7 +656,7 @@ public TransactionSelectionResult evaluateTransactionPostProcessing(
if (processingResult.getEstimateGasUsedByTransaction() > maxGasUsedByTransaction) {
return TransactionSelectionResult.invalidTransient("Invalid");
}
return TransactionSelectionResult.SELECTED;
return SELECTED;
}
};

Expand Down Expand Up @@ -869,9 +873,7 @@ public void shouldNotSelectTransactionsWithPriorityFeeLessThanConfig() {

assertThat(results.getSelectedTransactions()).containsOnly(txSelected);
assertThat(results.getNotSelectedTransactions())
.containsOnly(
entry(
txNotSelected, TransactionSelectionResult.PRIORITY_FEE_PER_GAS_BELOW_CURRENT_MIN));
.containsOnly(entry(txNotSelected, PRIORITY_FEE_PER_GAS_BELOW_CURRENT_MIN));
}

@ParameterizedTest
Expand All @@ -882,47 +884,84 @@ public void subsetOfPendingTransactionsIncludedWhenTxSelectionMaxTimeIsOver(
final boolean processingTooLate,
final boolean postProcessingTooLate) {

final Supplier<Answer<TransactionSelectionResult>> inTime =
() -> invocation -> TransactionSelectionResult.SELECTED;
internalBlockSelectionTimeoutSimulation(
isPoa,
preProcessingTooLate,
processingTooLate,
postProcessingTooLate,
500,
BLOCK_SELECTION_TIMEOUT,
false);
}

@ParameterizedTest
@MethodSource("subsetOfPendingTransactionsIncludedWhenTxSelectionMaxTimeIsOver")
public void pendingTransactionsThatTakesTooLongToEvaluateIsDroppedFromThePool(
final boolean isPoa,
final boolean preProcessingTooLate,
final boolean processingTooLate,
final boolean postProcessingTooLate) {

internalBlockSelectionTimeoutSimulation(
isPoa,
preProcessingTooLate,
processingTooLate,
postProcessingTooLate,
900,
TX_EVALUATION_TOO_LONG,
true);
}

private void internalBlockSelectionTimeoutSimulation(
final boolean isPoa,
final boolean preProcessingTooLate,
final boolean processingTooLate,
final boolean postProcessingTooLate,
final long longProcessingTxTime,
final TransactionSelectionResult longProcessingTxResult,
final boolean isLongProcessingTxDropped) {

final long fastProcessingTxTime = 200;

final Supplier<Answer<TransactionSelectionResult>> inTime = () -> invocation -> SELECTED;

final BiFunction<Transaction, Long, Answer<TransactionSelectionResult>> tooLate =
(p, t) ->
invocation -> {
if (((PendingTransaction) invocation.getArgument(0)).getTransaction().equals(p)) {
final org.hyperledger.besu.ethereum.eth.transactions.PendingTransaction ptx =
invocation.getArgument(0);
if (ptx.getTransaction().equals(p)) {
Thread.sleep(t);
} else {
Thread.sleep(fastProcessingTxTime);
}
return TransactionSelectionResult.SELECTED;
return SELECTED;
};

final ProcessableBlockHeader blockHeader = createBlock(301_000);
final Address miningBeneficiary = AddressHelpers.ofValue(1);
final int poaMinBlockTime = 1;
final long blockTxsSelectionMaxTime = 750;
final long longProcessingTxTime = 500;

final List<Transaction> transactionsToInject = new ArrayList<>(3);
for (int i = 0; i < 2; i++) {
final Transaction tx = createTransaction(i, Wei.of(7), 100_000);
transactionsToInject.add(tx);
ensureTransactionIsValid(tx);
ensureTransactionIsValid(tx, 0, 0, processingTooLate ? fastProcessingTxTime : 0);
}

final Transaction lateTx = createTransaction(2, Wei.of(7), 100_000);
transactionsToInject.add(lateTx);
ensureTransactionIsValid(
lateTx, 0, 0, processingTooLate ? blockTxsSelectionMaxTime + longProcessingTxTime : 0);
ensureTransactionIsValid(lateTx, 0, 0, processingTooLate ? longProcessingTxTime : 0);

PluginTransactionSelector transactionSelector = mock(PluginTransactionSelector.class);
when(transactionSelector.evaluateTransactionPreProcessing(any()))
.thenAnswer(
preProcessingTooLate
? inTime.get()
: tooLate.apply(lateTx, blockTxsSelectionMaxTime + longProcessingTxTime));
preProcessingTooLate ? tooLate.apply(lateTx, longProcessingTxTime) : inTime.get());

when(transactionSelector.evaluateTransactionPostProcessing(any(), any()))
.thenAnswer(
postProcessingTooLate
? inTime.get()
: tooLate.apply(lateTx, blockTxsSelectionMaxTime + longProcessingTxTime));
postProcessingTooLate ? tooLate.apply(lateTx, longProcessingTxTime) : inTime.get());

final PluginTransactionSelectorFactory transactionSelectorFactory =
mock(PluginTransactionSelectorFactory.class);
Expand Down Expand Up @@ -962,7 +1001,9 @@ public void subsetOfPendingTransactionsIncludedWhenTxSelectionMaxTimeIsOver(
// given enough time we can check the not selected tx
await().until(() -> !results.getNotSelectedTransactions().isEmpty());
assertThat(results.getNotSelectedTransactions())
.containsOnly(entry(lateTx, TransactionSelectionResult.BLOCK_SELECTION_TIMEOUT));
.containsOnly(entry(lateTx, longProcessingTxResult));
assertThat(transactionPool.getTransactionByHash(lateTx.getHash()).isEmpty())
.isEqualTo(isLongProcessingTxDropped ? true : false);
}

private static Stream<Arguments>
Expand Down
2 changes: 1 addition & 1 deletion plugin-api/build.gradle
Original file line number Diff line number Diff line change
Expand Up @@ -69,7 +69,7 @@ Calculated : ${currentHash}
tasks.register('checkAPIChanges', FileStateChecker) {
description = "Checks that the API for the Plugin-API project does not change without deliberate thought"
files = sourceSets.main.allJava.files
knownHash = '7Aj0APsKs1wBVqaWQFdEs85/MNKxTiVzyjIeZ+zCWlw='
knownHash = 'gKRXd2Ow7wYKSgeGrDMRj0+2LdCzjOhLx8UEno9btGw='
}
check.dependsOn('checkAPIChanges')

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@ private enum Status {
BLOCK_FULL(true, false),
BLOCK_OCCUPANCY_ABOVE_THRESHOLD(true, false),
BLOCK_SELECTION_TIMEOUT(true, false),
TX_EVALUATION_TOO_LONG(false, true),
INVALID_TRANSIENT(false, false),
INVALID(false, true);

Expand Down Expand Up @@ -60,8 +61,9 @@ public String toString() {
/** There was no more time to add transaction to the block */
public static final TransactionSelectionResult BLOCK_SELECTION_TIMEOUT =
new TransactionSelectionResult(Status.BLOCK_SELECTION_TIMEOUT);
;

/** Transaction took too much to evaluate */
public static final TransactionSelectionResult TX_EVALUATION_TOO_LONG =
new TransactionSelectionResult(Status.TX_EVALUATION_TOO_LONG);
/**
* The transaction has not been selected since too large and the occupancy of the block is enough
* to stop the selection.
Expand Down

0 comments on commit 3f9f0a5

Please sign in to comment.