From a5dbff3f38ef73272292a57021c7bcab3eec089c Mon Sep 17 00:00:00 2001 From: Peter Bushnell Date: Tue, 15 Nov 2022 10:02:35 +0000 Subject: [PATCH 1/3] Add benchmarking for custom TX --- src/validation.cpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/validation.cpp b/src/validation.cpp index 3c64455ac4b..5763c497d50 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -2878,7 +2878,10 @@ bool CChainState::ConnectBlock(const CBlock& block, CValidationState& state, CBl } CHistoryWriters writers{paccountHistoryDB.get(), pburnHistoryDB.get(), pvaultHistoryDB.get()}; + const auto applyCustomTxTime = GetTimeMicros(); const auto res = ApplyCustomTx(accountsView, view, tx, chainparams.GetConsensus(), pindex->nHeight, pindex->GetBlockTime(), nullptr, i, &writers); + std::vector metadata; + LogPrint(BCLog::BENCH, " - ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - applyCustomTxTime) * MILLI); if (!res.ok && (res.code & CustomTxErrCodes::Fatal)) { if (pindex->nHeight >= chainparams.GetConsensus().EunosHeight) { return state.Invalid(ValidationInvalidReason::CONSENSUS, From f981819960386b99ff51df443d508174a230f543 Mon Sep 17 00:00:00 2001 From: Peter Bushnell Date: Tue, 15 Nov 2022 15:26:23 +0000 Subject: [PATCH 2/3] Log custom TX time in multiple categories --- src/logging.cpp | 1 + src/logging.h | 1 + src/validation.cpp | 14 ++++++++++++-- 3 files changed, 14 insertions(+), 2 deletions(-) diff --git a/src/logging.cpp b/src/logging.cpp index 349dbeff685..b346b9c8050 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -158,6 +158,7 @@ const CLogCategoryDesc LogCategories[] = {BCLog::FUTURESWAP, "futureswap"}, {BCLog::TOKENSPLIT, "tokensplit"}, {BCLog::RPCCACHE, "rpccache"}, + {BCLog::CUSTOMTXBENCH, "customtxbench"}, {BCLog::ALL, "1"}, {BCLog::ALL, "all"}, }; diff --git a/src/logging.h b/src/logging.h index 7581b574ce4..2b1690e7702 100644 --- a/src/logging.h +++ b/src/logging.h @@ -64,6 +64,7 @@ namespace BCLog { FUTURESWAP = (1 << 27), TOKENSPLIT = (1 << 28), RPCCACHE = (1 << 29), + CUSTOMTXBENCH = (1 << 30), // Note: We're almost hitting 32 bit threshold. ALL = ~(uint32_t)0, }; diff --git a/src/validation.cpp b/src/validation.cpp index 5763c497d50..1f8e547d64e 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -2530,6 +2530,17 @@ bool StopOrInterruptConnect(const CBlockIndex *pIndex, CValidationState& state) return false; } +static void LogApplyCustomTx(const CTransaction &tx, const int64_t start) { + // Only log once for one of the following categories. Log BENCH first for consistent formatting. + if (LogAcceptCategory(BCLog::BENCH)) { + std::vector metadata; + LogPrint(BCLog::BENCH, " - ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - start) * MILLI); + } else if (LogAcceptCategory(BCLog::CUSTOMTXBENCH)) { + std::vector metadata; + LogPrint(BCLog::CUSTOMTXBENCH, "ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - start) * MILLI); + } +} + /** Apply the effects of this block (with given index) on the UTXO set represented by coins. * Validity checks that depend on the UTXO set are also done; ConnectBlock () * can fail if those validity checks fail (among other reasons). */ @@ -2880,8 +2891,7 @@ bool CChainState::ConnectBlock(const CBlock& block, CValidationState& state, CBl CHistoryWriters writers{paccountHistoryDB.get(), pburnHistoryDB.get(), pvaultHistoryDB.get()}; const auto applyCustomTxTime = GetTimeMicros(); const auto res = ApplyCustomTx(accountsView, view, tx, chainparams.GetConsensus(), pindex->nHeight, pindex->GetBlockTime(), nullptr, i, &writers); - std::vector metadata; - LogPrint(BCLog::BENCH, " - ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - applyCustomTxTime) * MILLI); + LogApplyCustomTx(tx, applyCustomTxTime); if (!res.ok && (res.code & CustomTxErrCodes::Fatal)) { if (pindex->nHeight >= chainparams.GetConsensus().EunosHeight) { return state.Invalid(ValidationInvalidReason::CONSENSUS, From 1b7dd8405b350cea55ed46f1ff226dc7b51af174 Mon Sep 17 00:00:00 2001 From: Prasanna Loganathar Date: Thu, 17 Nov 2022 16:07:33 +0800 Subject: [PATCH 3/3] Update src/validation.cpp --- src/validation.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/validation.cpp b/src/validation.cpp index 1f8e547d64e..874fa9942d6 100644 --- a/src/validation.cpp +++ b/src/validation.cpp @@ -2537,7 +2537,7 @@ static void LogApplyCustomTx(const CTransaction &tx, const int64_t start) { LogPrint(BCLog::BENCH, " - ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - start) * MILLI); } else if (LogAcceptCategory(BCLog::CUSTOMTXBENCH)) { std::vector metadata; - LogPrint(BCLog::CUSTOMTXBENCH, "ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - start) * MILLI); + LogPrint(BCLog::CUSTOMTXBENCH, "Bench::ApplyCustomTx: %s Type: %s Time: %.2fms\n", tx.GetHash().ToString(), ToString(GuessCustomTxType(tx, metadata, false)), (GetTimeMicros() - start) * MILLI); } }