diff --git a/packages/js-drive/lib/abci/errors/createContextLoggerFactory.js b/packages/js-drive/lib/abci/errors/createContextLoggerFactory.js new file mode 100644 index 00000000000..4e9b52354f6 --- /dev/null +++ b/packages/js-drive/lib/abci/errors/createContextLoggerFactory.js @@ -0,0 +1,24 @@ +/** + * + * @param {AsyncLocalStorage} abciAsyncLocalStorage + * @return {createContextLogger} + */ +function createContextLoggerFactory(abciAsyncLocalStorage) { + /** + * @typedef {createContextLogger} + * @param {Logger} logger + * @param {Object} context + * @return {Logger} + */ + function createContextLogger(logger, context) { + const contextLogger = logger.child(context); + + abciAsyncLocalStorage.getStore().set('logger', contextLogger); + + return contextLogger; + } + + return createContextLogger; +} + +module.exports = createContextLoggerFactory; diff --git a/packages/js-drive/lib/abci/errors/enrichErrorWithConsensusLoggerFactory.js b/packages/js-drive/lib/abci/errors/enrichErrorWithConsensusLoggerFactory.js deleted file mode 100644 index 0128416d6de..00000000000 --- a/packages/js-drive/lib/abci/errors/enrichErrorWithConsensusLoggerFactory.js +++ /dev/null @@ -1,42 +0,0 @@ -/** - * Add consensus logger to an error (factory) - * - * @param {BlockExecutionContext} latestBlockExecutionContext - * - * @return {enrichErrorWithConsensusLogger} - */ -function enrichErrorWithConsensusLoggerFactory(latestBlockExecutionContext) { - /** - * Add consensus logger to an error - * - * @typedef enrichErrorWithConsensusLogger - * - * @param {Function} method - * - * @return {Function} - */ - function enrichErrorWithConsensusLogger(method) { - /** - * @param {*[]} args - */ - async function methodHandler(...args) { - try { - return await method(...args); - } catch (e) { - const { consensusLogger } = latestBlockExecutionContext; - - if (consensusLogger) { - e.consensusLogger = consensusLogger; - } - - throw e; - } - } - - return methodHandler; - } - - return enrichErrorWithConsensusLogger; -} - -module.exports = enrichErrorWithConsensusLoggerFactory; diff --git a/packages/js-drive/lib/abci/errors/enrichErrorWithContextLoggerFactory.js b/packages/js-drive/lib/abci/errors/enrichErrorWithContextLoggerFactory.js new file mode 100644 index 00000000000..2493c6d7c92 --- /dev/null +++ b/packages/js-drive/lib/abci/errors/enrichErrorWithContextLoggerFactory.js @@ -0,0 +1,39 @@ +/** + * Add consensus logger to an error (factory) + * + * @param {AsyncLocalStorage} abciAsyncLocalStorage + * @return {enrichErrorWithContextLogger} + */ +function enrichErrorWithContextLoggerFactory(abciAsyncLocalStorage) { + /** + * Add consensus logger to an error + * + * @typedef enrichErrorWithContextLogger + * + * @param {Function} method + * + * @return {Function} + */ + function enrichErrorWithContextLogger(method) { + /** + * @param {*[]} args + */ + async function methodHandler(...args) { + return abciAsyncLocalStorage.run( + new Map(), + () => method(...args).catch((error) => { + // eslint-disable-next-line no-param-reassign + error.contextLogger = abciAsyncLocalStorage.getStore().get('logger'); + + return Promise.reject(error); + }), + ); + } + + return methodHandler; + } + + return enrichErrorWithContextLogger; +} + +module.exports = enrichErrorWithContextLoggerFactory; diff --git a/packages/js-drive/lib/abci/errors/wrapInErrorHandlerFactory.js b/packages/js-drive/lib/abci/errors/wrapInErrorHandlerFactory.js index bbf95334443..8445605f767 100644 --- a/packages/js-drive/lib/abci/errors/wrapInErrorHandlerFactory.js +++ b/packages/js-drive/lib/abci/errors/wrapInErrorHandlerFactory.js @@ -15,18 +15,10 @@ function wrapInErrorHandlerFactory(logger, isProductionEnvironment) { * @typedef wrapInErrorHandler * * @param {Function} method - * @param {Object} [options={}] - * @param {boolean} [options.respondWithInternalError=false] * * @return {Function} */ - function wrapInErrorHandler(method, options = {}) { - // eslint-disable-next-line no-param-reassign - options = { - respondWithInternalError: false, - ...options, - }; - + function wrapInErrorHandler(method) { /** * @param {*[]} args */ @@ -34,37 +26,31 @@ function wrapInErrorHandlerFactory(logger, isProductionEnvironment) { try { return await method(...args); } catch (e) { - let error = e; + let abciError = e; // Wrap all non ABCI errors to an internal ABCI error if (!(e instanceof AbstractAbciError)) { - error = new InternalAbciError(e); + abciError = new InternalAbciError(e); } // Log only internal ABCI errors - if (error instanceof InternalAbciError) { - // in consensus ABCI handlers (blockBegin, deliverTx, blockEnd, commit) - // we should propagate the error upwards - // to halt the Drive - // in order cases like query and checkTx - // we need to respond with internal errors - if (!options.respondWithInternalError) { - throw error.getError(); - } + if (abciError instanceof InternalAbciError) { + const originalError = abciError.getError(); - const originalError = error.getError(); + const preferredLogger = originalError.contextLogger || logger; + delete originalError.contextLogger; - (originalError.consensusLogger || logger).error( + preferredLogger.error( { err: originalError }, originalError.message, ); if (!isProductionEnvironment) { - error = new VerboseInternalAbciError(error); + abciError = new VerboseInternalAbciError(abciError); } } - return error.getAbciResponse(); + return abciError.getAbciResponse(); } } diff --git a/packages/js-drive/lib/abci/handlers/checkTxHandlerFactory.js b/packages/js-drive/lib/abci/handlers/checkTxHandlerFactory.js index 1cf6707185c..05057f6a239 100644 --- a/packages/js-drive/lib/abci/handlers/checkTxHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/checkTxHandlerFactory.js @@ -8,11 +8,16 @@ const { /** * @param {unserializeStateTransition} unserializeStateTransition + * @param {AsyncLocalStorage} unserializeStateTransition + * @param {createContextLogger} createContextLogger + * @param {Logger} logger * * @returns {checkTxHandler} */ function checkTxHandlerFactory( unserializeStateTransition, + createContextLogger, + logger, ) { /** * CheckTx ABCI Handler @@ -24,6 +29,10 @@ function checkTxHandlerFactory( * @returns {Promise} */ async function checkTxHandler({ tx: stateTransitionByteArray }) { + createContextLogger(logger, { + abciMethod: 'checkTx', + }); + await unserializeStateTransition(stateTransitionByteArray); return new ResponseCheckTx(); diff --git a/packages/js-drive/lib/abci/handlers/extendVoteHandlerFactory.js b/packages/js-drive/lib/abci/handlers/extendVoteHandlerFactory.js index 76f178b3f3a..9d0e1ef786c 100644 --- a/packages/js-drive/lib/abci/handlers/extendVoteHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/extendVoteHandlerFactory.js @@ -11,21 +11,21 @@ const { /** * @param {BlockExecutionContext} proposalBlockExecutionContext + * @param {createContextLogger} createContextLogger * * @return {extendVoteHandler} */ -function extendVoteHandlerFactory(proposalBlockExecutionContext) { +function extendVoteHandlerFactory(proposalBlockExecutionContext, createContextLogger) { /** * @typedef extendVoteHandler * @return {Promise} */ async function extendVoteHandler() { - const consensusLogger = proposalBlockExecutionContext.getConsensusLogger() - .child({ - abciMethod: 'extendVote', - }); + const contextLogger = createContextLogger(proposalBlockExecutionContext.getContextLogger(), { + abciMethod: 'extendVote', + }); - consensusLogger.debug('ExtendVote ABCI method requested'); + contextLogger.debug('ExtendVote ABCI method requested'); const unsignedWithdrawalTransactionsMap = proposalBlockExecutionContext .getWithdrawalTransactionsMap(); @@ -50,7 +50,7 @@ function extendVoteHandlerFactory(proposalBlockExecutionContext) { Math.min(30, extensionString.length), ); - consensusLogger.debug({ + contextLogger.debug({ type, extension: extensionString, }, `Vote extended to obtain ${voteExtensionTypeName} signature for ${extensionTruncatedString}... payload`); diff --git a/packages/js-drive/lib/abci/handlers/finalizeBlockHandlerFactory.js b/packages/js-drive/lib/abci/handlers/finalizeBlockHandlerFactory.js index b09282b9af7..6fcd3703a0b 100644 --- a/packages/js-drive/lib/abci/handlers/finalizeBlockHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/finalizeBlockHandlerFactory.js @@ -19,6 +19,8 @@ const lodashCloneDeep = require('lodash/cloneDeep'); * @param {BlockExecutionContext} latestBlockExecutionContext * @param {BlockExecutionContext} proposalBlockExecutionContext * @param {processProposal} processProposal + * @param {createContextLogger} createContextLogger + * */ function finalizeBlockHandlerFactory( groveDBStore, @@ -29,6 +31,7 @@ function finalizeBlockHandlerFactory( latestBlockExecutionContext, proposalBlockExecutionContext, processProposal, + createContextLogger, ) { /** * @typedef finalizeBlockHandler @@ -43,7 +46,7 @@ function finalizeBlockHandlerFactory( round, } = request; - const consensusLogger = logger.child({ + const contextLogger = createContextLogger(logger, { height: height.toString(), round, abciMethod: 'finalizeBlock', @@ -52,13 +55,13 @@ function finalizeBlockHandlerFactory( const requestToLog = lodashCloneDeep(request); delete requestToLog.block.data; - consensusLogger.debug('FinalizeBlock ABCI method requested'); - consensusLogger.trace({ abciRequest: requestToLog }); + contextLogger.debug('FinalizeBlock ABCI method requested'); + contextLogger.trace({ abciRequest: requestToLog }); const lastProcessedRound = proposalBlockExecutionContext.getRound(); if (lastProcessedRound !== round) { - consensusLogger.warn({ + contextLogger.warn({ lastProcessedRound, round, }, `Finalizing previously executed round ${round} instead of the last known ${lastProcessedRound}`); @@ -88,10 +91,7 @@ function finalizeBlockHandlerFactory( round, }); - await processProposal(processProposalRequest, consensusLogger); - - // Revert consensus logger - proposalBlockExecutionContext.setConsensusLogger(consensusLogger); + await processProposal(processProposalRequest, contextLogger); } proposalBlockExecutionContext.setLastCommitInfo(commitInfo); @@ -138,7 +138,7 @@ function finalizeBlockHandlerFactory( const blockExecutionTimings = executionTimer.stopTimer('blockExecution'); - consensusLogger.info( + contextLogger.info( { timings: blockExecutionTimings, }, diff --git a/packages/js-drive/lib/abci/handlers/infoHandlerFactory.js b/packages/js-drive/lib/abci/handlers/infoHandlerFactory.js index 427637a9d1a..0d056c005d0 100644 --- a/packages/js-drive/lib/abci/handlers/infoHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/infoHandlerFactory.js @@ -17,6 +17,7 @@ const { version: driveVersion } = require('../../../package.json'); * @param {updateSimplifiedMasternodeList} updateSimplifiedMasternodeList * @param {BaseLogger} logger * @param {GroveDBStore} groveDBStore + * @param {createContextLogger} createContextLogger * @return {infoHandler} */ function infoHandlerFactory( @@ -26,6 +27,7 @@ function infoHandlerFactory( updateSimplifiedMasternodeList, logger, groveDBStore, + createContextLogger, ) { /** * Info ABCI handler @@ -36,37 +38,32 @@ function infoHandlerFactory( * @return {Promise} */ async function infoHandler(request) { - let contextLogger = logger.child({ + let contextLogger = createContextLogger(logger, { abciMethod: 'info', }); contextLogger.debug('Info ABCI method requested'); contextLogger.trace({ abciRequest: request }); - // Initialize Block Execution Contexts - - const persistedBlockExecutionContext = await blockExecutionContextRepository.fetch(); - if (persistedBlockExecutionContext) { - latestBlockExecutionContext.populate(persistedBlockExecutionContext); - } - // Initialize current heights let lastHeight = Long.fromNumber(0); let lastCoreChainLockedHeight = 0; - if (!latestBlockExecutionContext.isEmpty()) { + // Initialize latest Block Execution Context + const persistedBlockExecutionContext = await blockExecutionContextRepository.fetch(); + if (!persistedBlockExecutionContext.isEmpty()) { + latestBlockExecutionContext.populate(persistedBlockExecutionContext); + lastHeight = latestBlockExecutionContext.getHeight(); lastCoreChainLockedHeight = latestBlockExecutionContext.getCoreChainLockedHeight(); - } - contextLogger = contextLogger.child({ - height: lastHeight.toString(), - }); + contextLogger = createContextLogger(contextLogger, { + height: lastHeight.toString(), + }); - // Update SML store to latest saved core chain lock to make sure - // that verify chain lock handler has updated SML Store to verify signatures - if (!latestBlockExecutionContext.isEmpty()) { + // Update SML store to latest saved core chain lock to make sure + // that verify chain lock handler has updated SML Store to verify signatures await updateSimplifiedMasternodeList(lastCoreChainLockedHeight, { logger: contextLogger, }); diff --git a/packages/js-drive/lib/abci/handlers/initChainHandlerFactory.js b/packages/js-drive/lib/abci/handlers/initChainHandlerFactory.js index 9db11dd6cec..55baffe64fd 100644 --- a/packages/js-drive/lib/abci/handlers/initChainHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/initChainHandlerFactory.js @@ -22,6 +22,7 @@ const protoTimestampToMillis = require('../../util/protoTimestampToMillis'); * @param {GroveDBStore} groveDBStore * @param {RSAbci} rsAbci * @param {createCoreChainLockUpdate} createCoreChainLockUpdate + * @param {createContextLogger} createContextLogger * @return {initChainHandler} */ function initChainHandlerFactory( @@ -35,6 +36,7 @@ function initChainHandlerFactory( groveDBStore, rsAbci, createCoreChainLockUpdate, + createContextLogger, ) { /** * @typedef initChainHandler @@ -45,17 +47,17 @@ function initChainHandlerFactory( async function initChainHandler(request) { const { time } = request; - const consensusLogger = logger.child({ + const contextLogger = createContextLogger(logger, { height: request.initialHeight.toString(), abciMethod: 'initChain', }); - consensusLogger.debug('InitChain ABCI method requested'); - consensusLogger.trace({ abciRequest: request }); + contextLogger.debug('InitChain ABCI method requested'); + contextLogger.trace({ abciRequest: request }); await updateSimplifiedMasternodeList( initialCoreChainLockedHeight, { - logger: consensusLogger, + logger: contextLogger, }, ); @@ -75,7 +77,7 @@ function initChainHandlerFactory( protoTimestampToMillis(time), ); - await registerSystemDataContracts(consensusLogger, blockInfo); + await registerSystemDataContracts(contextLogger, blockInfo); const synchronizeMasternodeIdentitiesResult = await synchronizeMasternodeIdentities( initialCoreChainLockedHeight, @@ -86,11 +88,11 @@ function initChainHandlerFactory( createdEntities, updatedEntities, removedEntities, fromHeight, toHeight, } = synchronizeMasternodeIdentitiesResult; - consensusLogger.info( + contextLogger.info( `Masternode identities are synced for heights from ${fromHeight} to ${toHeight}: ${createdEntities.length} created, ${updatedEntities.length} updated, ${removedEntities.length} removed`, ); - consensusLogger.trace( + contextLogger.trace( { createdEntities: createdEntities.map((item) => item.toJSON()), updatedEntities: updatedEntities.map((item) => item.toJSON()), @@ -110,16 +112,16 @@ function initChainHandlerFactory( const coreChainLockUpdate = await createCoreChainLockUpdate( initialCoreChainLockedHeight, 0, - consensusLogger, + contextLogger, ); const appHash = await groveDBStore.getRootHash({ useTransaction: true }); await groveDBStore.commitTransaction(); - consensusLogger.trace(validatorSetUpdate, `Validator set initialized with ${quorumHash} quorum`); + contextLogger.trace(validatorSetUpdate, `Validator set initialized with ${quorumHash} quorum`); - consensusLogger.info( + contextLogger.info( { chainId: request.chainId, appHash: appHash.toString('hex').toUpperCase(), diff --git a/packages/js-drive/lib/abci/handlers/prepareProposalHandlerFactory.js b/packages/js-drive/lib/abci/handlers/prepareProposalHandlerFactory.js index 924fe2e25c7..0c0b84d915d 100644 --- a/packages/js-drive/lib/abci/handlers/prepareProposalHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/prepareProposalHandlerFactory.js @@ -24,6 +24,7 @@ const txAction = { * @param {endBlock} endBlock * @param {createCoreChainLockUpdate} createCoreChainLockUpdate * @param {ExecutionTimer} executionTimer + * @param {createContextLogger} createContextLogger * @return {prepareProposalHandler} */ function prepareProposalHandlerFactory( @@ -34,6 +35,7 @@ function prepareProposalHandlerFactory( endBlock, createCoreChainLockUpdate, executionTimer, + createContextLogger, ) { /** * @typedef prepareProposalHandler @@ -53,7 +55,7 @@ function prepareProposalHandlerFactory( round, } = request; - const consensusLogger = logger.child({ + const contextLogger = createContextLogger(logger, { height: height.toString(), round, abciMethod: 'prepareProposal', @@ -62,10 +64,10 @@ function prepareProposalHandlerFactory( const requestToLog = lodashCloneDeep(request); delete requestToLog.txs; - consensusLogger.debug('PrepareProposal ABCI method requested'); - consensusLogger.trace({ abciRequest: requestToLog }); + contextLogger.debug('PrepareProposal ABCI method requested'); + contextLogger.trace({ abciRequest: requestToLog }); - consensusLogger.info(`Preparing a block proposal for height #${height} round #${round}`); + contextLogger.info(`Preparing a block proposal for height #${height} round #${round}`); await beginBlock( { @@ -77,7 +79,7 @@ function prepareProposalHandlerFactory( proposerProTxHash: Buffer.from(proposerProTxHash), round, }, - consensusLogger, + contextLogger, ); let totalSizeBytes = 0; @@ -110,7 +112,7 @@ function prepareProposalHandlerFactory( code, info, fees, - } = await wrappedDeliverTx(tx, round, consensusLogger); + } = await wrappedDeliverTx(tx, round, contextLogger); if (code === 0) { validTxCount += 1; @@ -129,13 +131,10 @@ function prepareProposalHandlerFactory( txResults.push(txResult); } - // Revert consensus logger after deliverTx - proposalBlockExecutionContext.setConsensusLogger(consensusLogger); - const coreChainLockUpdate = await createCoreChainLockUpdate( coreChainLockedHeight, round, - consensusLogger, + contextLogger, ); const { @@ -147,13 +146,13 @@ function prepareProposalHandlerFactory( round, fees: feeResults, coreChainLockedHeight, - }, consensusLogger); + }, contextLogger); const roundExecutionTime = executionTimer.getTimer('roundExecution', true); const mempoolTxCount = txs.length - validTxCount - invalidTxCount; - consensusLogger.info( + contextLogger.info( { roundExecutionTime, validTxCount, diff --git a/packages/js-drive/lib/abci/handlers/processProposalHandlerFactory.js b/packages/js-drive/lib/abci/handlers/processProposalHandlerFactory.js index 33d21bbef7e..ee942a773be 100644 --- a/packages/js-drive/lib/abci/handlers/processProposalHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/processProposalHandlerFactory.js @@ -14,6 +14,7 @@ const statuses = require('./proposal/statuses'); * @param {verifyChainLock} verifyChainLock * @param {processProposal} processProposal * @param {BlockExecutionContext} proposalBlockExecutionContext + * @param {createContextLogger} createContextLogger * @return {processProposalHandler} */ function processProposalHandlerFactory( @@ -21,6 +22,7 @@ function processProposalHandlerFactory( verifyChainLock, processProposal, proposalBlockExecutionContext, + createContextLogger, ) { /** * @typedef processProposalHandler @@ -34,7 +36,7 @@ function processProposalHandlerFactory( round, } = request; - const consensusLogger = logger.child({ + const contextLogger = createContextLogger(logger, { height: height.toString(), round, abciMethod: 'processProposal', @@ -43,8 +45,8 @@ function processProposalHandlerFactory( const requestToLog = lodashCloneDeep(request); delete requestToLog.txs; - consensusLogger.debug('ProcessProposal ABCI method requested'); - consensusLogger.trace({ abciRequest: requestToLog }); + contextLogger.debug('ProcessProposal ABCI method requested'); + contextLogger.trace({ abciRequest: requestToLog }); // Skip process proposal if it was already prepared for this height and round const prepareProposalResult = proposalBlockExecutionContext.getPrepareProposalResult(); @@ -52,7 +54,7 @@ function processProposalHandlerFactory( if (prepareProposalResult && proposalBlockExecutionContext.getHeight().toNumber() === height.toNumber() && proposalBlockExecutionContext.getRound() === round) { - consensusLogger.debug('Skip processing proposal and return prepared result'); + contextLogger.debug('Skip processing proposal and return prepared result'); const { appHash, @@ -74,7 +76,7 @@ function processProposalHandlerFactory( const chainLockIsValid = await verifyChainLock(coreChainLockUpdate); if (!chainLockIsValid) { - consensusLogger.warn({ + contextLogger.warn({ coreChainLockUpdate, }, `Block proposal #${height} round #${round} rejected due to invalid core chain locked height update`); @@ -88,7 +90,7 @@ function processProposalHandlerFactory( }, `ChainLock is valid for height ${coreChainLockUpdate.coreBlockHeight}`); } - return processProposal(request, consensusLogger); + return processProposal(request, contextLogger); } return processProposalHandler; diff --git a/packages/js-drive/lib/abci/handlers/proposal/beginBlockFactory.js b/packages/js-drive/lib/abci/handlers/proposal/beginBlockFactory.js index d5fc50c9a58..d202f09f90a 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/beginBlockFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/beginBlockFactory.js @@ -45,11 +45,11 @@ function beginBlockFactory( * @param {IConsensus} request.version * @param {ITimestamp} request.time * @param {Buffer} request.proposerProTxHash - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * * @return {Promise} */ - async function beginBlock(request, consensusLogger) { + async function beginBlock(request, contextLogger) { const { lastCommitInfo, height, @@ -88,7 +88,7 @@ function beginBlockFactory( // Reset block execution context proposalBlockExecutionContext.reset(); - proposalBlockExecutionContext.setConsensusLogger(consensusLogger); + proposalBlockExecutionContext.setContextLogger(contextLogger); proposalBlockExecutionContext.setHeight(height); proposalBlockExecutionContext.setVersion(version); proposalBlockExecutionContext.setRound(round); @@ -124,7 +124,7 @@ function beginBlockFactory( rsRequest.previousBlockTimeMs = latestBlockExecutionContext.getTimeMs(); } - consensusLogger.debug(rsRequest, 'Request RS Drive\'s BlockBegin method'); + contextLogger.debug(rsRequest, 'Request RS Drive\'s BlockBegin method'); const rsResponse = await rsAbci.blockBegin(rsRequest, true); @@ -153,14 +153,14 @@ function beginBlockFactory( const blockTimeFormatted = new Date(proposalBlockExecutionContext.getTimeMs()).toUTCString(); - consensusLogger.info(debugData, `Epoch #${currentEpochIndex} started on block #${height} at ${blockTimeFormatted}`); + contextLogger.info(debugData, `Epoch #${currentEpochIndex} started on block #${height} at ${blockTimeFormatted}`); } // Update SML const isSimplifiedMasternodeListUpdated = await updateSimplifiedMasternodeList( coreChainLockedHeight, { - logger: consensusLogger, + logger: contextLogger, }, ); @@ -176,12 +176,12 @@ function beginBlockFactory( createdEntities, updatedEntities, removedEntities, fromHeight, toHeight, } = synchronizeMasternodeIdentitiesResult; - consensusLogger.info( + contextLogger.info( `Masternode identities are synced for heights from ${fromHeight} to ${toHeight}: ${createdEntities.length} created, ${updatedEntities.length} updated, ${removedEntities.length} removed`, ); if (createdEntities.length > 0 || updatedEntities.length > 0 || removedEntities.length > 0) { - consensusLogger.trace( + contextLogger.trace( { createdEntities: createdEntities.map((item) => item.toJSON()), updatedEntities: updatedEntities.map((item) => item.toJSON()), diff --git a/packages/js-drive/lib/abci/handlers/proposal/createConsensusParamUpdateFactory.js b/packages/js-drive/lib/abci/handlers/proposal/createConsensusParamUpdateFactory.js index edb2aeb79f1..4ac31ad0377 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/createConsensusParamUpdateFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/createConsensusParamUpdateFactory.js @@ -21,10 +21,10 @@ function createConsensusParamUpdateFactory( * @typedef createConsensusParamUpdate * @param {number} height * @param {number} round - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * @return {Promise} */ - async function createConsensusParamUpdate(height, round, consensusLogger) { + async function createConsensusParamUpdate(height, round, contextLogger) { const contextVersion = proposalBlockExecutionContext.getVersion(); // Update consensus params feature flag @@ -52,7 +52,7 @@ function createConsensusParamUpdateFactory( version, }); - consensusLogger.info( + contextLogger.info( { consensusParamUpdates, }, diff --git a/packages/js-drive/lib/abci/handlers/proposal/createCoreChainLockUpdateFactory.js b/packages/js-drive/lib/abci/handlers/proposal/createCoreChainLockUpdateFactory.js index d13008a3aea..8a712216696 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/createCoreChainLockUpdateFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/createCoreChainLockUpdateFactory.js @@ -17,10 +17,10 @@ function createCoreChainLockUpdateFactory( * @typedef createCoreChainLockUpdate * @param {number} contextCoreChainLockedHeight * @param {number} round - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * @return {Promise} */ - async function createCoreChainLockUpdate(contextCoreChainLockedHeight, round, consensusLogger) { + async function createCoreChainLockUpdate(contextCoreChainLockedHeight, round, contextLogger) { // Update Core Chain Locks const coreChainLock = latestCoreChainLock.getChainLock(); @@ -32,7 +32,7 @@ function createCoreChainLockUpdateFactory( signature: coreChainLock.signature, }); - consensusLogger.debug( + contextLogger.debug( { nextCoreChainLockHeight: coreChainLock.height, }, diff --git a/packages/js-drive/lib/abci/handlers/proposal/deliverTxFactory.js b/packages/js-drive/lib/abci/handlers/proposal/deliverTxFactory.js index 883f4115879..cca94b1ff62 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/deliverTxFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/deliverTxFactory.js @@ -25,6 +25,7 @@ const TIMERS = require('../timers'); * @param {DashPlatformProtocol} transactionalDpp * @param {BlockExecutionContext} proposalBlockExecutionContext * @param {ExecutionTimer} executionTimer + * @param {createContextLogger} createContextLogger * * @return {deliverTx} */ @@ -33,18 +34,19 @@ function deliverTxFactory( transactionalDpp, proposalBlockExecutionContext, executionTimer, + createContextLogger, ) { /** * @typedef deliverTx * * @param {Buffer} stateTransitionByteArray * @param {number} round - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * @return {Promise<{ * code: number, * fees: BlockFeeResult}>} */ - async function deliverTx(stateTransitionByteArray, round, consensusLogger) { + async function deliverTx(stateTransitionByteArray, round, contextLogger) { const blockHeight = proposalBlockExecutionContext.getHeight(); // Start execution timer @@ -65,18 +67,16 @@ function deliverTxFactory( .toString('hex') .toUpperCase(); - const txConsensusLogger = consensusLogger.child({ + const txContextLogger = createContextLogger(contextLogger, { txId: stHash, }); - proposalBlockExecutionContext.setConsensusLogger(txConsensusLogger); - - txConsensusLogger.info(`Deliver state transition ${stHash} from block #${blockHeight}`); + txContextLogger.info(`Deliver state transition ${stHash} from block #${blockHeight}`); const stateTransition = await transactionalUnserializeStateTransition( stateTransitionByteArray, { - logger: txConsensusLogger, + logger: txContextLogger, executionTimer, }, ); @@ -98,8 +98,8 @@ function deliverTxFactory( const consensusError = result.getFirstError(); const message = 'State transition is invalid against the state'; - txConsensusLogger.info(message); - txConsensusLogger.debug({ + txContextLogger.info(message); + txContextLogger.debug({ consensusError, }); @@ -122,7 +122,7 @@ function deliverTxFactory( const actualStateTransitionOperations = stateTransition.getExecutionContext().getOperations(); if (actualStateTransitionFees.total > predictedStateTransitionFees.total) { - txConsensusLogger.warn({ + txContextLogger.warn({ predictedFee: predictedStateTransitionFees.total, actualFee: actualStateTransitionFees.total, }, `Actual fees are greater than predicted for ${actualStateTransitionFees.total - predictedStateTransitionFees.total} credits`); @@ -155,7 +155,7 @@ function deliverTxFactory( const description = DATA_CONTRACT_ACTION_DESCRIPTIONS[stateTransition.getType()]; - txConsensusLogger.info( + txContextLogger.info( { dataContractId: dataContract.getId().toString(), }, @@ -167,7 +167,7 @@ function deliverTxFactory( case stateTransitionTypes.IDENTITY_CREATE: { const identityId = stateTransition.getIdentityId(); - txConsensusLogger.info( + txContextLogger.info( { identityId: identityId.toString(), }, @@ -179,7 +179,7 @@ function deliverTxFactory( case stateTransitionTypes.IDENTITY_TOP_UP: { const identityId = stateTransition.getIdentityId(); - txConsensusLogger.info( + txContextLogger.info( { identityId: identityId.toString(), }, @@ -191,7 +191,7 @@ function deliverTxFactory( case stateTransitionTypes.IDENTITY_UPDATE: { const identityId = stateTransition.getIdentityId(); - txConsensusLogger.info( + txContextLogger.info( { identityId: identityId.toString(), }, @@ -204,7 +204,7 @@ function deliverTxFactory( const description = DOCUMENT_ACTION_DESCRIPTIONS[transition.getAction()]; const dataContract = transition.getDataContract(); - txConsensusLogger.info( + txContextLogger.info( { documentId: transition.getId().toString(), dataContractId: dataContract.getId().toString(), @@ -221,7 +221,7 @@ function deliverTxFactory( const deliverTxTiming = executionTimer.stopTimer(TIMERS.DELIVER_TX.OVERALL); - txConsensusLogger.trace( + txContextLogger.trace( { timings: { overall: deliverTxTiming, diff --git a/packages/js-drive/lib/abci/handlers/proposal/endBlockFactory.js b/packages/js-drive/lib/abci/handlers/proposal/endBlockFactory.js index 0e4fd206282..307e50fd95b 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/endBlockFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/endBlockFactory.js @@ -37,7 +37,7 @@ function endBlockFactory( * feeRefundsSum: number * } request.fees * @param {number} request.coreChainLockedHeight - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * @return {Promise<{ * consensusParamUpdates: ConsensusParams, * validatorSetUpdate: ValidatorSetUpdate, @@ -46,7 +46,7 @@ function endBlockFactory( */ async function endBlock( request, - consensusLogger, + contextLogger, ) { const { height, @@ -61,11 +61,11 @@ function endBlockFactory( fees, }; - consensusLogger.debug(rsRequest, 'Request RS Drive\'s BlockEnd method'); + contextLogger.debug(rsRequest, 'Request RS Drive\'s BlockEnd method'); const rsResponse = await rsAbci.blockEnd(rsRequest, true); - consensusLogger.debug(rsResponse, 'RS Drive\'s BlockEnd method response'); + contextLogger.debug(rsResponse, 'RS Drive\'s BlockEnd method response'); const { currentEpochIndex } = proposalBlockExecutionContext.getEpochInfo(); @@ -76,7 +76,7 @@ function endBlockFactory( } = fees; if (processingFee > 0 || storageFee > 0) { - consensusLogger.debug({ + contextLogger.debug({ currentEpochIndex, processingFee, storageFee, @@ -85,7 +85,7 @@ function endBlockFactory( } if (rsResponse.proposersPaidCount) { - consensusLogger.debug({ + contextLogger.debug({ currentEpochIndex, proposersPaidCount: rsResponse.proposersPaidCount, paidEpochIndex: rsResponse.paidEpochIndex, @@ -93,19 +93,19 @@ function endBlockFactory( } if (rsResponse.refundedEpochsCount) { - consensusLogger.debug({ + contextLogger.debug({ currentEpochIndex, refundedEpochsCount: rsResponse.refundedEpochsCount, }, `${rsResponse.refundedEpochsCount} epochs were refunded`); } - const consensusParamUpdates = await createConsensusParamUpdate(height, round, consensusLogger); + const consensusParamUpdates = await createConsensusParamUpdate(height, round, contextLogger); const validatorSetUpdate = await rotateAndCreateValidatorSetUpdate( height, coreChainLockedHeight, round, - consensusLogger, + contextLogger, ); const appHash = await groveDBStore.getRootHash({ useTransaction: true }); diff --git a/packages/js-drive/lib/abci/handlers/proposal/processProposalFactory.js b/packages/js-drive/lib/abci/handlers/proposal/processProposalFactory.js index d80fb6da913..506c1fc9b57 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/processProposalFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/processProposalFactory.js @@ -29,11 +29,11 @@ function processProposalFactory( ) { /** * @param {abci.RequestProcessProposal} request - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * * @typedef processProposal */ - async function processProposal(request, consensusLogger) { + async function processProposal(request, contextLogger) { const { height, txs, @@ -45,7 +45,7 @@ function processProposalFactory( round, } = request; - consensusLogger.info(`Processing a block proposal for height #${height} round #${round}`); + contextLogger.info(`Processing a block proposal for height #${height} round #${round}`); await beginBlock( { @@ -57,7 +57,7 @@ function processProposalFactory( proposerProTxHash: Buffer.from(proposerProTxHash), round, }, - consensusLogger, + contextLogger, ); const txResults = []; @@ -76,7 +76,7 @@ function processProposalFactory( code, info, fees, - } = await wrappedDeliverTx(tx, round, consensusLogger); + } = await wrappedDeliverTx(tx, round, contextLogger); if (code === 0) { validTxCount += 1; @@ -96,7 +96,7 @@ function processProposalFactory( } // Revert consensus logger after deliverTx - proposalBlockExecutionContext.setConsensusLogger(consensusLogger); + proposalBlockExecutionContext.setContextLogger(contextLogger); const { consensusParamUpdates, @@ -107,11 +107,11 @@ function processProposalFactory( round, fees: feeResults, coreChainLockedHeight, - }, consensusLogger); + }, contextLogger); const roundExecutionTime = executionTimer.getTimer('roundExecution', true); - consensusLogger.info( + contextLogger.info( { roundExecutionTime, validTxCount, diff --git a/packages/js-drive/lib/abci/handlers/proposal/rotateAndCreateValidatorSetUpdateFactory.js b/packages/js-drive/lib/abci/handlers/proposal/rotateAndCreateValidatorSetUpdateFactory.js index 1b02f223a92..9307c5f05c2 100644 --- a/packages/js-drive/lib/abci/handlers/proposal/rotateAndCreateValidatorSetUpdateFactory.js +++ b/packages/js-drive/lib/abci/handlers/proposal/rotateAndCreateValidatorSetUpdateFactory.js @@ -14,14 +14,14 @@ function rotateAndCreateValidatorSetUpdateFactory( * @param {number} height * @param {number} coreChainLockedHeight * @param {number} round - * @param {BaseLogger} consensusLogger + * @param {BaseLogger} contextLogger * @return {Promise} */ async function rotateAndCreateValidatorSetUpdate( height, coreChainLockedHeight, round, - consensusLogger, + contextLogger, ) { const lastCommitInfo = proposalBlockExecutionContext.getLastCommitInfo(); @@ -34,7 +34,7 @@ function rotateAndCreateValidatorSetUpdateFactory( const { quorumHash } = validatorSet.getQuorum(); - consensusLogger.debug( + contextLogger.debug( { quorumHash, }, diff --git a/packages/js-drive/lib/abci/handlers/queryHandlerFactory.js b/packages/js-drive/lib/abci/handlers/queryHandlerFactory.js index 77fd405435f..338538af6a0 100644 --- a/packages/js-drive/lib/abci/handlers/queryHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/queryHandlerFactory.js @@ -5,9 +5,11 @@ const InvalidArgumentAbciError = require('../errors/InvalidArgumentAbciError'); /** * @param {Object} queryHandlerRouter * @param {Function} sanitizeUrl + * @param {BaseLogger} logger + * @param {createContextLogger} createContextLogger * @return {queryHandler} */ -function queryHandlerFactory(queryHandlerRouter, sanitizeUrl) { +function queryHandlerFactory(queryHandlerRouter, sanitizeUrl, logger, createContextLogger) { /** * Query ABCI Handler * @@ -19,6 +21,10 @@ function queryHandlerFactory(queryHandlerRouter, sanitizeUrl) { async function queryHandler(request) { const { path, data } = request; + createContextLogger(logger, { + abciMethod: 'query', + }); + const route = queryHandlerRouter.find('GET', sanitizeUrl(path)); if (!route) { diff --git a/packages/js-drive/lib/abci/handlers/verifyVoteExtensionHandlerFactory.js b/packages/js-drive/lib/abci/handlers/verifyVoteExtensionHandlerFactory.js index 1c5a56479b9..948e539ce0b 100644 --- a/packages/js-drive/lib/abci/handlers/verifyVoteExtensionHandlerFactory.js +++ b/packages/js-drive/lib/abci/handlers/verifyVoteExtensionHandlerFactory.js @@ -22,12 +22,12 @@ function verifyVoteExtensionHandlerFactory(proposalBlockExecutionContext) { * @return {Promise} */ async function verifyVoteExtensionHandler() { - const consensusLogger = proposalBlockExecutionContext.getConsensusLogger() + const contextLogger = proposalBlockExecutionContext.getContextLogger() .child({ abciMethod: 'verifyVoteExtension', }); - consensusLogger.debug('VerifyVote ABCI method requested'); + contextLogger.debug('VerifyVote ABCI method requested'); // TODO Verify withdrawal vote extensions and add logs diff --git a/packages/js-drive/lib/blockExecution/BlockExecutionContext.js b/packages/js-drive/lib/blockExecution/BlockExecutionContext.js index b1c21afa7cd..7f73864d6bf 100644 --- a/packages/js-drive/lib/blockExecution/BlockExecutionContext.js +++ b/packages/js-drive/lib/blockExecution/BlockExecutionContext.js @@ -140,25 +140,25 @@ class BlockExecutionContext { } /** - * Set consensus logger + * Set context logger * * @param {BaseLogger} logger */ - setConsensusLogger(logger) { - this.consensusLogger = logger; + setContextLogger(logger) { + this.contextLogger = logger; } /** - * Get consensus logger + * Get context logger * * @return {BaseLogger} */ - getConsensusLogger() { - if (!this.consensusLogger) { + getContextLogger() { + if (!this.contextLogger) { throw new Error('Consensus logger has not been set'); } - return this.consensusLogger; + return this.contextLogger; } /** @@ -251,7 +251,7 @@ class BlockExecutionContext { this.version = null; this.time = null; this.lastCommitInfo = null; - this.consensusLogger = null; + this.contextLogger = null; this.withdrawalTransactionsMap = {}; this.round = null; this.epochInfo = null; @@ -280,7 +280,7 @@ class BlockExecutionContext { this.height = blockExecutionContext.height; this.coreChainLockedHeight = blockExecutionContext.coreChainLockedHeight; this.version = blockExecutionContext.version; - this.consensusLogger = blockExecutionContext.consensusLogger || null; + this.contextLogger = blockExecutionContext.contextLogger || null; this.withdrawalTransactionsMap = blockExecutionContext.withdrawalTransactionsMap; this.round = blockExecutionContext.round; this.epochInfo = blockExecutionContext.epochInfo; @@ -297,7 +297,7 @@ class BlockExecutionContext { this.dataContracts = object.dataContracts .map((rawDataContract) => new DataContract(rawDataContract)); this.lastCommitInfo = CommitInfo.fromObject(object.lastCommitInfo); - this.consensusLogger = object.consensusLogger; + this.contextLogger = object.contextLogger; this.epochInfo = object.epochInfo; this.timeMs = object.timeMs; this.height = Long.fromNumber(object.height); @@ -310,7 +310,7 @@ class BlockExecutionContext { /** * @param {Object} options - * @param {boolean} [options.skipConsensusLogger=false] + * @param {boolean} [options.skipContextLogger=false] * @param {boolean} [options.skipPrepareProposalResult=false] * @return {{ * dataContracts: Object[], @@ -344,8 +344,8 @@ class BlockExecutionContext { epochInfo: this.epochInfo, }; - if (!options.skipConsensusLogger) { - object.consensusLogger = this.consensusLogger; + if (!options.skipContextLogger) { + object.contextLogger = this.contextLogger; } if (!options.skipPrepareProposalResult) { diff --git a/packages/js-drive/lib/blockExecution/BlockExecutionContextRepository.js b/packages/js-drive/lib/blockExecution/BlockExecutionContextRepository.js index bcd6d45c585..e7e2800ca81 100644 --- a/packages/js-drive/lib/blockExecution/BlockExecutionContextRepository.js +++ b/packages/js-drive/lib/blockExecution/BlockExecutionContextRepository.js @@ -23,7 +23,7 @@ class BlockExecutionContextRepository { await this.db.putAux( BlockExecutionContextRepository.EXTERNAL_STORE_KEY_NAME, await cbor.encodeAsync(blockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })), options, diff --git a/packages/js-drive/lib/createDIContainer.js b/packages/js-drive/lib/createDIContainer.js index b3fe49eed70..f69ad1204f6 100644 --- a/packages/js-drive/lib/createDIContainer.js +++ b/packages/js-drive/lib/createDIContainer.js @@ -8,6 +8,8 @@ const { const fs = require('fs'); +const { AsyncLocalStorage } = require('node:async_hooks'); + const Long = require('long'); const RSDrive = require('@dashevo/rs-drive'); @@ -106,7 +108,7 @@ const waitForChainLockedHeightFactory = require('./core/waitForChainLockedHeight const SimplifiedMasternodeList = require('./core/SimplifiedMasternodeList'); const SpentAssetLockTransactionsRepository = require('./identity/SpentAssetLockTransactionsRepository'); -const enrichErrorWithConsensusErrorFactory = require('./abci/errors/enrichErrorWithConsensusLoggerFactory'); +const enrichErrorWithConsensusErrorFactory = require('./abci/errors/enrichErrorWithContextLoggerFactory'); const closeAbciServerFactory = require('./abci/closeAbciServerFactory'); const getLatestFeatureFlagFactory = require('./featureFlag/getLatestFeatureFlagFactory'); const getFeatureFlagForHeightFactory = require('./featureFlag/getFeatureFlagForHeightFactory'); @@ -138,6 +140,7 @@ const fetchTransactionFactory = require('./core/fetchTransactionFactory'); const LastSyncedCoreHeightRepository = require('./identity/masternode/LastSyncedCoreHeightRepository'); const fetchSimplifiedMNListFactory = require('./core/fetchSimplifiedMNListFactory'); const processProposalFactory = require('./abci/handlers/proposal/processProposalFactory'); +const createContextLoggerFactory = require('./abci/errors/createContextLoggerFactory'); /** * @@ -693,6 +696,8 @@ function createDIContainer(options) { * Register ABCI handlers */ container.register({ + createContextLogger: asFunction(createContextLoggerFactory), + abciAsyncLocalStorage: asValue(new AsyncLocalStorage()), createQueryResponse: asFunction(createQueryResponseFactory).singleton(), createValidatorSetUpdate: asValue(createValidatorSetUpdate), identityQueryHandler: asFunction(identityQueryHandlerFactory).singleton(), @@ -730,11 +735,10 @@ function createDIContainer(options) { wrappedDeliverTx: asFunction(( wrapInErrorHandler, - enrichErrorWithConsensusError, + enrichErrorWithContextError, deliverTx, ) => wrapInErrorHandler( - enrichErrorWithConsensusError(deliverTx), - { respondWithInternalError: true }, + enrichErrorWithContextError(deliverTx), )).singleton(), endBlock: asFunction(endBlockFactory).singleton(), @@ -768,7 +772,7 @@ function createDIContainer(options) { verifyVoteExtensionHandler: asFunction(verifyVoteExtensionHandlerFactory).singleton(), wrapInErrorHandler: asFunction(wrapInErrorHandlerFactory).singleton(), - enrichErrorWithConsensusError: asFunction(enrichErrorWithConsensusErrorFactory).singleton(), + enrichErrorWithContextError: asFunction(enrichErrorWithConsensusErrorFactory).singleton(), errorHandler: asFunction(errorHandlerFactory).singleton(), abciHandlers: asFunction(( @@ -776,7 +780,7 @@ function createDIContainer(options) { checkTxHandler, initChainHandler, wrapInErrorHandler, - enrichErrorWithConsensusError, + enrichErrorWithContextError, queryHandler, extendVoteHandler, finalizeBlockHandler, @@ -784,15 +788,15 @@ function createDIContainer(options) { processProposalHandler, verifyVoteExtensionHandler, ) => ({ - info: infoHandler, - checkTx: wrapInErrorHandler(checkTxHandler, { respondWithInternalError: true }), - initChain: initChainHandler, - query: wrapInErrorHandler(queryHandler, { respondWithInternalError: true }), - extendVote: enrichErrorWithConsensusError(extendVoteHandler), - finalizeBlock: enrichErrorWithConsensusError(finalizeBlockHandler), - prepareProposal: enrichErrorWithConsensusError(prepareProposalHandler), - processProposal: enrichErrorWithConsensusError(processProposalHandler), - verifyVoteExtension: enrichErrorWithConsensusError(verifyVoteExtensionHandler), + info: enrichErrorWithContextError(infoHandler), + checkTx: wrapInErrorHandler(enrichErrorWithContextError(checkTxHandler)), + initChain: enrichErrorWithContextError(initChainHandler), + query: wrapInErrorHandler(enrichErrorWithContextError(queryHandler)), + extendVote: enrichErrorWithContextError(extendVoteHandler), + finalizeBlock: enrichErrorWithContextError(finalizeBlockHandler), + prepareProposal: enrichErrorWithContextError(prepareProposalHandler), + processProposal: enrichErrorWithContextError(processProposalHandler), + verifyVoteExtension: enrichErrorWithContextError(verifyVoteExtensionHandler), })).singleton(), closeAbciServer: asFunction(closeAbciServerFactory).singleton(), diff --git a/packages/js-drive/lib/dpp/LoggedStateRepositoryDecorator.js b/packages/js-drive/lib/dpp/LoggedStateRepositoryDecorator.js index 591e580409e..46fe71eca5b 100644 --- a/packages/js-drive/lib/dpp/LoggedStateRepositoryDecorator.js +++ b/packages/js-drive/lib/dpp/LoggedStateRepositoryDecorator.js @@ -21,7 +21,7 @@ class LoggedStateRepositoryDecorator { * @param {object} response - response of the state repository call */ log(method, parameters, response) { - const logger = this.blockExecutionContext.getConsensusLogger(); + const logger = this.blockExecutionContext.getContextLogger(); logger.trace({ stateRepository: { diff --git a/packages/js-drive/lib/errorHandlerFactory.js b/packages/js-drive/lib/errorHandlerFactory.js index cf06daf200b..7172646507a 100644 --- a/packages/js-drive/lib/errorHandlerFactory.js +++ b/packages/js-drive/lib/errorHandlerFactory.js @@ -37,7 +37,10 @@ function errorHandlerFactory(logger, container, closeAbciServer) { console.log(printErrorFace()); errors.forEach((e) => { - (error.consensusLogger || logger).fatal({ err: e }, e.message); + const preferredLogger = e.contextLogger || logger; + delete e.contextLogger; + + preferredLogger.fatal({ err: e }, e.message); }); } finally { await container.dispose(); diff --git a/packages/js-drive/lib/test/fixtures/getBlockExecutionContextObjectFixture.js b/packages/js-drive/lib/test/fixtures/getBlockExecutionContextObjectFixture.js index c9abca30cd6..e0d0de4daa1 100644 --- a/packages/js-drive/lib/test/fixtures/getBlockExecutionContextObjectFixture.js +++ b/packages/js-drive/lib/test/fixtures/getBlockExecutionContextObjectFixture.js @@ -25,7 +25,7 @@ const { hash } = require('@dashevo/dpp/lib/util/hash'); * version: number, * timeMs: number, * validTxs: number, - * consensusLogger: Logger, + * contextLogger: Logger, * withdrawalTransactionsMap: Object, * round: number, * }} @@ -52,7 +52,7 @@ function getBlockExecutionContextObjectFixture(dataContract = getDataContractFix height: 10, coreChainLockedHeight: 10, version, - consensusLogger: pino(), + contextLogger: pino(), epochInfo: { height: 1, timeMs: 100, diff --git a/packages/js-drive/lib/test/mock/BlockExecutionContextMock.js b/packages/js-drive/lib/test/mock/BlockExecutionContextMock.js index dd2f95d5bee..82c68b9b5c2 100644 --- a/packages/js-drive/lib/test/mock/BlockExecutionContextMock.js +++ b/packages/js-drive/lib/test/mock/BlockExecutionContextMock.js @@ -11,8 +11,8 @@ * @method getLastCommitInfo * @method getValidTxCount * @method getInvalidTxCount - * @method setConsensusLogger - * @method getConsensusLogger + * @method setContextLogger + * @method getContextLogger * @method getRound * @method fromObject * @method toObject @@ -40,8 +40,8 @@ class BlockExecutionContextMock { this.getVersion = sinon.stub(); this.setLastCommitInfo = sinon.stub(); this.getLastCommitInfo = sinon.stub(); - this.setConsensusLogger = sinon.stub(); - this.getConsensusLogger = sinon.stub(); + this.setContextLogger = sinon.stub(); + this.getContextLogger = sinon.stub(); this.setWithdrawalTransactionsMap = sinon.stub(); this.getWithdrawalTransactionsMap = sinon.stub(); this.getRound = sinon.stub(); diff --git a/packages/js-drive/test/integration/abci/handlers/queryHandlerFactory.spec.js b/packages/js-drive/test/integration/abci/handlers/queryHandlerFactory.spec.js index a5f55f9405d..a06c3c3e9a4 100644 --- a/packages/js-drive/test/integration/abci/handlers/queryHandlerFactory.spec.js +++ b/packages/js-drive/test/integration/abci/handlers/queryHandlerFactory.spec.js @@ -49,7 +49,8 @@ describe('queryHandlerFactory', function main() { container.register('dataContractQueryHandler', asValue(dataContractQueryHandlerMock)); container.register('documentQueryHandler', asValue(documentQueryHandlerMock)); - queryHandler = container.resolve('queryHandler'); + const enrichErrorWithContextError = container.resolve('enrichErrorWithContextError'); + queryHandler = enrichErrorWithContextError(container.resolve('queryHandler')); }); afterEach(async () => { diff --git a/packages/js-drive/test/integration/blockExecution/BlockExecutionContextRepository.spec.js b/packages/js-drive/test/integration/blockExecution/BlockExecutionContextRepository.spec.js index 6895d6e4359..4d453ade22a 100644 --- a/packages/js-drive/test/integration/blockExecution/BlockExecutionContextRepository.spec.js +++ b/packages/js-drive/test/integration/blockExecution/BlockExecutionContextRepository.spec.js @@ -57,7 +57,7 @@ describe('BlockExecutionContextRepository', () => { const rawBlockExecutionContext = cbor.decode(blockExecutionContextEncoded); expect(rawBlockExecutionContext).to.deep.equal(blockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })); }); @@ -66,7 +66,7 @@ describe('BlockExecutionContextRepository', () => { await store.putAux( BlockExecutionContextRepository.EXTERNAL_STORE_KEY_NAME, await cbor.encodeAsync(blockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, })), options, ); @@ -76,10 +76,10 @@ describe('BlockExecutionContextRepository', () => { expect(fetchedBlockExecutionContext).to.be.instanceOf(BlockExecutionContext); expect(fetchedBlockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })).to.deep.equal(blockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })); }); @@ -102,10 +102,10 @@ describe('BlockExecutionContextRepository', () => { expect(fetchedBlockExecutionContext).to.be.instanceOf(BlockExecutionContext); expect(fetchedBlockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })).to.deep.equal(blockExecutionContext.toObject({ - skipConsensusLogger: true, + skipContextLogger: true, skipPrepareProposalResult: true, })); }); diff --git a/packages/js-drive/test/unit/abci/errors/enrichErrorWithConsensusLoggerFactory.spec.js b/packages/js-drive/test/unit/abci/errors/enrichErrorWithConsensusLoggerFactory.spec.js deleted file mode 100644 index 7ed0c86195a..00000000000 --- a/packages/js-drive/test/unit/abci/errors/enrichErrorWithConsensusLoggerFactory.spec.js +++ /dev/null @@ -1,39 +0,0 @@ -const enrichErrorWithConsensusLoggerFactory = require('../../../../lib/abci/errors/enrichErrorWithConsensusLoggerFactory'); -const BlockExecutionContextMock = require('../../../../lib/test/mock/BlockExecutionContextMock'); -const LoggerMock = require('../../../../lib/test/mock/LoggerMock'); - -describe('enrichErrorWithConsensusLoggerFactory', () => { - let blockExecutionContextMock; - let enrichErrorWithConsensusLogger; - let loggerMock; - - beforeEach(function beforeEach() { - loggerMock = new LoggerMock(this.sinon); - - blockExecutionContextMock = new BlockExecutionContextMock(this.sinon); - blockExecutionContextMock.consensusLogger = loggerMock; - - enrichErrorWithConsensusLogger = enrichErrorWithConsensusLoggerFactory( - blockExecutionContextMock, - ); - }); - - it('should add consensusLogger from BlockExecutionContext to thrown error', async () => { - const error = new Error(); - - const method = () => { - throw error; - }; - - const methodHandler = enrichErrorWithConsensusLogger(method); - - try { - await methodHandler(); - - expect.fail('should throw an error'); - } catch (e) { - expect(e).to.equal(error); - expect(e.consensusLogger).to.equal(loggerMock); - } - }); -}); diff --git a/packages/js-drive/test/unit/abci/errors/enrichErrorWithContextLoggerFactory.spec.js b/packages/js-drive/test/unit/abci/errors/enrichErrorWithContextLoggerFactory.spec.js new file mode 100644 index 00000000000..d182a4caf3b --- /dev/null +++ b/packages/js-drive/test/unit/abci/errors/enrichErrorWithContextLoggerFactory.spec.js @@ -0,0 +1,38 @@ +const { AsyncLocalStorage } = require('node:async_hooks'); +const enrichErrorWithContextLoggerFactory = require('../../../../lib/abci/errors/enrichErrorWithContextLoggerFactory'); +const LoggerMock = require('../../../../lib/test/mock/LoggerMock'); + +describe('enrichErrorWithContextLoggerFactory', () => { + let enrichErrorWithContextLogger; + let loggerMock; + let asyncLocalStorage; + + beforeEach(function beforeEach() { + loggerMock = new LoggerMock(this.sinon); + + asyncLocalStorage = new AsyncLocalStorage(); + + enrichErrorWithContextLogger = enrichErrorWithContextLoggerFactory(asyncLocalStorage); + }); + + it('should add contextLogger from BlockExecutionContext to thrown error', async () => { + const error = new Error('my error'); + + const method = async () => { + asyncLocalStorage.getStore().set('logger', loggerMock); + + throw error; + }; + + const methodHandler = enrichErrorWithContextLogger(method); + + try { + await methodHandler(); + + expect.fail('should throw an error'); + } catch (e) { + expect(e).to.equal(error); + expect(e.contextLogger).to.equal(loggerMock); + } + }); +}); diff --git a/packages/js-drive/test/unit/abci/errors/wrapInErrorHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/errors/wrapInErrorHandlerFactory.spec.js index fb51a98d179..cfda8a6f1d8 100644 --- a/packages/js-drive/test/unit/abci/errors/wrapInErrorHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/errors/wrapInErrorHandlerFactory.spec.js @@ -28,36 +28,6 @@ describe('wrapInErrorHandlerFactory', () => { ); }); - it('should throw an internal error if any Error is thrown in handler', async () => { - const error = new Error('Custom error'); - - methodMock.throws(error); - - try { - await handler(request); - - expect.fail('Internal error must be thrown'); - } catch (e) { - expect(e).to.equal(error); - } - }); - - it('should throw en internal error if an InternalAbciError is thrown in handler', async () => { - const originError = new Error(); - const metadata = { sample: 'data' }; - const error = new InternalAbciError(originError, metadata); - - methodMock.throws(error); - - try { - await handler(request); - - expect.fail('Internal error must be thrown'); - } catch (e) { - expect(e).to.equal(originError); - } - }); - it('should respond with internal error code if any Error is thrown in handler and respondWithInternalError enabled', async () => { handler = wrapInErrorHandler( methodMock, { respondWithInternalError: true }, diff --git a/packages/js-drive/test/unit/abci/handlers/checkTxHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/checkTxHandlerFactory.spec.js index 00f48adde14..fd4a5621278 100644 --- a/packages/js-drive/test/unit/abci/handlers/checkTxHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/checkTxHandlerFactory.spec.js @@ -9,12 +9,15 @@ const { const getIdentityCreateTransitionFixture = require('@dashevo/dpp/lib/test/fixtures/getIdentityCreateTransitionFixture'); const checkTxHandlerFactory = require('../../../../lib/abci/handlers/checkTxHandlerFactory'); +const LoggerMock = require('../../../../lib/test/mock/LoggerMock'); describe('checkTxHandlerFactory', () => { let checkTxHandler; let request; let stateTransitionFixture; let unserializeStateTransitionMock; + let loggerMock; + let createContextLoggerMock; beforeEach(function beforeEach() { stateTransitionFixture = getIdentityCreateTransitionFixture(); @@ -26,8 +29,13 @@ describe('checkTxHandlerFactory', () => { unserializeStateTransitionMock = this.sinon.stub() .resolves(stateTransitionFixture); + loggerMock = new LoggerMock(this.sinon); + createContextLoggerMock = this.sinon.stub(); + checkTxHandler = checkTxHandlerFactory( unserializeStateTransitionMock, + createContextLoggerMock, + loggerMock, ); }); @@ -38,5 +46,9 @@ describe('checkTxHandlerFactory', () => { expect(response.code).to.equal(0); expect(unserializeStateTransitionMock).to.be.calledOnceWith(request.tx); + + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + abciMethod: 'checkTx', + }); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/extendVoteHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/extendVoteHandlerFactory.spec.js index 5c313aefbe0..3d646e40a31 100644 --- a/packages/js-drive/test/unit/abci/handlers/extendVoteHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/extendVoteHandlerFactory.spec.js @@ -16,17 +16,24 @@ const LoggerMock = require('../../../../lib/test/mock/LoggerMock'); describe('extendVoteHandlerFactory', () => { let extendVoteHandler; let blockExecutionContextMock; + let createContextLoggerMock; + let loggerMock; beforeEach(function beforeEach() { blockExecutionContextMock = new BlockExecutionContextMock(this.sinon); - const loggerMock = new LoggerMock(this.sinon); + loggerMock = new LoggerMock(this.sinon); - blockExecutionContextMock.getConsensusLogger.returns(loggerMock); + blockExecutionContextMock.getContextLogger.returns(loggerMock); blockExecutionContextMock.getWithdrawalTransactionsMap.returns({}); - extendVoteHandler = extendVoteHandlerFactory(blockExecutionContextMock); + createContextLoggerMock = this.sinon.stub().returns(loggerMock); + + extendVoteHandler = extendVoteHandlerFactory( + blockExecutionContextMock, + createContextLoggerMock, + ); }); it('should return ResponseExtendVote with vote extensions if withdrawal transactions are present', async () => { @@ -53,5 +60,9 @@ describe('extendVoteHandlerFactory', () => { extension: hash(txTwoBytes), }, ]); + + expect(createContextLoggerMock).to.be.calledOnceWith(loggerMock, { + abciMethod: 'extendVote', + }); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/finalizeBlockHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/finalizeBlockHandlerFactory.spec.js index 919fe252f06..062329f12bc 100644 --- a/packages/js-drive/test/unit/abci/handlers/finalizeBlockHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/finalizeBlockHandlerFactory.spec.js @@ -32,6 +32,7 @@ describe('finalizeBlockHandlerFactory', () => { let round; let block; let processProposalMock; + let createContextLoggerMock; beforeEach(function beforeEach() { round = 0; @@ -97,6 +98,7 @@ describe('finalizeBlockHandlerFactory', () => { ); processProposalMock = this.sinon.stub(); + createContextLoggerMock = this.sinon.stub().returns(loggerMock); finalizeBlockHandler = finalizeBlockHandlerFactory( groveDBStoreMock, @@ -107,6 +109,7 @@ describe('finalizeBlockHandlerFactory', () => { latestBlockExecutionContextMock, proposalBlockExecutionContextMock, processProposalMock, + createContextLoggerMock, ); }); @@ -130,6 +133,13 @@ describe('finalizeBlockHandlerFactory', () => { expect(latestBlockExecutionContextMock.populate).to.be.calledOnce(); expect(processProposalMock).to.be.not.called(); + expect(createContextLoggerMock).to.be.calledOnceWithExactly( + loggerMock, { + height: '42', + round, + abciMethod: 'finalizeBlock', + }, + ); }); it('should send withdrawal transaction if vote extensions are present', async () => { @@ -160,6 +170,13 @@ describe('finalizeBlockHandlerFactory', () => { expect(coreRpcClientMock.sendRawTransaction).to.have.been.calledTwice(); expect(processProposalMock).to.be.not.called(); + expect(createContextLoggerMock).to.be.calledOnceWithExactly( + loggerMock, { + height: '42', + round, + abciMethod: 'finalizeBlock', + }, + ); }); it('should call processProposal if round is not equal to execution context', async () => { @@ -181,5 +198,12 @@ describe('finalizeBlockHandlerFactory', () => { }); expect(processProposalMock).to.be.calledOnceWithExactly(processProposalRequest, loggerMock); + expect(createContextLoggerMock).to.be.calledOnceWithExactly( + loggerMock, { + height: '42', + round, + abciMethod: 'finalizeBlock', + }, + ); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/infoHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/infoHandlerFactory.spec.js index 0701535ea36..c97411142b7 100644 --- a/packages/js-drive/test/unit/abci/handlers/infoHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/infoHandlerFactory.spec.js @@ -28,6 +28,7 @@ describe('infoHandlerFactory', () => { let blockExecutionContextMock; let blockExecutionContextRepositoryMock; let groveDBStoreMock; + let createContextLoggerMock; beforeEach(function beforeEach() { lastBlockHeight = Long.fromInt(0); @@ -51,6 +52,8 @@ describe('infoHandlerFactory', () => { groveDBStoreMock.getRootHash.resolves(lastBlockAppHash); + createContextLoggerMock = this.sinon.stub().returns(loggerMock); + infoHandler = infoHandlerFactory( blockExecutionContextMock, blockExecutionContextRepositoryMock, @@ -58,11 +61,12 @@ describe('infoHandlerFactory', () => { updateSimplifiedMasternodeListMock, loggerMock, groveDBStoreMock, + createContextLoggerMock, ); }); it('should return respond with genesis heights and app hash on the first run', async () => { - blockExecutionContextRepositoryMock.fetch.resolves(null); + blockExecutionContextRepositoryMock.fetch.resolves(blockExecutionContextMock); blockExecutionContextMock.getHeight.returns(null); blockExecutionContextMock.isEmpty.returns(true); @@ -83,6 +87,11 @@ describe('infoHandlerFactory', () => { expect(blockExecutionContextMock.getCoreChainLockedHeight).to.not.be.called(); expect(updateSimplifiedMasternodeListMock).to.not.be.called(); expect(groveDBStoreMock.getRootHash).to.be.calledOnce(); + expect(createContextLoggerMock).to.be.calledOnceWithExactly( + loggerMock, { + abciMethod: 'info', + }, + ); }); it('should populate context and update SML on subsequent runs', async () => { @@ -105,5 +114,16 @@ describe('infoHandlerFactory', () => { logger: loggerMock, }, ); + expect(createContextLoggerMock).to.be.calledTwice(); + expect(createContextLoggerMock.getCall(0)).to.be.calledWithExactly( + loggerMock, { + abciMethod: 'info', + }, + ); + expect(createContextLoggerMock.getCall(1)).to.be.calledWithExactly( + loggerMock, { + height: lastBlockHeight.toString(), + }, + ); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/initChainHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/initChainHandlerFactory.spec.js index f637a2cca3f..17616434537 100644 --- a/packages/js-drive/test/unit/abci/handlers/initChainHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/initChainHandlerFactory.spec.js @@ -34,6 +34,7 @@ describe('initChainHandlerFactory', () => { let rsAbciMock; let createCoreChainLockUpdateMock; let coreChainLockUpdate; + let createContextLoggerMock; beforeEach(function beforeEach() { initialCoreChainLockedHeight = 1; @@ -78,6 +79,7 @@ describe('initChainHandlerFactory', () => { }); createCoreChainLockUpdateMock = this.sinon.stub().resolves(coreChainLockUpdate); + createContextLoggerMock = this.sinon.stub().returns(loggerMock); initChainHandler = initChainHandlerFactory( updateSimplifiedMasternodeListMock, @@ -90,6 +92,7 @@ describe('initChainHandlerFactory', () => { groveDBStoreMock, rsAbciMock, createCoreChainLockUpdateMock, + createContextLoggerMock, ); }); @@ -147,5 +150,9 @@ describe('initChainHandlerFactory', () => { expect(createCoreChainLockUpdateMock) .to.be.calledOnceWithExactly(initialCoreChainLockedHeight, 0, loggerMock); + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + height: request.initialHeight.toString(), + abciMethod: 'initChain', + }); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/prepareProposalHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/prepareProposalHandlerFactory.spec.js index c52e03cb2b0..2bb3e3f5640 100644 --- a/packages/js-drive/test/unit/abci/handlers/prepareProposalHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/prepareProposalHandlerFactory.spec.js @@ -33,6 +33,7 @@ describe('prepareProposalHandlerFactory', () => { let proposalBlockExecutionContextMock; let round; let executionTimerMock; + let createContextLoggerMock; beforeEach(function beforeEach() { round = 1; @@ -93,6 +94,7 @@ describe('prepareProposalHandlerFactory', () => { executionTimerMock = { getTimer: this.sinon.stub().returns(0.1), }; + createContextLoggerMock = this.sinon.stub().returns(loggerMock); prepareProposalHandler = prepareProposalHandlerFactory( deliverTxMock, @@ -102,6 +104,7 @@ describe('prepareProposalHandlerFactory', () => { endBlockMock, updateCoreChainLockMock, executionTimerMock, + createContextLoggerMock, ); const maxTxBytes = 42; @@ -198,6 +201,11 @@ describe('prepareProposalHandlerFactory', () => { consensusParamUpdates, validatorSetUpdate, }); + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + height: '42', + round, + abciMethod: 'prepareProposal', + }); }); it('should cut txs that are not fit into the size limit', async () => { diff --git a/packages/js-drive/test/unit/abci/handlers/processProposalHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/processProposalHandlerFactory.spec.js index 647901fc7e9..ccb4b0deb5f 100644 --- a/packages/js-drive/test/unit/abci/handlers/processProposalHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/processProposalHandlerFactory.spec.js @@ -28,6 +28,7 @@ describe('processProposalHandlerFactory', () => { let proposalBlockExecutionContextMock; let consensusParamUpdates; let validatorSetUpdate; + let createContextLoggerMock; beforeEach(function beforeEach() { round = 0; @@ -57,12 +58,14 @@ describe('processProposalHandlerFactory', () => { verifyChainLockMock = this.sinon.stub().resolves(true); processProposalMock = this.sinon.stub().resolves(new ResponseProcessProposal({ status: 1 })); + createContextLoggerMock = this.sinon.stub().returns(loggerMock); processProposalHandler = processProposalHandlerFactory( loggerMock, verifyChainLockMock, processProposalMock, proposalBlockExecutionContextMock, + createContextLoggerMock, ); const txs = new Array(3).fill(Buffer.alloc(5, 0)); @@ -148,5 +151,10 @@ describe('processProposalHandlerFactory', () => { expect(processProposalMock).to.not.be.called(); expect(verifyChainLockMock).to.not.be.called(); + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + height: '42', + round, + abciMethod: 'processProposal', + }); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/proposal/beginBlockFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/proposal/beginBlockFactory.spec.js index 51d7d9dface..00f37b1c502 100644 --- a/packages/js-drive/test/unit/abci/handlers/proposal/beginBlockFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/proposal/beginBlockFactory.spec.js @@ -171,7 +171,7 @@ describe('beginBlockFactory', () => { expect(executionTimerMock.startTimer.getCall(1)).to.be.calledWithExactly('roundExecution'); expect(executionTimerMock.startTimer.getCall(0)).to.be.calledWithExactly('blockExecution'); - expect(proposalBlockExecutionContextMock.setConsensusLogger) + expect(proposalBlockExecutionContextMock.setContextLogger) .to.be.calledOnceWithExactly(loggerMock); expect(proposalBlockExecutionContextMock.setHeight) .to.be.calledOnceWithExactly(blockHeight); diff --git a/packages/js-drive/test/unit/abci/handlers/proposal/deliverTxFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/proposal/deliverTxFactory.spec.js index 91e4e6793d9..27313697037 100644 --- a/packages/js-drive/test/unit/abci/handlers/proposal/deliverTxFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/proposal/deliverTxFactory.spec.js @@ -1,21 +1,22 @@ +const crypto = require('crypto'); + const DashPlatformProtocol = require('@dashevo/dpp'); const ValidationResult = require('@dashevo/dpp/lib/validation/ValidationResult'); const getIdentityFixture = require('@dashevo/dpp/lib/test/fixtures/getIdentityFixture'); - const createDPPMock = require('@dashevo/dpp/lib/test/mocks/createDPPMock'); const createStateRepositoryMock = require('@dashevo/dpp/lib/test/mocks/createStateRepositoryMock'); const getDataContractFixture = require('@dashevo/dpp/lib/test/fixtures/getDataContractFixture'); const getDocumentFixture = require('@dashevo/dpp/lib/test/fixtures/getDocumentsFixture'); const GrpcErrorCodes = require('@dashevo/grpc-common/lib/server/error/GrpcErrorCodes'); + const StateTransitionExecutionContext = require('@dashevo/dpp/lib/stateTransition/StateTransitionExecutionContext'); const SomeConsensusError = require('@dashevo/dpp/lib/test/mocks/SomeConsensusError'); - const BlockExecutionContextMock = require('../../../../../lib/test/mock/BlockExecutionContextMock'); -const deliverTxFactory = require('../../../../../lib/abci/handlers/proposal/deliverTxFactory'); +const deliverTxFactory = require('../../../../../lib/abci/handlers/proposal/deliverTxFactory'); const LoggerMock = require('../../../../../lib/test/mock/LoggerMock'); const DPPValidationAbciError = require('../../../../../lib/abci/errors/DPPValidationAbciError'); const InvalidArgumentAbciError = require('../../../../../lib/abci/errors/InvalidArgumentAbciError'); @@ -39,6 +40,7 @@ describe('deliverTxFactory', () => { let round; let proposalBlockExecutionContextMock; let stateTransitionExecutionContextMock; + let createContextLoggerMock; beforeEach(async function beforeEach() { round = 42; @@ -105,11 +107,14 @@ describe('deliverTxFactory', () => { isStarted: this.sinon.stub(), }; + createContextLoggerMock = this.sinon.stub().returns(loggerMock); + deliverTx = deliverTxFactory( unserializeStateTransitionMock, dppMock, proposalBlockExecutionContextMock, executionTimerMock, + createContextLoggerMock, ); }); @@ -148,6 +153,17 @@ describe('deliverTxFactory', () => { identity.reduceBalance(stateTransitionExecutionContextMock.getLastCalculatedFeeDetails().total); expect(stateRepositoryMock.updateIdentity).to.be.calledOnceWith(identity); + + const stHash = crypto + .createHash('sha256') + .update(documentTx) + .digest() + .toString('hex') + .toUpperCase(); + + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + txId: stHash, + }); }); it('should apply a DataContractCreateTransition, add it to block execution state and return ResponseDeliverTx', async () => { diff --git a/packages/js-drive/test/unit/abci/handlers/queryHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/queryHandlerFactory.spec.js index d7027723173..bac844658ee 100644 --- a/packages/js-drive/test/unit/abci/handlers/queryHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/queryHandlerFactory.spec.js @@ -12,6 +12,7 @@ describe('queryHandlerFactory', () => { let request; let routeMock; let loggerMock; + let createContextLoggerMock; beforeEach(function beforeEach() { request = { @@ -32,10 +33,13 @@ describe('queryHandlerFactory', () => { find: this.sinon.stub().returns(routeMock), }; + createContextLoggerMock = this.sinon.stub(); + queryHandler = queryHandlerFactory( queryHandlerRouterMock, sanitizeUrlMock, loggerMock, + createContextLoggerMock, ); }); @@ -118,5 +122,8 @@ describe('queryHandlerFactory', () => { expect(queryHandlerRouterMock.find).to.be.calledOnceWith('GET', sanitizedUrl); expect(routeMock.handler).to.be.calledOnceWith(routeMock.params, encodedData, request); expect(result).to.equal(data); + expect(createContextLoggerMock).to.be.calledOnceWithExactly(loggerMock, { + abciMethod: 'query', + }); }); }); diff --git a/packages/js-drive/test/unit/abci/handlers/verifyVoteExtensionHandlerFactory.spec.js b/packages/js-drive/test/unit/abci/handlers/verifyVoteExtensionHandlerFactory.spec.js index d1821dc96de..722f1443d1d 100644 --- a/packages/js-drive/test/unit/abci/handlers/verifyVoteExtensionHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/abci/handlers/verifyVoteExtensionHandlerFactory.spec.js @@ -17,7 +17,7 @@ describe('verifyVoteExtensionHandlerFactory', () => { proposalBlockExecutionContextMock = new BlockExecutionContextMock(this.sinon); const loggerMock = new LoggerMock(this.sinon); - proposalBlockExecutionContextMock.getConsensusLogger.returns(loggerMock); + proposalBlockExecutionContextMock.getContextLogger.returns(loggerMock); verifyVoteExtensionHandler = verifyVoteExtensionHandlerFactory( proposalBlockExecutionContextMock, diff --git a/packages/js-drive/test/unit/blockExecution/BlockExecutionContext.spec.js b/packages/js-drive/test/unit/blockExecution/BlockExecutionContext.spec.js index 90b09bbb355..778713b9d4d 100644 --- a/packages/js-drive/test/unit/blockExecution/BlockExecutionContext.spec.js +++ b/packages/js-drive/test/unit/blockExecution/BlockExecutionContext.spec.js @@ -37,7 +37,7 @@ describe('BlockExecutionContext', () => { lastCommitInfo = CommitInfo.fromObject(plainObject.lastCommitInfo); - logger = plainObject.consensusLogger; + logger = plainObject.contextLogger; height = Long.fromNumber(plainObject.height); coreChainLockedHeight = plainObject.coreChainLockedHeight; version = Consensus.fromObject(plainObject.version); @@ -283,7 +283,7 @@ describe('BlockExecutionContext', () => { anotherBlockExecutionContext.height = height; anotherBlockExecutionContext.version = version; anotherBlockExecutionContext.coreChainLockedHeight = coreChainLockedHeight; - anotherBlockExecutionContext.consensusLogger = logger; + anotherBlockExecutionContext.contextLogger = logger; anotherBlockExecutionContext.withdrawalTransactionsMap = plainObject .withdrawalTransactionsMap; anotherBlockExecutionContext.epochInfo = epochInfo; @@ -306,8 +306,8 @@ describe('BlockExecutionContext', () => { expect(blockExecutionContext.coreChainLockedHeight).to.equal( anotherBlockExecutionContext.coreChainLockedHeight, ); - expect(blockExecutionContext.consensusLogger).to.equal( - anotherBlockExecutionContext.consensusLogger, + expect(blockExecutionContext.contextLogger).to.equal( + anotherBlockExecutionContext.contextLogger, ); expect(blockExecutionContext.withdrawalTransactionsMap).to.equal( anotherBlockExecutionContext.withdrawalTransactionsMap, @@ -328,7 +328,7 @@ describe('BlockExecutionContext', () => { blockExecutionContext.height = height; blockExecutionContext.coreChainLockedHeight = coreChainLockedHeight; blockExecutionContext.version = version; - blockExecutionContext.consensusLogger = logger; + blockExecutionContext.contextLogger = logger; blockExecutionContext.epochInfo = epochInfo; blockExecutionContext.timeMs = timeMs; blockExecutionContext.withdrawalTransactionsMap = plainObject.withdrawalTransactionsMap; @@ -338,22 +338,22 @@ describe('BlockExecutionContext', () => { expect(blockExecutionContext.toObject()).to.deep.equal(plainObject); }); - it('should skipConsensusLogger if the option passed', () => { + it('should skipContextLogger if the option passed', () => { blockExecutionContext.dataContracts = [dataContract]; blockExecutionContext.lastCommitInfo = lastCommitInfo; blockExecutionContext.height = height; blockExecutionContext.coreChainLockedHeight = coreChainLockedHeight; blockExecutionContext.version = version; - blockExecutionContext.consensusLogger = logger; + blockExecutionContext.contextLogger = logger; blockExecutionContext.withdrawalTransactionsMap = plainObject.withdrawalTransactionsMap; blockExecutionContext.round = plainObject.round; blockExecutionContext.epochInfo = epochInfo; blockExecutionContext.timeMs = timeMs; blockExecutionContext.prepareProposalResult = prepareProposalResult; - const result = blockExecutionContext.toObject({ skipConsensusLogger: true }); + const result = blockExecutionContext.toObject({ skipContextLogger: true }); - delete plainObject.consensusLogger; + delete plainObject.contextLogger; expect(result).to.deep.equal(plainObject); }); @@ -364,7 +364,7 @@ describe('BlockExecutionContext', () => { blockExecutionContext.height = height; blockExecutionContext.coreChainLockedHeight = coreChainLockedHeight; blockExecutionContext.version = version; - blockExecutionContext.consensusLogger = logger; + blockExecutionContext.contextLogger = logger; blockExecutionContext.withdrawalTransactionsMap = plainObject.withdrawalTransactionsMap; blockExecutionContext.round = plainObject.round; blockExecutionContext.epochInfo = epochInfo; @@ -393,7 +393,7 @@ describe('BlockExecutionContext', () => { expect(blockExecutionContext.height).to.deep.equal(height); expect(blockExecutionContext.version).to.deep.equal(version); expect(blockExecutionContext.coreChainLockedHeight).to.deep.equal(coreChainLockedHeight); - expect(blockExecutionContext.consensusLogger).to.equal(logger); + expect(blockExecutionContext.contextLogger).to.equal(logger); expect(blockExecutionContext.withdrawalTransactionsMap).to.deep.equal( plainObject.withdrawalTransactionsMap, ); diff --git a/packages/js-drive/test/unit/dpp/LoggedStateRepositoryDecorator.spec.js b/packages/js-drive/test/unit/dpp/LoggedStateRepositoryDecorator.spec.js index 81d9e3da579..6d277c074ea 100644 --- a/packages/js-drive/test/unit/dpp/LoggedStateRepositoryDecorator.spec.js +++ b/packages/js-drive/test/unit/dpp/LoggedStateRepositoryDecorator.spec.js @@ -19,7 +19,7 @@ describe('LoggedStateRepositoryDecorator', () => { loggerMock = new LoggerMock(this.sinon); blockExecutionContextMock = new BlockExecutionContextMock(this.sinon); - blockExecutionContextMock.getConsensusLogger.returns(loggerMock); + blockExecutionContextMock.getContextLogger.returns(loggerMock); loggedStateRepositoryDecorator = new LoggedStateRepositoryDecorator( stateRepositoryMock, diff --git a/packages/js-drive/test/unit/util/errorHandlerFactory.spec.js b/packages/js-drive/test/unit/util/errorHandlerFactory.spec.js index eed07ae33d8..466f87948a4 100644 --- a/packages/js-drive/test/unit/util/errorHandlerFactory.spec.js +++ b/packages/js-drive/test/unit/util/errorHandlerFactory.spec.js @@ -48,12 +48,14 @@ describe('errorHandlerFactory', () => { it('should use consensus logger if it\'s present', async function it() { const error = new Error('message'); - error.consensusLogger = new LoggerMock(this.sinon); + const contextLogger = new LoggerMock(this.sinon); + + error.contextLogger = contextLogger; await errorHandler(error); expect(loggerMock.fatal).to.not.be.called(); - expect(error.consensusLogger.fatal).to.be.calledOnceWithExactly({ err: error }, error.message); + expect(contextLogger.fatal).to.be.calledOnceWithExactly({ err: error }, error.message); expect(containerMock.dispose).to.be.calledOnceWithExactly();