diff --git a/lib/blockchainexplorers/insight.js b/lib/blockchainexplorers/insight.js index 614c68b..04a4ddb 100644 --- a/lib/blockchainexplorers/insight.js +++ b/lib/blockchainexplorers/insight.js @@ -41,6 +41,16 @@ Insight.prototype._doRequest = function(args, cb) { 'User-Agent': this.userAgent, } }; + + if (log.level == 'verbose') { + var s = JSON.stringify(args); + + if ( s.length > 100 ) + s= s.substr(0,100) + '...'; + + log.debug('', 'Insight Q: %s', s); + } + requestList(_.defaults(args, opts), cb); }; @@ -59,9 +69,10 @@ Insight.prototype.getUtxos = function(addresses, cb) { json: { addrs: _.uniq([].concat(addresses)).join(',') }, - timeout: 120000, }; + log.info('','Querying utxos: %s addrs', addresses.length); + this._doRequest(args, function(err, res, unspent) { if (err || res.statusCode !== 200) return cb(_parseErr(err, res)); return cb(null, unspent); @@ -122,6 +133,9 @@ Insight.prototype.getTransactions = function(addresses, from, to, cb) { timeout: 120000, }; + + log.info('','Querying addresses: %s addrs', addresses.length); + this._doRequest(args, function(err, res, txs) { if (err || res.statusCode !== 200) return cb(_parseErr(err, res)); diff --git a/lib/blockchainexplorers/request-list.js b/lib/blockchainexplorers/request-list.js index 93fb650..8c7f4c5 100644 --- a/lib/blockchainexplorers/request-list.js +++ b/lib/blockchainexplorers/request-list.js @@ -31,11 +31,23 @@ var requestList = function(args, cb) { async.whilst( function() { nextUrl = urls.shift(); + if (!nextUrl && success === 'false') + log.warn('no more servers to test for the request'); return nextUrl && !success; }, function(a_cb) { args.uri = nextUrl; + + var time = 0; + var interval = setInterval(function() { + time += 10; + log.debug('', 'Delayed insight query: %s, time: %d s', args.uri, time); + }, 10000); + request(args, function(err, res, body) { + clearInterval(interval); + sucess = false; + if (err) { log.warn('REQUEST FAIL: ' + nextUrl + ' ERROR: ' + err); } diff --git a/lib/errors/errordefinitions.js b/lib/errors/errordefinitions.js index 245fb20..a69017e 100644 --- a/lib/errors/errordefinitions.js +++ b/lib/errors/errordefinitions.js @@ -33,7 +33,7 @@ var errors = { UPGRADE_NEEDED: 'Client app needs to be upgraded', WALLET_ALREADY_EXISTS: 'Wallet already exists', WALLET_FULL: 'Wallet full', - WALLET_LOCKED: 'Wallet is busy, try later', + WALLET_BUSY: 'Wallet is busy, try later', WALLET_NOT_COMPLETE: 'Wallet is not complete', WALLET_NOT_FOUND: 'Wallet not found', }; diff --git a/lib/expressapp.js b/lib/expressapp.js index 98b62fe..657ab71 100644 --- a/lib/expressapp.js +++ b/lib/expressapp.js @@ -17,7 +17,7 @@ var Stats = require('./stats'); log.disableColor(); log.debug = log.verbose; -log.level = 'info'; +log.level = 'verbose'; var ExpressApp = function() { this.app = express(); @@ -75,14 +75,10 @@ ExpressApp.prototype.start = function(opts, cb) { } else { var morgan = require('morgan'); morgan.token('walletId', function getId(req) { - return req.walletId + return req.walletId ? '<' + req.walletId + '>' : '<>'; }); - morgan.token('copayerId', function getId(req) { - return req.copayerId - }); - - var logFormat = ':remote-addr :date[iso] ":method :url" :status :res[content-length] :response-time ":user-agent" :walletId :copayerId'; + var logFormat = ':walletId :remote-addr :date[iso] ":method :url" :status :res[content-length] :response-time ":user-agent" '; var logOpts = { skip: function(req, res) { if (res.statusCode != 200) return false; @@ -141,6 +137,7 @@ ExpressApp.prototype.start = function(opts, cb) { }; function getServer(req, res) { + log.heading = '<>'; var opts = { clientVersion: req.header('x-client-version'), }; @@ -183,6 +180,8 @@ ExpressApp.prototype.start = function(opts, cb) { req.walletId = server.walletId; req.copayerId = server.copayerId; + log.heading = '<' + req.walletId + '>'; + return cb(server); }); }; diff --git a/lib/lock.js b/lib/lock.js index 0dd2e69..caeb18d 100644 --- a/lib/lock.js +++ b/lib/lock.js @@ -31,7 +31,7 @@ Lock.prototype.runLocked = function(token, cb, task) { $.shouldBeDefined(token); this.lock.locked(token, 5 * 1000, 5 * 60 * 1000, function(err, release) { - if (err) return cb(Errors.WALLET_LOCKED); + if (err) return cb(Errors.WALLET_BUSY); var _cb = function() { cb.apply(null, arguments); release(); diff --git a/lib/server.js b/lib/server.js index 5cb776e..032fa2b 100644 --- a/lib/server.js +++ b/lib/server.js @@ -1399,11 +1399,13 @@ WalletService.prototype.getBalance = function(opts, cb, i) { var now = Math.floor(Date.now() / 1000); if (twoStepCache.lastEmpty > now - Defaults.TWO_STEP_INACTIVE_CLEAN_DURATION_MIN * 60 ) { + log.debug('Not running the FULL balance query due to TWO_STEP_INACTIVE_CLEAN_DURATION_MIN '); return; } setTimeout(function() { + log.debug('Running full balance query'); self._getBalanceOneStep(opts, function(err, fullBalance) { if (err) return; if (!_.isEqual(partialBalance, fullBalance)) { diff --git a/test/integration/server.js b/test/integration/server.js index 42f3d20..bfc9889 100644 --- a/test/integration/server.js +++ b/test/integration/server.js @@ -2335,6 +2335,78 @@ describe('Wallet service', function() { }); }); + it('should do 2 steps if called 2 times given the first one there found no funds on non-active addresses, but times passes', function(done) { + var oldAddrs, newAddrs, spy; + + async.series([ + function(next) { + spy = sinon.spy(server, '_getBalanceOneStep'); + helpers.createAddresses(server, wallet, 2, 0, function(addrs) { + oldAddrs = addrs; + next(); + }); + }, + function(next) { + clock.tick(7 * Defaults.TWO_STEP_CREATION_HOURS * 3600 * 1000); + helpers.createAddresses(server, wallet, 2, 0, function(addrs) { + newAddrs = addrs; + helpers.stubUtxos(server, wallet, [1, 2], { + addresses: newAddrs, + }, function() { + next(); + }); + }); + }, + function(next) { + server.getBalance({ + twoStep: true + }, function(err, balance) { + should.not.exist(err); + should.exist(balance); + balance.totalAmount.should.equal(helpers.toSatoshi(3)); + next(); + }); + }, + function(next) { + setTimeout(next, 100); + }, + // Should _oneStep should be called once + function(next) { + spy.calledOnce.should.equal(true); + next(); + }, + function(next) { + helpers.stubUtxos(server, wallet, 0.5, { + addresses: newAddrs[0], + keepUtxos: true, + }, function() { + clock.tick(2 * Defaults.TWO_STEP_INACTIVE_CLEAN_DURATION_MIN * 60 * 1000); + next(); + }); + }, + function(next) { + server.getBalance({ + twoStep: true + }, function(err, balance) { + should.not.exist(err); + should.exist(balance); + balance.totalAmount.should.equal(helpers.toSatoshi(3.5)); + next(); + }); + }, + function(next) { + setTimeout(next, 100); + }, + function(next) { + spy.calledTwice.should.equal(true); + next(); + }, + ], function(err) { + should.not.exist(err); + done(); + }); + }); + it('should do 2 steps if called 2 times given the first one there found funds on non-active addresses', function(done) { var oldAddrs, newAddrs, spy, notificationCount;