Comparing version 5.0.2-510 to 5.0.2-517
@@ -73,2 +73,3 @@ /// <reference types="bunyan" /> | ||
private addPreviousBlockToHistory; | ||
private loggedGetBlock; | ||
private logForkDetected; | ||
@@ -75,0 +76,0 @@ private logForkResolved; |
@@ -32,3 +32,3 @@ "use strict"; | ||
this.initialized = false; | ||
const optionsWithDefaults = Object.assign({ startAtBlock: 1, onlyIrreversible: false }, options); | ||
const optionsWithDefaults = Object.assign({ startAtBlock: 1, onlyIrreversible: false, logLevel: 'info' }, options); | ||
this.startAtBlock = optionsWithDefaults.startAtBlock; | ||
@@ -38,2 +38,3 @@ this.currentBlockNumber = optionsWithDefaults.startAtBlock - 1; | ||
this.log = BunyanProvider_1.BunyanProvider.getLogger(); | ||
this.log.level(optionsWithDefaults.logLevel); | ||
} | ||
@@ -55,5 +56,10 @@ /** | ||
if (!this.initialized) { | ||
this.log.info('Action Reader was not initialized before started, so it is being initialized now'); | ||
yield this.initialize(); | ||
} | ||
this.log.debug('Getting last irreversible block number...'); | ||
const lastIrreversibleStart = Date.now(); | ||
this.lastIrreversibleBlockNumber = yield this.getLastIrreversibleBlockNumber(); | ||
const lastIrreversibleTime = Date.now() - lastIrreversibleStart; | ||
this.log.debug(`Got last irreversible block number: ${this.lastIrreversibleBlockNumber} (${lastIrreversibleTime}ms)`); | ||
if (this.currentBlockNumber === this.headBlockNumber) { | ||
@@ -63,3 +69,3 @@ this.headBlockNumber = yield this.getLatestNeededBlockNumber(); | ||
if (this.currentBlockNumber < this.headBlockNumber) { | ||
const unvalidatedBlockData = yield this.getBlock(this.currentBlockNumber + 1); | ||
const unvalidatedBlockData = yield this.loggedGetBlock(this.currentBlockNumber + 1, 'next block'); | ||
const expectedHash = this.currentBlockData.blockInfo.blockHash; | ||
@@ -95,5 +101,12 @@ const actualHash = this.currentBlockNumber ? | ||
return __awaiter(this, void 0, void 0, function* () { | ||
this.log.debug('Initializing Action Reader...'); | ||
const setupStart = Date.now(); | ||
yield this.setup(); | ||
const betweenSetupAndInit = Date.now(); | ||
yield this.initBlockState(); | ||
this.initialized = true; | ||
const setupTime = betweenSetupAndInit - setupStart; | ||
const initTime = Date.now() - betweenSetupAndInit; | ||
const initializeTime = setupTime + initTime; | ||
this.log.debug(`Initialized Action Reader (${setupTime}ms setup + ${initTime}ms block state init = ${initializeTime}ms)`); | ||
}); | ||
@@ -110,2 +123,4 @@ } | ||
return __awaiter(this, void 0, void 0, function* () { | ||
this.log.debug(`Seeking to block ${blockNumber}...`); | ||
const seekStart = Date.now(); | ||
this.headBlockNumber = yield this.getLatestNeededBlockNumber(); | ||
@@ -120,2 +135,4 @@ if (blockNumber < this.startAtBlock) { | ||
yield this.reloadHistory(); | ||
const seekTime = Date.now() - seekStart; | ||
this.log.debug(`Seeked to block ${blockNumber} (${seekTime}ms)`); | ||
}); | ||
@@ -152,3 +169,3 @@ } | ||
this.log.info(`Refetching Block ${this.currentBlockData.blockInfo.blockNumber}...`); | ||
this.currentBlockData = yield this.getBlock(this.currentBlockData.blockInfo.blockNumber); | ||
this.currentBlockData = yield this.loggedGetBlock(this.currentBlockData.blockInfo.blockNumber, 'resolving fork'); | ||
const { blockInfo: currentBlockInfo } = this.currentBlockData; | ||
@@ -187,3 +204,8 @@ const { blockInfo: previousBlockInfo } = previousBlockData; | ||
else { | ||
return this.getHeadBlockNumber(); | ||
const headBlockFetchStart = Date.now(); | ||
this.log.debug('Getting head block number...'); | ||
const headBlockNumber = yield this.getHeadBlockNumber(); | ||
const headBlockFetchTime = Date.now() - headBlockFetchStart; | ||
this.log.debug(`Got head block number: ${headBlockNumber} (${headBlockFetchTime}ms)`); | ||
return headBlockNumber; | ||
} | ||
@@ -229,3 +251,3 @@ }); | ||
this.blockHistory = [defaultBlock]; | ||
this.currentBlockData = yield this.getBlock(1); | ||
this.currentBlockData = yield this.loggedGetBlock(1, 'reloading history first block edge case'); | ||
return; | ||
@@ -243,3 +265,3 @@ } | ||
for (const blockNumber of historyRange) { | ||
const historyBlock = yield this.getBlock(blockNumber); | ||
const historyBlock = yield this.loggedGetBlock(blockNumber, 'reloading history'); | ||
if (this.blockHistory.length === 0) { | ||
@@ -251,2 +273,6 @@ this.blockHistory.push(historyBlock); | ||
if (latestHistoryBlockHash !== historyBlock.blockInfo.previousBlockHash) { | ||
this.log.info('Microforked while reloading history!'); | ||
this.log.info(` EXPECTED: ${latestHistoryBlockHash}`); | ||
this.log.info(` RECEIVED: ${historyBlock.blockInfo.previousBlockHash}`); | ||
this.log.info(`Scrapping history and trying again (try ${tryCount + 1})`); | ||
microForked = true; | ||
@@ -270,5 +296,15 @@ break; | ||
} | ||
this.blockHistory.push(yield this.getBlock(this.currentBlockData.blockInfo.blockNumber - 1)); | ||
this.blockHistory.push(yield this.loggedGetBlock(this.currentBlockData.blockInfo.blockNumber - 1, 'populating history')); | ||
}); | ||
} | ||
loggedGetBlock(blockNumber, logContext) { | ||
return __awaiter(this, void 0, void 0, function* () { | ||
const getBlockStart = Date.now(); | ||
this.log.debug(`Getting block ${blockNumber}... (${logContext})`); | ||
const block = yield this.getBlock(blockNumber); | ||
const getBlockFetchTime = Date.now() - getBlockStart; | ||
this.log.debug(`Got block ${blockNumber} (${getBlockFetchTime}ms; ${block.actions.length} actions)`); | ||
return block; | ||
}); | ||
} | ||
logForkDetected(unvalidatedBlockData, expectedHash, actualHash) { | ||
@@ -275,0 +311,0 @@ this.log.info('!! FORK DETECTED !!'); |
@@ -26,6 +26,7 @@ "use strict"; | ||
this.clean = true; | ||
const optionsWithDefault = Object.assign({ pollInterval: 250, velocitySampleSize: 20 }, options); | ||
const optionsWithDefault = Object.assign({ pollInterval: 250, velocitySampleSize: 20, logLevel: 'info' }, options); | ||
this.pollInterval = optionsWithDefault.pollInterval; | ||
this.velocitySampleSize = optionsWithDefault.velocitySampleSize; | ||
this.log = BunyanProvider_1.BunyanProvider.getLogger(); | ||
this.log.level(optionsWithDefault.logLevel); | ||
} | ||
@@ -57,3 +58,3 @@ /** | ||
const startTime = Date.now(); | ||
this.log.debug('Checking for blocks'); | ||
this.log.debug('Checking for blocks...'); | ||
try { | ||
@@ -140,4 +141,5 @@ yield this.checkForBlocks(isReplay); | ||
const readStartTime = Date.now(); | ||
this.log.debug(`Processing block ${this.actionReader.currentBlockNumber + 1}...`); | ||
const nextBlock = yield this.actionReader.getNextBlock(); | ||
const readDuration = readStartTime - Date.now(); | ||
const readDuration = Date.now() - readStartTime; | ||
if (!nextBlock.blockMeta.isNewBlock) { | ||
@@ -149,12 +151,10 @@ break; | ||
const handleEndTime = Date.now(); | ||
const handleDuration = handleStartTime - handleEndTime; | ||
this.log.info(`Processed block ${nextBlock.block.blockInfo.blockNumber}`); | ||
this.log.debug(`${readDuration}ms read + ${handleDuration}ms handle = ${readDuration + handleDuration}ms`); | ||
const handleDuration = handleEndTime - handleStartTime; | ||
const processDuration = readDuration + handleDuration; | ||
const blockNumber = nextBlock.block.blockInfo.blockNumber; | ||
this.log.info(`Processed block ${blockNumber} (${processDuration}ms; ${nextBlock.block.actions.length} actions)`); | ||
this.log.debug(`Block ${blockNumber} read time: ${readDuration}ms; Handle time: ${handleDuration}ms`); | ||
this.addProcessInterval(readStartTime, handleEndTime); | ||
if (nextBlockNumberNeeded) { | ||
const seekStartTime = Date.now(); | ||
yield this.actionReader.seekToBlock(nextBlockNumberNeeded); | ||
const seekDuration = seekStartTime - Date.now(); | ||
this.log.info(`Seeked to block ${nextBlockNumberNeeded}`); | ||
this.log.debug(`Seek time: ${seekDuration}ms`); | ||
} | ||
@@ -161,0 +161,0 @@ headBlockNumber = this.actionReader.headBlockNumber; |
@@ -0,1 +1,2 @@ | ||
import { LogLevel } from 'bunyan'; | ||
export interface ActionReaderOptions { | ||
@@ -15,2 +16,3 @@ /** | ||
onlyIrreversible?: boolean; | ||
logLevel?: LogLevel; | ||
} | ||
@@ -20,2 +22,3 @@ export interface ActionWatcherOptions { | ||
velocitySampleSize?: number; | ||
logLevel?: LogLevel; | ||
} | ||
@@ -22,0 +25,0 @@ export interface ExpressActionWatcherOptions extends ActionWatcherOptions { |
{ | ||
"name": "demux", | ||
"version": "5.0.2-510", | ||
"version": "5.0.2-517", | ||
"author": { | ||
@@ -5,0 +5,0 @@ "name": "block.one", |
Sorry, the diff of this file is not supported yet
Sorry, the diff of this file is not supported yet
Sorry, the diff of this file is not supported yet
License Policy Violation
LicenseThis package is not allowed per your license policy. Review the package's license to ensure compliance.
Found 1 instance in 1 package
License Policy Violation
LicenseThis package is not allowed per your license policy. Review the package's license to ensure compliance.
Found 1 instance in 1 package
114654
1594