feat(drive): ABCI context logger

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;

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;

packages/js-drive/lib/abci/errors/wrapInErrorHandlerFactory.js

@@ -15,56 +15,42 @@ 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
      */
     async function methodErrorHandler(...args) {
       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();
       }
     }
 

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<abci.ResponseCheckTx>}
    */
   async function checkTxHandler({ tx: stateTransitionByteArray }) {
+    createContextLogger(logger, {
+      abciMethod: 'checkTx',
+    });
+
     await unserializeStateTransition(stateTransitionByteArray);
 
     return new ResponseCheckTx();

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<abci.ResponseExtendVote>}
    */
   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`);

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,
       },

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<ResponseInfo>}
    */
   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,
       });