diff --git a/lib/bcoin/chain.js b/lib/bcoin/chain.js index 1b124d1a..9fdb962c 100644 --- a/lib/bcoin/chain.js +++ b/lib/bcoin/chain.js @@ -78,6 +78,7 @@ function Chain(options) { this.synced = false; this.state = new DeploymentState(); this.stateCache = {}; + this._time = utils.hrtime(); this.orphan = { map: {}, @@ -103,18 +104,6 @@ Chain.prototype._init = function _init() { self.logger.warning('Warning: %dmb of pending objects. Purging.', utils.mb(size)); }); - // Hook into events for debugging - this.on('block', function(block, entry) { - if (!self.synced && self.height < self.network.block.slowHeight) - return; - - if (self.options.spv) - return; - - self.logger.info('Block %s (%d) added to chain.', - entry.rhash, entry.height); - }); - this.on('competitor', function(block, entry) { self.logger.warning('Heads up: Competing chain at height %d:' + ' tip-height=%d competitor-height=%d' @@ -1336,7 +1325,6 @@ Chain.prototype.isBusy = function isBusy() { Chain.prototype.add = function add(block, callback, force) { var self = this; - var total = 0; var ret = {}; var unlock; @@ -1351,10 +1339,11 @@ Chain.prototype.add = function add(block, callback, force) { (function next(block, initial) { var hash = block.hash('hex'); - var prevHash = block.prevBlock; + var prevBlock = block.prevBlock; var height, checkpoint, orphan, entry; self.currentBlock = hash; + self._mark(); function handleOrphans() { // No orphan chain. @@ -1372,7 +1361,7 @@ Chain.prototype.add = function add(block, callback, force) { } // Do not revalidate known invalid blocks. - if (self.invalid[hash] || self.invalid[prevHash]) { + if (self.invalid[hash] || self.invalid[prevBlock]) { self.emit('invalid', block, block.getCoinbaseHeight()); self.invalid[hash] = true; return done(new VerifyError(block, 'duplicate', 'duplicate', 100)); @@ -1386,7 +1375,7 @@ Chain.prototype.add = function add(block, callback, force) { // If the block is already known to be // an orphan, ignore it. - orphan = self.orphan.map[prevHash]; + orphan = self.orphan.map[prevBlock]; if (orphan) { // The orphan chain forked. if (orphan.hash('hex') !== hash) { @@ -1425,7 +1414,7 @@ Chain.prototype.add = function add(block, callback, force) { } // Find the previous block height/index. - self.db.get(prevHash, function(err, prev) { + self.db.get(prevBlock, function(err, prev) { if (err) return done(err); @@ -1441,7 +1430,7 @@ Chain.prototype.add = function add(block, callback, force) { if (!prev) { self.orphan.count++; self.orphan.size += block.getSize(); - self.orphan.map[prevHash] = block; + self.orphan.map[prevBlock] = block; self.orphan.bmap[hash] = block; // Update the best height based on the coinbase. @@ -1516,9 +1505,8 @@ Chain.prototype.add = function add(block, callback, force) { if (err) return done(err); - // Keep track of the number of blocks we - // added and the number of orphans resolved. - total++; + // Keep track of stats. + self._done(block, entry); // Emit our block (and potentially resolved // orphan) only if it is on the main chain. @@ -1536,9 +1524,8 @@ Chain.prototype.add = function add(block, callback, force) { if (err) return done(err); - // Keep track of the number of blocks we - // added and the number of orphans resolved. - total++; + // Keep track of stats. + self._done(block, entry); // Emit our block (and potentially resolved // orphan) only if it is on the main chain. @@ -1560,15 +1547,6 @@ Chain.prototype.add = function add(block, callback, force) { if (self.orphan.size > self.orphanLimit) self.pruneOrphans(); - // Keep track of total blocks handled. - self.total += total; - - // Report memory for debugging. - if (self.total === 1 || self.total % 20 === 0) { - utils.gc(); - self.logger.memory(); - } - utils.nextTick(function() { if (!self.synced && self.isFull()) { self.synced = true; @@ -1577,14 +1555,69 @@ Chain.prototype.add = function add(block, callback, force) { self.currentBlock = null; - if (err) - callback(err); - else - callback(null, total); + callback(err); }); } }; +/** + * Test whether the chain has reached its slow height. + * @private + * @returns {Boolean} + */ + +Chain.prototype._isSlow = function _isSlow() { + if (this.options.spv) + return false; + + if (this.total === 1 || this.total % 20 === 0) + return true; + + return this.synced || this.height >= this.network.block.slowHeight; +}; + +/** + * Mark the start time for block processing. + * @private + */ + +Chain.prototype._mark = function _mark() { + this._time = utils.hrtime(); +}; + +/** + * Calculate the time difference from + * start time and log block. + * @private + * @param {Block} block + * @param {ChainEntry} entry + */ + +Chain.prototype._done = function _done(block, entry) { + var elapsed, time; + + // Keep track of total blocks handled. + this.total += 1; + + if (!this._isSlow()) + return; + + // Report memory for debugging. + utils.gc(); + this.logger.memory(); + + elapsed = utils.hrtime(this._time); + time = elapsed[0] * 1000 + elapsed[1] / 1e6; + + this.logger.info( + 'Block %s (%d) added to chain (size=%d, txs=%d time=%d).', + entry.rhash, + entry.height, + block.getSize(), + block.txs.length, + time); +}; + /** * Purge any waiting orphans. */ diff --git a/lib/bcoin/pool.js b/lib/bcoin/pool.js index b38ff054..7fc83ad5 100644 --- a/lib/bcoin/pool.js +++ b/lib/bcoin/pool.js @@ -893,11 +893,10 @@ Pool.prototype._handleBlock = function _handleBlock(block, peer, callback) { if (self.logger.level === 4 && self.chain.total % 20 === 0) { self.logger.debug('Status:' - + ' tip=%s ts=%s height=%d progress=%s' + + ' ts=%s height=%d progress=%s' + ' blocks=%d orphans=%d active=%d' + ' queue=%d target=%s peers=%d' + ' pending=%d highest=%d jobs=%d', - block.rhash, utils.date(block.ts), self.chain.height, (self.chain.getProgress() * 100).toFixed(2) + '%', diff --git a/lib/bcoin/protocol/network.js b/lib/bcoin/protocol/network.js index 53e42613..651f4e69 100644 --- a/lib/bcoin/protocol/network.js +++ b/lib/bcoin/protocol/network.js @@ -286,7 +286,7 @@ main.block = { * logs without spamming. */ - slowHeight: 400000 + slowHeight: 325000 }; /** diff --git a/lib/bcoin/utils.js b/lib/bcoin/utils.js index c5f65040..a55da1b2 100644 --- a/lib/bcoin/utils.js +++ b/lib/bcoin/utils.js @@ -383,6 +383,29 @@ utils.getMerkleBranch = crypto.getMerkleBranch; utils.checkMerkleBranch = crypto.checkMerkleBranch; +/** + * Return hrtime (shim for browser). + * @param {Array} time + * @returns {Array} + */ + +utils.hrtime = function hrtime(time) { + var now, ms, sec; + + if (utils.isBrowser) { + now = utils.ms(); + if (time) { + time = time[0] * 1000 + time[1] / 1e6; + now -= time; + } + ms = now % 1000; + sec = (now - ms) / 1000; + return [sec, ms * 1e6]; + } + + return process.hrtime(time); +}; + /** * Test whether a string is hex. Note that this * _could_ yield a false positive on base58