diff --git a/package.json b/package.json index 3ca1cee4..84e12443 100644 --- a/package.json +++ b/package.json @@ -48,7 +48,7 @@ "request-promise": "^4.2.2", "response-time": "^2.3.2", "shelljs": "^0.8.2", - "shock-common": "6.0.0", + "shock-common": "8.0.0", "socket.io": "2.1.1", "text-encoding": "^0.7.0", "tingodb": "^0.6.1", diff --git a/services/gunDB/contact-api/jobs/onOrders.js b/services/gunDB/contact-api/jobs/onOrders.js index b7c3e43b..bf3f45a2 100644 --- a/services/gunDB/contact-api/jobs/onOrders.js +++ b/services/gunDB/contact-api/jobs/onOrders.js @@ -30,8 +30,35 @@ const ordersProcessed = new Set() * @typedef {import('../SimpleGUN').UserGUNNode} UserGUNNode */ +/** + * @typedef {object} InvoiceRequest + * @prop {number} expiry + * @prop {string} memo + * @prop {number} value + * @prop {boolean} private + */ + let currentOrderAddr = '' +/** @param {InvoiceRequest} invoiceReq */ +const _addInvoice = invoiceReq => + new Promise((resolve, rej) => { + const { + services: { lightning } + } = LightningServices + + lightning.addInvoice(invoiceReq, ( + /** @type {any} */ error, + /** @type {{ payment_request: string }} */ response + ) => { + if (error) { + rej(error) + } else { + resolve(response.payment_request) + } + }) + }) + /** * @param {string} addr * @param {ISEA} SEA @@ -58,6 +85,8 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { return } + const listenerStartTime = Date.now() + ordersProcessed.add(orderID) logger.info( @@ -66,20 +95,35 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { )} -- addr: ${addr}` ) - const alreadyAnswered = getUser() + const orderAnswerStartTime = Date.now() + + const alreadyAnswered = await getUser() .get(Key.ORDER_TO_RESPONSE) .get(orderID) .then() - if (await alreadyAnswered) { + if (alreadyAnswered) { logger.info('this order is already answered, quitting') return } + const orderAnswerEndTime = Date.now() - orderAnswerStartTime + + logger.info(`[PERF] Order Already Answered: ${orderAnswerEndTime}ms`) + + const decryptStartTime = Date.now() + const senderEpub = await Utils.pubToEpub(order.from) const secret = await SEA.secret(senderEpub, getUser()._.sea) - const decryptedAmount = await SEA.decrypt(order.amount, secret) + const [decryptedAmount, memo] = await Promise.all([ + SEA.decrypt(order.amount, secret), + SEA.decrypt(order.memo, secret) + ]) + + const decryptEndTime = Date.now() - decryptStartTime + + logger.info(`[PERF] Decrypt invoice info: ${decryptEndTime}ms`) const amount = Number(decryptedAmount) @@ -101,8 +145,6 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { ) } - const memo = await SEA.decrypt(order.memo, secret) - const invoiceReq = { expiry: 36000, memo, @@ -114,32 +156,29 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { `onOrders() -> Will now create an invoice : ${JSON.stringify(invoiceReq)}` ) + const invoiceStartTime = Date.now() + /** * @type {string} */ - const invoice = await new Promise((resolve, rej) => { - const { - services: { lightning } - } = LightningServices + const invoice = await _addInvoice(invoiceReq) - lightning.addInvoice(invoiceReq, ( - /** @type {any} */ error, - /** @type {{ payment_request: string }} */ response - ) => { - if (error) { - rej(error) - } else { - resolve(response.payment_request) - } - }) - }) + const invoiceEndTime = Date.now() - invoiceStartTime + + logger.info(`[PERF] LND Invoice created in ${invoiceEndTime}ms`) logger.info( 'onOrders() -> Successfully created the invoice, will now encrypt it' ) + const invoiceEncryptStartTime = Date.now() + const encInvoice = await SEA.encrypt(invoice, secret) + const invoiceEncryptEndTime = Date.now() - invoiceEncryptStartTime + + logger.info(`[PERF] Invoice encrypted in ${invoiceEncryptEndTime}ms`) + logger.info( `onOrders() -> Will now place the encrypted invoice in order to response usergraph: ${addr}` ) @@ -150,11 +189,12 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { type: 'invoice' } + const invoicePutStartTime = Date.now() + await new Promise((res, rej) => { getUser() .get(Key.ORDER_TO_RESPONSE) .get(orderID) - //@ts-ignore .put(orderResponse, ack => { if (ack.err && typeof ack.err !== 'number') { rej( @@ -167,6 +207,14 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { } }) }) + + const invoicePutEndTime = Date.now() - invoicePutStartTime + + logger.info(`[PERF] Added invoice to GunDB in ${invoicePutEndTime}ms`) + + const listenerEndTime = Date.now() - listenerStartTime + + logger.info(`[PERF] Invoice generation completed in ${listenerEndTime}ms`) } catch (err) { logger.error( `error inside onOrders, orderAddr: ${addr}, orderID: ${orderID}, order: ${JSON.stringify( @@ -184,7 +232,6 @@ const listenerForAddr = (addr, SEA) => async (order, orderID) => { getUser() .get(Key.ORDER_TO_RESPONSE) .get(orderID) - //@ts-ignore .put(orderResponse, ack => { if (ack.err && typeof ack.err !== 'number') { logger.error( diff --git a/src/routes.js b/src/routes.js index 65fc1a68..a0156829 100644 --- a/src/routes.js +++ b/src/routes.js @@ -21,6 +21,7 @@ const auth = require('../services/auth/auth') const FS = require('../utils/fs') const Encryption = require('../utils/encryptionStore') const LightningServices = require('../utils/lightningServices') +const lndErrorManager = require('../utils/lightningServices/errors') const GunDB = require('../services/gunDB/Mediator') const { unprotectedRoutes, @@ -63,7 +64,10 @@ module.exports = async ( return message } - const getAvailableService = () => + const getAvailableService = () => { + return lndErrorManager.getAvailableService() + } + /* new Promise((resolve, reject) => { const { lightning } = LightningServices.services @@ -105,13 +109,22 @@ module.exports = async ( success: true }) }) - }) + })*/ const checkHealth = async () => { logger.info('Getting service status...') - const serviceStatus = await getAvailableService() - logger.info('Received status:', serviceStatus) - const LNDStatus = serviceStatus + let LNDStatus = {} + try { + const serviceStatus = await getAvailableService() + logger.info('Received status:', serviceStatus) + LNDStatus = serviceStatus + } catch (e) { + LNDStatus = { + message: e.message, + success: false + } + } + try { logger.info('Getting API status...') const APIHealth = await Http.get( @@ -367,14 +380,31 @@ module.exports = async ( const walletStatus = await walletExists() const availableService = await getAvailableService() const statusMessage = availableService.walletStatus + if (availableService.code === 12) { + return res.status(401).json({ + field: 'lnd_locked', + errorMessage: availableService.message + ? availableService.message + : 'unknown' + }) + } + if (availableService.code === 14) { + return res.status(401).json({ + field: 'lnd_dead', + errorMessage: availableService.message + ? availableService.message + : 'unknown' + }) + } if (walletStatus) { if (statusMessage === 'unlocked') { return next() } - return res.status(401).json({ field: 'wallet', - errorMessage: statusMessage ? statusMessage : 'unknown' + errorMessage: availableService.message + ? availableService.message + : 'unknown' }) } @@ -386,6 +416,18 @@ module.exports = async ( next() } catch (err) { logger.error(err) + if (err.code === 12) { + return res.status(401).json({ + field: 'lnd_locked', + errorMessage: err.message ? err.message : 'unknown' + }) + } + if (err.code === 14) { + return res.status(401).json({ + field: 'lnd_dead', + errorMessage: err.message ? err.message : 'unknown' + }) + } res.status(500).json({ field: 'wallet', errorMessage: err.message ? err.message : err @@ -589,17 +631,46 @@ module.exports = async ( stream.on('end', () => { logger.info('Channel backup stream ended, starting a new one...') // Prevents call stack overflow exceptions - process.nextTick(onNewChannelBackup) + //process.nextTick(onNewChannelBackup) }) stream.on('error', err => { logger.error('Channel backup stream error:', err) }) stream.on('status', status => { - if (status.code === 14) { - // Prevents call stack overflow exceptions - process.nextTick(() => setTimeout(onNewChannelBackup, 30000)) - } else { - logger.error('Channel backup stream status:', status) + logger.error('Channel backup stream status:', status) + switch (status.code) { + case 0: { + logger.info('Channel backup stream ok') + break + } + case 2: { + //Happens to fire when the grpc client lose access to macaroon file + logger.warn('Channel backup got UNKNOWN error status') + break + } + case 12: { + logger.warn( + 'Channel backup LND locked, new registration in 60 seconds' + ) + process.nextTick(() => + setTimeout(() => onNewTransaction(socket, subID), 60000) + ) + break + } + case 13: { + //https://grpc.github.io/grpc/core/md_doc_statuscodes.html + logger.error('Channel backup INTERNAL LND error') + break + } + case 14: { + logger.error( + 'Channel backup LND disconnected, sockets reconnecting in 30 seconds...' + ) + process.nextTick(() => + setTimeout(() => onNewTransaction(socket, subID), 30000) + ) + break + } } }) } diff --git a/src/sockets.js b/src/sockets.js index 76d195fc..fd317c61 100644 --- a/src/sockets.js +++ b/src/sockets.js @@ -111,9 +111,9 @@ module.exports = ( } } - const onNewInvoice = socket => { + const onNewInvoice = (socket, subID) => { const { lightning } = LightningServices.services - logger.warn('Subscribing to invoices socket...') + logger.warn('Subscribing to invoices socket...' + subID) const stream = lightning.subscribeInvoices({}) stream.on('data', data => { logger.info('[SOCKET] New invoice data:', data) @@ -122,49 +122,107 @@ module.exports = ( stream.on('end', () => { logger.info('New invoice stream ended, starting a new one...') // Prevents call stack overflow exceptions - process.nextTick(() => onNewInvoice(socket)) + //process.nextTick(() => onNewInvoice(socket)) }) stream.on('error', err => { - logger.error('New invoice stream error:', err) + logger.error('New invoice stream error:' + subID, err) }) stream.on('status', status => { - logger.warn('New invoice stream status:', status) - if (status.code === 14) { - // Prevents call stack overflow exceptions - logger.error( - '[event:invoice:new] LND disconnected, sockets reconnecting in 30 seconds...' - ) - process.nextTick(() => setTimeout(() => onNewInvoice(socket), 30000)) + logger.warn('New invoice stream status:' + subID, status) + switch (status.code) { + case 0: { + logger.info('[event:invoice:new] stream ok') + break + } + case 2: { + logger.warn('[event:invoice:new] got UNKNOWN error status') + break + } + case 12: { + logger.warn( + '[event:invoice:new] LND locked, new registration in 60 seconds' + ) + process.nextTick(() => + setTimeout(() => onNewInvoice(socket, subID), 60000) + ) + break + } + case 13: { + //https://grpc.github.io/grpc/core/md_doc_statuscodes.html + logger.error('[event:invoice:new] INTERNAL LND error') + break + } + case 14: { + logger.error( + '[event:invoice:new] LND disconnected, sockets reconnecting in 30 seconds...' + ) + process.nextTick(() => + setTimeout(() => onNewInvoice(socket, subID), 30000) + ) + break + } } }) + return () => { + stream.cancel() + } } - const onNewTransaction = socket => { + const onNewTransaction = (socket, subID) => { const { lightning } = LightningServices.services const stream = lightning.subscribeTransactions({}) - logger.warn('Subscribing to transactions socket...') + logger.warn('Subscribing to transactions socket...' + subID) stream.on('data', data => { logger.info('[SOCKET] New transaction data:', data) emitEncryptedEvent({ eventName: 'transaction:new', data, socket }) }) stream.on('end', () => { - logger.info('New invoice stream ended, starting a new one...') - process.nextTick(() => onNewTransaction(socket)) + logger.info('New transactions stream ended, starting a new one...') + //process.nextTick(() => onNewTransaction(socket)) }) stream.on('error', err => { - logger.error('New invoice stream error:', err) + logger.error('New transactions stream error:' + subID, err) }) stream.on('status', status => { - logger.error('New invoice stream status:', status) - if (status.code === 14) { - logger.error( - '[event:transaction:new] LND disconnected, sockets reconnecting in 30 seconds...' - ) - process.nextTick(() => - setTimeout(() => onNewTransaction(socket), 30000) - ) + logger.error('New transactions stream status:' + subID, status) + switch (status.code) { + case 0: { + logger.info('[event:transaction:new] stream ok') + break + } + case 2: { + //Happens to fire when the grpc client lose access to macaroon file + logger.warn('[event:transaction:new] got UNKNOWN error status') + break + } + case 12: { + logger.warn( + '[event:transaction:new] LND locked, new registration in 60 seconds' + ) + process.nextTick(() => + setTimeout(() => onNewTransaction(socket, subID), 60000) + ) + break + } + case 13: { + //https://grpc.github.io/grpc/core/md_doc_statuscodes.html + logger.error('[event:transaction:new] INTERNAL LND error') + break + } + case 14: { + logger.error( + '[event:transaction:new] LND disconnected, sockets reconnecting in 30 seconds...' + ) + process.nextTick(() => + setTimeout(() => onNewTransaction(socket, subID), 30000) + ) + break + } } }) + return () => { + stream.cancel() + } } io.on('connection', socket => { @@ -174,6 +232,8 @@ module.exports = ( const isOneTimeUseSocket = !!socket.handshake.query.IS_GUN_AUTH const isLNDSocket = !!socket.handshake.query.IS_LND_SOCKET + const isNotificationsSocket = !!socket.handshake.query + .IS_NOTIFICATIONS_SOCKET if (!isLNDSocket) { /** printing out the client who joined */ logger.info('New socket client connected (id=' + socket.id + ').') @@ -203,9 +263,16 @@ module.exports = ( }) } else { if (isLNDSocket) { - logger.info('[LND] New LND Socket created') - onNewInvoice(socket) - onNewTransaction(socket) + const subID = Math.floor(Math.random() * 1000).toString() + const isNotifications = isNotificationsSocket ? 'notifications' : '' + logger.info('[LND] New LND Socket created:' + isNotifications + subID) + const cancelInvoiceStream = onNewInvoice(socket, subID) + const cancelTransactionStream = onNewTransaction(socket, subID) + socket.on('disconnect', () => { + logger.info('LND socket disconnected:' + isNotifications + subID) + cancelInvoiceStream() + cancelTransactionStream() + }) return } logger.info('New socket is NOT one time use') diff --git a/utils/lightningServices/errors.js b/utils/lightningServices/errors.js new file mode 100644 index 00000000..971a0d02 --- /dev/null +++ b/utils/lightningServices/errors.js @@ -0,0 +1,152 @@ + +const LightningServices = require('./lightning-services') + +/** + * @typedef {{ + * code:number, + * details:string, + * message:string + * }} LNDError + */ + +/** + * @typedef {(err:LNDError,response:object)=>void} HealthListener + */ + +class LNDErrorManager { + + /** + * @type {boolean} + */ + _isCheckingHealth = false + + /** + * @type {HealthListener[]} + */ + _healthListeners = [] + + //rejects if(err && err.code !== 12) + getAvailableService(){ + + //require('shock-common').Utils.makePromise((res, rej) => ...) + return new Promise((res,rej)=>{ + if(!this._isCheckingHealth){ + this._isCheckingHealth = true + this.getInfo() + } + /** + * + * @param {LNDError} err + * @param {object} response + */ + const listener = (err,response)=>{ + if (err) { + if (err.code === 12) { + res({ + service: 'walletUnlocker', + message: 'Wallet locked', + code: err.code, + walletStatus: 'locked', + success: true + }) + } else if (err.code === 14) { + rej({ + service: 'unknown', + message: + "Failed to connect to LND server, make sure it's up and running.", + code: 14, + walletStatus: 'unknown', + success: false + }) + } else if(err.code === 4){ + rej({ + service: 'unknown', + message: + "LND Timeout", + code: 4, + walletStatus: 'unknown', + success: false + }) + } else { + rej({ + service: 'lightning', + message: this.sanitizeLNDError(err), + code: err.code, + walletStatus: 'unlocked', + success: false + }) + } + } + + res({ + service: 'lightning', + message: response, + code: null, + walletStatus: 'unlocked', + success: true + }) + + } + this._healthListeners.push(listener) + }) + + } + + //private + getInfo(){ + const { lightning } = LightningServices.services + /** + * + * @param {LNDError} err + * @param {object} response + */ + const callback = (err, response) => { + this._healthListeners.forEach(l =>{ + l(err,response) + }) + this._healthListeners.length = 0 + this._isCheckingHealth = false + } + const deadline = Date.now() + 4000 + lightning.getInfo({},{deadline}, callback) + } + + /** + * @param {LNDError} e + */ + handleError(e){ + return this.sanitizeLNDError(e) + } + + /** + * @param {LNDError} e + */ + // eslint-disable-next-line + sanitizeLNDError(e){ + let eMessage = '' + if(typeof e === 'string'){ + eMessage = e + }else if(e.details){ + eMessage = e.details + } else if(e.message){ + eMessage = e.message + } + if (eMessage.toLowerCase().includes('unknown')) { + const splittedMessage = eMessage.split('UNKNOWN: ') + return splittedMessage.length > 1 + ? splittedMessage.slice(1).join('') + : splittedMessage.join('') + } + if(eMessage === ''){ + return 'unknown LND error' + } + return eMessage + } + + +} + + +const lndErrorManager = new LNDErrorManager() + +module.exports = lndErrorManager \ No newline at end of file diff --git a/yarn.lock b/yarn.lock index eebaf010..127d03ad 100644 --- a/yarn.lock +++ b/yarn.lock @@ -6021,10 +6021,10 @@ shellwords@^0.1.1: resolved "https://registry.yarnpkg.com/shellwords/-/shellwords-0.1.1.tgz#d6b9181c1a48d397324c84871efbcfc73fc0654b" integrity sha512-vFwSUfQvqybiICwZY5+DAWIPLKsWO31Q91JSKl3UYv+K5c2QRPzn0qzec6QPu1Qc9eHYItiP3NdJqNVqetYAww== -shock-common@6.0.0: - version "6.0.0" - resolved "https://registry.yarnpkg.com/shock-common/-/shock-common-6.0.0.tgz#77701dabb344830046b85ece0103de21775197b9" - integrity sha512-kbSkLTtWTK8qVcbW6uViWtar3otW2S5oJIMO/1twPs6Iuv9ATF0QviDtUiU1YN/Y4bX/SXAMm/jRZ3OJ3PLyUA== +shock-common@8.0.0: + version "8.0.0" + resolved "https://registry.yarnpkg.com/shock-common/-/shock-common-8.0.0.tgz#4dbc8c917adfb221a00b6d1e815c4d26d205ce66" + integrity sha512-X9jkSxNUjQOcVdEAGBl6dlBgBxF9MpjV50Cih4hoqLqeGfrAYHK/iqgXgDyaHkLraHRxdP6FWJ2DoWOpuBgpDQ== dependencies: immer "^6.0.6" lodash "^4.17.19"