From 764c3bccce4d5a2ca283372953efe8c72bb1f766 Mon Sep 17 00:00:00 2001 From: Pedro Branco Date: Thu, 26 Jan 2017 19:06:47 +0000 Subject: [PATCH] Add request logging --- README.md | 59 +++++- package.json | 2 + src/index.js | 8 +- src/logging/request-logger.js | 22 +++ src/logging/request-obfuscator.js | 117 ++++++++++++ src/methods.js | 242 ++++++++++++++---------- test/logging/request-obfuscator_test.js | 118 ++++++++++++ 7 files changed, 454 insertions(+), 114 deletions(-) create mode 100644 src/logging/request-logger.js create mode 100644 src/logging/request-obfuscator.js create mode 100644 test/logging/request-obfuscator_test.js diff --git a/README.md b/README.md index acd0fff..5de2725 100644 --- a/README.md +++ b/README.md @@ -17,15 +17,16 @@ npm install bitcoin-core --save 1. `[agentOptions]` _(Object)_: Optional `agent` [options](https://github.com/request/request#using-optionsagentoptions) to configure SSL/TLS. 2. `[headers=false]` _(boolean)_: Whether to return the response headers. 3. `[host=localhost]` _(string)_: The host to connect to. -4. `[network=mainnet]` _(string)_: The network -5. `[password]` _(string)_: The RPC server user password. -6. `[port=[network]]` _(string)_: The RPC server port. -7. `[ssl]` _(boolean|Object)_: Whether to use SSL/TLS with strict checking (_boolean_) or an expanded config (_Object_). -8. `[ssl.enabled]` _(boolean)_: Whether to use SSL/TLS. -9. `[ssl.strict]` _(boolean)_: Whether to do strict SSL/TLS checking (certificate must match host). -10. `[timeout=30000]` _(number)_: How long until the request times out (ms). -11. `[username]` _(number)_: The RPC server user name. -12. `[version]` _(string)_: Which version to check methods for ([read more](#versionchecking)). +4. `[logger=debugnyan('bitcoin-core')]` _(Function)_: Custom logger (by default, `debugnyan`). +5. `[network=mainnet]` _(string)_: The network +6. `[password]` _(string)_: The RPC server user password. +7. `[port=[network]]` _(string)_: The RPC server port. +8. `[ssl]` _(boolean|Object)_: Whether to use SSL/TLS with strict checking (_boolean_) or an expanded config (_Object_). +9. `[ssl.enabled]` _(boolean)_: Whether to use SSL/TLS. +10. `[ssl.strict]` _(boolean)_: Whether to do strict SSL/TLS checking (certificate must match host). +11. `[timeout=30000]` _(number)_: How long until the request times out (ms). +12. `[username]` _(number)_: The RPC server user name. +13. `[version]` _(string)_: Which version to check methods for ([read more](#versionchecking)). ### Examples #### Using network mode @@ -348,6 +349,46 @@ const client = new Client({ }); ``` +## Logging + +By default, all requests made with `bitcoin-core` are logged using [seegno/debugnyan](https://github.com/seegno/debugnyan) with `bitcoin-core` as the logging namespace. + +Please note that all sensitive data is obfuscated before calling the logger. + +#### Example + +Example output defining the environment variable `DEBUG=bitcoin-core`: + +```javascript +const client = new Client(); + +client.getTransactionByHash('b4dd08f32be15d96b7166fd77afd18aece7480f72af6c9c7f9c5cbeb01e686fe'); + +// { +// "name": "bitcoin-core", +// "hostname": "localhost", +// "pid": 57908, +// "level": 20, +// "request": { +// "headers": { +// "host": "localhost:8332", +// "accept": "application/json" +// }, +// "id": "82cea4e5-2c85-4284-b9ec-e5876c84e67c", +// "method": "GET", +// "type": "request", +// "uri": "http://localhost:8332/rest/tx/b4dd08f32be15d96b7166fd77afd18aece7480f72af6c9c7f9c5cbeb01e686fe.json" +// }, +// "msg": "Making request 82cea4e5-2c85-4284-b9ec-e5876c84e67c to GET http://localhost:8332/rest/tx/b4dd08f32be15d96b7166fd77afd18aece7480f72af6c9c7f9c5cbeb01e686fe.json", +// "time": "2017-02-07T14:40:35.020Z", +// "v": 0 +// } +``` + +### Custom logger + +A custom logger can be passed via the `logger` option and it should implement [bunyan's log levels](https://github.com/trentm/node-bunyan#levels). + ## Tests Currently the test suite is tailored for Docker (including `docker-compose`) due to the multitude of different `bitcoind` configurations that are required in order to get the test suite passing. diff --git a/package.json b/package.json index 10946a4..4340d7a 100644 --- a/package.json +++ b/package.json @@ -35,7 +35,9 @@ "version": "npm run changelog --future-release=$npm_package_version && npm run transpile && git add -A CHANGELOG.md dist" }, "dependencies": { + "@uphold/request-logger": "^1.2.0", "bluebird": "^3.4.1", + "debugnyan": "^1.0.0", "lodash": "^4.0.0", "request": "^2.53.0", "semver": "^5.1.0", diff --git a/src/index.js b/src/index.js index d480c83..5de0d1a 100755 --- a/src/index.js +++ b/src/index.js @@ -7,8 +7,9 @@ import Parser from './parser'; import Promise from 'bluebird'; import Requester from './requester'; import _ from 'lodash'; +import debugnyan from 'debugnyan'; import methods from './methods'; -import request from 'request'; +import requestLogger from './logging/request-logger'; import semver from 'semver'; /** @@ -47,6 +48,7 @@ class Client { agentOptions, headers = false, host = 'localhost', + logger = debugnyan('bitcoin-core'), network = 'mainnet', password, port, @@ -76,12 +78,14 @@ class Client { if (version) { unsupported = _.chain(methods) - .pickBy(range => !semver.satisfies(version, range)) + .pickBy(method => !semver.satisfies(version, method.version)) .keys() .invokeMap(String.prototype.toLowerCase) .value(); } + const request = requestLogger(logger); + this.request = Promise.promisifyAll(request.defaults({ agentOptions: this.agentOptions, baseUrl: `${this.ssl.enabled ? 'https' : 'http'}://${this.host}:${this.port}`, diff --git a/src/logging/request-logger.js b/src/logging/request-logger.js new file mode 100644 index 0000000..7f817d6 --- /dev/null +++ b/src/logging/request-logger.js @@ -0,0 +1,22 @@ + +/** + * Module dependencies. + */ + +import { obfuscate } from './request-obfuscator'; +import request from 'request'; +import requestLogger from '@uphold/request-logger'; + +/** + * Exports. + */ + +export default logger => requestLogger(request, (request, instance) => { + obfuscate(request, instance); + + if (request.type === 'response') { + return logger.debug({ request }, `Received response for request ${request.id}`); + } + + return logger.debug({ request }, `Making request ${request.id} to ${request.method} ${request.uri}`); +}); diff --git a/src/logging/request-obfuscator.js b/src/logging/request-obfuscator.js new file mode 100644 index 0000000..05fef76 --- /dev/null +++ b/src/logging/request-obfuscator.js @@ -0,0 +1,117 @@ + +/** + * Module dependencies. + */ + +import methods from '../methods'; +import { defaults, get, has, isArray, isEmpty, isString, map, mapKeys } from 'lodash'; + +/** + * Map all methods to lowercase. + */ + +const lowercaseMethods = mapKeys(methods, (value, key) => key.toLowerCase()); + +/** + * Obfuscate the response body. + */ + +function obfuscateResponseBody(body, method) { + const fn = get(lowercaseMethods[method], 'obfuscate.response'); + + if (!fn || isEmpty(body.result)) { + return body; + } + + return defaults({ result: fn(body.result) }, body); +} + +/** + * Obfuscate the response. + */ + +function obfuscateResponse(request, instance) { + if (!get(request, 'response.body')) { + return; + } + + if (get(request, `response.headers['content-type']`) === 'application/octet-stream') { + request.response.body = '******'; + + return; + } + + if (!instance.body) { + return; + } + + const requestBody = JSON.parse(instance.body); + + if (isArray(request.response.body)) { + const methodsById = mapKeys(requestBody, method => method.id); + + request.response.body = map(request.response.body, request => obfuscateResponseBody(request, methodsById[request.id].method)); + + return; + } + + request.response.body = obfuscateResponseBody(request.response.body, requestBody.method); +} + +/** + * Obfuscate the request body. + */ + +function obfuscateRequestBody(body) { + const method = get(lowercaseMethods[body.method], 'obfuscate.request'); + + if (!method) { + return body; + } + + body.params = method(body.params); + + return body; +} + +/** + * Obfuscate the request. + */ + +function obfuscateRequest(request) { + if (!isString(request.body)) { + return; + } + + request.body = JSON.parse(request.body); + + if (isArray(request.body)) { + request.body = map(request.body, obfuscateRequestBody); + } else { + request.body = obfuscateRequestBody(request.body); + } + + request.body = JSON.stringify(request.body); +} + +/** + * Obfuscate headers. + */ + +function obfuscateHeaders(request) { + if (!has(request, 'headers.authorization')) { + return; + } + + request.headers.authorization = request.headers.authorization.replace(/(Basic )(.*)/, `$1******`); +} + +/** + * Export `RequestObfuscator`. + */ + +export function obfuscate(request, instance) { + obfuscateHeaders(request); + obfuscateRequest(request); + obfuscateResponse(request, instance); +} diff --git a/src/methods.js b/src/methods.js index 8c8c1d0..d3d17b6 100755 --- a/src/methods.js +++ b/src/methods.js @@ -1,111 +1,147 @@ /* eslint-disable no-inline-comments */ +/** + * Module dependencies. + */ + +import { map, set } from 'lodash'; + /** * Export available rpc methods. */ export default { - abandonTransaction: '>=0.12.0', - addMultiSigAddress: '>=0.1.0', - addNode: '>=0.8.0', - addWitnessAddress: '>=0.13.0', - backupWallet: '>=0.3.12', - clearBanned: '>=0.12.0', - createMultiSig: '>=0.1.0', - createRawTransaction: '>=0.7.0', - createWitnessAddress: '>=0.13.0', - decodeRawTransaction: '>=0.7.0', - decodeScript: '>=0.9.0', - disconnectNode: '>=0.12.0', - dumpPrivKey: '>=0.6.0', - dumpWallet: '>=0.9.0', - encryptWallet: '>=0.1.0', - estimateFee: '>=0.10.0', - estimatePriority: '>=0.10.0', - estimateSmartFee: '>=0.12.0', - estimateSmartPriority: '>=0.12.0', - fundRawTransaction: '>=0.12.0', - generate: '>=0.11.0', - generateToAddress: '>=0.13.0', - getAccount: '>=0.1.0', - getAccountAddress: '>=0.3.18', - getAddedNodeInfo: '>=0.8.0', - getAddressesByAccount: '>=0.1.0', - getBalance: '>=0.3.18', - getBestBlockHash: '>=0.9.0', - getBlock: '>=0.6.0', - getBlockCount: '>=0.1.0', - getBlockHash: '>=0.6.0', - getBlockHeader: '>=0.12.0', - getBlockTemplate: '>=0.7.0', - getBlockchainInfo: '>=0.9.2', - getChainTips: '>=0.10.0', - getConnectionCount: '>=0.1.0', - getDifficulty: '>=0.1.0', - getGenerate: '<0.13.0', - getHashesPerSec: '<0.10.0', - getInfo: '>=0.1.0', - getMempoolAncestors: '>=0.13.0', - getMempoolDescendants: '>=0.13.0', - getMempoolEntry: '>=0.13.0', - getMempoolInfo: '>=0.10.0', - getMiningInfo: '>=0.6.0', - getNetTotals: '>=0.1.0', - getNetworkHashPs: '>=0.9.0', - getNetworkInfo: '>=0.9.2', - getNewAddress: '>=0.1.0', - getPeerInfo: '>=0.7.0', - getRawChangeAddress: '>=0.9.0', - getRawMemPool: '>=0.7.0', - getRawTransaction: '>=0.7.0', - getReceivedByAccount: '>=0.1.0', - getReceivedByAddress: '>=0.1.0', - getTransaction: '>=0.1.0', - getTxOut: '>=0.7.0', - getTxOutProof: '>=0.11.0', - getTxOutSetInfo: '>=0.7.0', - getUnconfirmedBalance: '>=0.9.0', - getWalletInfo: '>=0.9.2', - getWork: '<0.10.0', - help: '>=0.1.0', - importAddress: '>=0.10.0', - importPrivKey: '>=0.6.0', - importPrunedFunds: '>=0.13.0', - importPubKey: '>=0.12.0', - importWallet: '>=0.9.0', - keypoolRefill: '>=0.1.0', - listAccounts: '>=0.1.0', - listAddressGroupings: '>=0.7.0', - listBanned: '>=0.12.0', - listLockUnspent: '>=0.8.0', - listReceivedByAccount: '>=0.1.0', - listReceivedByAddress: '>=0.1.0', - listSinceBlock: '>=0.5.0', - listTransactions: '>=0.3.18', - listUnspent: '>=0.7.0', - lockUnspent: '>=0.8.0', - move: '>=0.3.18', - ping: '>=0.9.0', - prioritiseTransaction: '>=0.10.0', - removePrunedFunds: '>=0.13.0', - sendFrom: '>=0.3.18', - sendMany: '>=0.3.21', - sendRawTransaction: '>=0.7.0', - sendToAddress: '>=0.1.0', - setAccount: '>=0.1.0', - setBan: '>=0.12.0', - setGenerate: '<0.13.0', - setTxFee: '>=0.3.22', - signMessage: '>=0.5.0', - signMessageWithPrivKey: '>=0.13.0', - signRawTransaction: '>=0.7.0', - stop: '>=0.1.0', - submitBlock: '>=0.7.0', - validateAddress: '>=0.3.14', - verifyChain: '>=0.9.0', - verifyMessage: '>=0.5.0', - verifyTxOutProof: '>0.11.0', - walletLock: '>=0.1.0', - walletPassphrase: '>=0.1.0', - walletPassphraseChange: '>=0.1.0' + abandonTransaction: { version: '>=0.12.0' }, + addMultiSigAddress: { version: '>=0.1.0' }, + addNode: { version: '>=0.8.0' }, + addWitnessAddress: { version: '>=0.13.0' }, + backupWallet: { version: '>=0.3.12' }, + clearBanned: { version: '>=0.12.0' }, + createMultiSig: { version: '>=0.1.0' }, + createRawTransaction: { version: '>=0.7.0' }, + createWitnessAddress: { version: '>=0.13.0' }, + decodeRawTransaction: { version: '>=0.7.0' }, + decodeScript: { version: '>=0.9.0' }, + disconnectNode: { version: '>=0.12.0' }, + dumpPrivKey: { + obfuscate: { + response: () => '******' + }, + version: '>=0.6.0' + }, + dumpWallet: { version: '>=0.9.0' }, + encryptWallet: { + obfuscate: { + request: params => set([...params], '[0]', '******') + }, + version: '>=0.1.0' + }, + estimateFee: { version: '>=0.10.0' }, + estimatePriority: { version: '>=0.10.0' }, + estimateSmartFee: { version: '>=0.12.0' }, + estimateSmartPriority: { version: '>=0.12.0' }, + fundRawTransaction: { version: '>=0.12.0' }, + generate: { version: '>=0.11.0' }, + generateToAddress: { version: '>=0.13.0' }, + getAccount: { version: '>=0.1.0' }, + getAccountAddress: { version: '>=0.3.18' }, + getAddedNodeInfo: { version: '>=0.8.0' }, + getAddressesByAccount: { version: '>=0.1.0' }, + getBalance: { version: '>=0.3.18' }, + getBestBlockHash: { version: '>=0.9.0' }, + getBlock: { version: '>=0.6.0' }, + getBlockCount: { version: '>=0.1.0' }, + getBlockHash: { version: '>=0.6.0' }, + getBlockHeader: { version: '>=0.12.0' }, + getBlockTemplate: { version: '>=0.7.0' }, + getBlockchainInfo: { version: '>=0.9.2' }, + getChainTips: { version: '>=0.10.0' }, + getConnectionCount: { version: '>=0.1.0' }, + getDifficulty: { version: '>=0.1.0' }, + getGenerate: { version: '<0.13.0' }, + getHashesPerSec: { version: '<0.10.0' }, + getInfo: { version: '>=0.1.0' }, + getMempoolAncestors: { version: '>=0.13.0' }, + getMempoolDescendants: { version: '>=0.13.0' }, + getMempoolEntry: { version: '>=0.13.0' }, + getMempoolInfo: { version: '>=0.10.0' }, + getMiningInfo: { version: '>=0.6.0' }, + getNetTotals: { version: '>=0.1.0' }, + getNetworkHashPs: { version: '>=0.9.0' }, + getNetworkInfo: { version: '>=0.9.2' }, + getNewAddress: { version: '>=0.1.0' }, + getPeerInfo: { version: '>=0.7.0' }, + getRawChangeAddress: { version: '>=0.9.0' }, + getRawMemPool: { version: '>=0.7.0' }, + getRawTransaction: { version: '>=0.7.0' }, + getReceivedByAccount: { version: '>=0.1.0' }, + getReceivedByAddress: { version: '>=0.1.0' }, + getTransaction: { version: '>=0.1.0' }, + getTxOut: { version: '>=0.7.0' }, + getTxOutProof: { version: '>=0.11.0' }, + getTxOutSetInfo: { version: '>=0.7.0' }, + getUnconfirmedBalance: { version: '>=0.9.0' }, + getWalletInfo: { version: '>=0.9.2' }, + getWork: { version: '<0.10.0' }, + help: { version: '>=0.1.0' }, + importAddress: { version: '>=0.10.0' }, + importPrivKey: { + obfuscate: { + request: () => ['******'] + }, + version: '>=0.6.0' + }, + importPrunedFunds: { version: '>=0.13.0' }, + importPubKey: { version: '>=0.12.0' }, + importWallet: { version: '>=0.9.0' }, + keypoolRefill: { version: '>=0.1.0' }, + listAccounts: { version: '>=0.1.0' }, + listAddressGroupings: { version: '>=0.7.0' }, + listBanned: { version: '>=0.12.0' }, + listLockUnspent: { version: '>=0.8.0' }, + listReceivedByAccount: { version: '>=0.1.0' }, + listReceivedByAddress: { version: '>=0.1.0' }, + listSinceBlock: { version: '>=0.5.0' }, + listTransactions: { version: '>=0.3.18' }, + listUnspent: { version: '>=0.7.0' }, + lockUnspent: { version: '>=0.8.0' }, + move: { version: '>=0.3.18' }, + ping: { version: '>=0.9.0' }, + prioritiseTransaction: { version: '>=0.10.0' }, + removePrunedFunds: { version: '>=0.13.0' }, + sendFrom: { version: '>=0.3.18' }, + sendMany: { version: '>=0.3.21' }, + sendRawTransaction: { version: '>=0.7.0' }, + sendToAddress: { version: '>=0.1.0' }, + setAccount: { version: '>=0.1.0' }, + setBan: { version: '>=0.12.0' }, + setGenerate: { version: '<0.13.0' }, + setTxFee: { version: '>=0.3.22' }, + signMessage: { version: '>=0.5.0' }, + signMessageWithPrivKey: { + obfuscate: { + request: params => set([...params], '[0]', '******') + }, + version: '>=0.13.0' + }, + signRawTransaction: { + obfuscate: { + request: params => set([...params], '[2]', map(params[2], () => '******')) + }, + version: '>=0.7.0' + }, + stop: { version: '>=0.1.0' }, + submitBlock: { version: '>=0.7.0' }, + validateAddress: { version: '>=0.3.14' }, + verifyChain: { version: '>=0.9.0' }, + verifyMessage: { version: '>=0.5.0' }, + verifyTxOutProof: { version: '>0.11.0' }, + walletLock: { version: '>=0.1.0' }, + walletPassphrase: { + obfuscate: { + request: params => set([...params], '[0]', '******') + }, + version: '>=0.1.0' + }, + walletPassphraseChange: { version: '>=0.1.0' } }; diff --git a/test/logging/request-obfuscator_test.js b/test/logging/request-obfuscator_test.js new file mode 100644 index 0000000..891959a --- /dev/null +++ b/test/logging/request-obfuscator_test.js @@ -0,0 +1,118 @@ + +/** + * Module dependencies. + */ + +import { obfuscate } from '../../src/logging/request-obfuscator'; + +/** + * Test `RequestObfuscator`. + */ + +describe('RequestObfuscator', () => { + describe('obfuscate', () => { + it('should not obfuscate `request.body.params` when `method` is not listed for obfuscation', () => { + const request = { body: '{"id":"1485369469422","method":"foo","params":["foobar"]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"foo","params":["foobar"]}' }); + }); + + it('should obfuscate the authorization header', () => { + const request = { headers: { authorization: 'Basic ==foobar' } }; + + obfuscate(request); + + request.should.eql({ headers: { authorization: 'Basic ******' } }); + }); + + it('should obfuscate the private key from `request.body` when `method` is `importprivkey`', () => { + const request = { body: '{"id":"1485369469422","method":"importprivkey","params":["foobar"]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"importprivkey","params":["******"]}' }); + }); + + it('should obfuscate the private key from `request.body` when `method` is `signmessagewithprivkey`', () => { + const request = { body: '{"id":"1485369469422","method":"signmessagewithprivkey","params":["foobar", "foobiz"]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"signmessagewithprivkey","params":["******","foobiz"]}' }); + }); + + it('should obfuscate all private keys from `request.body` when `method` is `signrawtransaction`', () => { + const request = { body: '{"id":"1485369469422","method":"signrawtransaction","params":["foo","bar",["biz", "boz"]]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"signrawtransaction","params":["foo","bar",["******","******"]]}' }); + }); + + it('should obfuscate the passphrase from `request.body` when `method` is `encryptwallet`', () => { + const request = { body: '{"id":"1485369469422","method":"encryptwallet","params":["foobar"]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"encryptwallet","params":["******"]}' }); + }); + + it('should obfuscate the passphrase from `request.body` when `method` is `walletpassphrase`', () => { + const request = { body: '{"id":"1485369469422","method":"walletpassphrase","params":["foobar"]}' }; + + obfuscate(request); + + request.should.eql({ body: '{"id":"1485369469422","method":"walletpassphrase","params":["******"]}' }); + }); + + it('should obfuscate the `request.body` of a batch request', () => { + const request = { body: '[{"id":"1485369469422","method":"walletpassphrase","params":["foobar"]},{"id":"1485369469423","method":"walletpassphrase","params":["foobar"]}]' }; + + obfuscate(request); + + request.should.eql({ body: '[{"id":"1485369469422","method":"walletpassphrase","params":["******"]},{"id":"1485369469423","method":"walletpassphrase","params":["******"]}]' }); + }); + + it('should obfuscate the private key from `response.body` when `method` is `dumpprivkey`', () => { + const request = { response: { body: { id: '1485369469422-0', result: 'foobiz' } } }; + + obfuscate(request, { body: '{"id":"1485369469422","method":"dumpprivkey","params":["foobar"]}' }); + + request.should.eql({ response: { body: { id: '1485369469422-0', result: '******' } } }); + }); + + it('should obfuscate the `response.body` when `headers.content-type` is `application/octet-stream`', () => { + const request = { response: { body: new Buffer('foobar'), headers: { 'content-type': 'application/octet-stream' } } }; + + obfuscate(request, { uri: 'foobar.bin' }); + + request.should.eql({ response: { body: '******', headers: { 'content-type': 'application/octet-stream' } } }); + }); + + it('should obfuscate the `request.response.body` of a batch request', () => { + const request = { + response: { + body: [ + { id: '1485369469422-0', result: 'foobar' }, + { id: '1485369469422-2', result: 'foobiz' }, + { id: '1485369469422-1', result: 'foo' } + ] + } + }; + + obfuscate(request, { body: '[{"id":"1485369469422-0","method":"dumpprivkey","params":["foobar"]},{"id":"1485369469422-2","method":"getnewaddress","params":["foobiz"]},{"id":"1485369469422-1","method":"dumpprivkey","params":["foobiz"]}]' }); + + request.should.eql({ + response: { + body: [ + { id: '1485369469422-0', result: '******' }, + { id: '1485369469422-2', result: 'foobiz' }, + { id: '1485369469422-1', result: '******' } + ] + } + }); + }); + }); +});