From dc78fa037155f28fb7a25e78ce066e755318e4f2 Mon Sep 17 00:00:00 2001 From: Daniel Lugo Date: Wed, 15 Sep 2021 12:14:59 -0400 Subject: [PATCH] Better logging from subprocess, now uses winston --- utils/GunSmith/GunSmith.js | 65 +++++++++++++++++++++++++++------ utils/GunSmith/GunSmith.spec.js | 2 +- utils/GunSmith/gun.js | 30 ++++++++------- 3 files changed, 71 insertions(+), 26 deletions(-) diff --git a/utils/GunSmith/GunSmith.js b/utils/GunSmith/GunSmith.js index e5c302ba..ffb7aa8e 100644 --- a/utils/GunSmith/GunSmith.js +++ b/utils/GunSmith/GunSmith.js @@ -133,17 +133,24 @@ let lastPass = '' let lastPair = null /** @type {import('gun/types/options').IGunConstructorOptions} */ let lastOpts = {} +let isAuthing = false /** * @param {string} alias * @param {string} pass * @returns {Promise} */ -const auth = (alias, pass) => - new Promise((res, rej) => { +const auth = (alias, pass) => { + logger.info(`Authing with ${alias}`) + if (isAuthing) { + throw new Error(`Double auth?`) + } + isAuthing = true + return new Promise((res, rej) => { lastAlias = '' lastPass = '' lastPair = null + logger.info('Reset cached credentials in case auth fails') /** @type {Smith.SmithMsgAuth} */ const msg = { alias, @@ -154,8 +161,11 @@ const auth = (alias, pass) => /** @param {Smith.GunMsg} msg */ const _cb = msg => { if (msg.type === 'auth') { + logger.info('Received auth reply.', msg) currentGun.off('message', _cb) + isAuthing = false + const { ack } = msg if (ack.err) { @@ -164,6 +174,9 @@ const auth = (alias, pass) => lastAlias = alias lastPass = pass lastPair = ack.sea + logger.info( + 'Auth successful, credentials cached, will now flush pending puts.' + ) flushPendingPuts() res(ack.sea) } else { @@ -173,7 +186,9 @@ const auth = (alias, pass) => } currentGun.on('message', _cb) currentGun.send(msg) + logger.info('Sent auth message.') }) +} /** * Returns null if there's no cached credentials. @@ -181,8 +196,10 @@ const auth = (alias, pass) => */ const autoAuth = () => { if (!lastAlias || !lastPass) { + logger.info('No credentials cached, will not auto-auth') return Promise.resolve(null) } + logger.info('Credentials cached, will auth.') return auth(lastAlias, lastPass) } @@ -207,30 +224,41 @@ const flushPendingPuts = () => { return msg }) currentGun.send(messages) + logger.info(`Sent ${messages.length} pending puts.`) } +let isReforging = false + const forge = () => { + if (isReforging) { + throw new Error('Double forge?') + } + logger.info('Will reforge') + isReforging = true if (currentGun) { currentGun.off('message', handleMsg) currentGun.disconnect() currentGun.kill() } + logger.info('Killed current gun') const newGun = fork('utils/GunSmith/gun.js') currentGun = newGun + logger.info('Forged new gun') // currentGun.on('', e => { // console.log('event from subprocess') // console.log(e) // }) + currentGun.on('message', handleMsg) + /** @type {Smith.SmithMsgInit} */ const initMsg = { opts: lastOpts, type: 'init' } currentGun.send(initMsg) - - currentGun.on('message', handleMsg) + logger.info('Sent init msg') const lastGunListeners = Object.keys(pathToListeners).map(path => { /** @type {Smith.SmithMsgOn} */ @@ -242,6 +270,21 @@ const forge = () => { }) currentGun.send(lastGunListeners) + const lastGunMapListeners = Object.keys(pathToMapListeners).map(path => { + /** @type {Smith.SmithMsgMapOn} */ + const msg = { + path, + type: 'map.on' + } + return msg + }) + currentGun.send(lastGunMapListeners) + + logger.info('Sent pending map.on listeners') + + logger.info('Finished reforging, will now auto-auth') + + isReforging = false autoAuth() } @@ -398,7 +441,9 @@ function createReplica(path, afterMap = false) { path, type: 'put' } - currentGun.send(msg) + if (!isAuthing && !isReforging) { + currentGun.send(msg) + } return this }, set(data, cb) { @@ -570,7 +615,7 @@ function createUserReplica() { } /** - * @typedef {GunT.GUNNode & { kill(): void }} RootNode + * @typedef {GunT.GUNNode & { reforge(): void }} RootNode */ /** @@ -585,12 +630,8 @@ const Gun = opts => { // signature return { ...createReplica('$root'), - kill() { - if (currentGun) { - currentGun.off('message', handleMsg) - currentGun.disconnect() - currentGun.kill() - } + reforge() { + forge() } } } diff --git a/utils/GunSmith/GunSmith.spec.js b/utils/GunSmith/GunSmith.spec.js index 16ae6d63..69b26ade 100644 --- a/utils/GunSmith/GunSmith.spec.js +++ b/utils/GunSmith/GunSmith.spec.js @@ -35,7 +35,7 @@ describe('constructor', () => { // eslint-disable-next-line jest/no-hooks afterAll(() => { if (instance) { - instance.kill() + instance.reforge() } }) diff --git a/utils/GunSmith/gun.js b/utils/GunSmith/gun.js index 3b728c05..444158da 100644 --- a/utils/GunSmith/gun.js +++ b/utils/GunSmith/gun.js @@ -8,8 +8,7 @@ const Gun = require('gun') require('gun/nts') require('gun/lib/load') -// @ts-ignore -Gun.log = () => {} +const logger = require('../../config/log') /** * @param {any} msg @@ -18,22 +17,22 @@ const sendMsg = msg => { if (process.send) { process.send(msg) } else { - console.log( + logger.error( 'Fatal error: Could not send a message from inside the gun process.' ) } } -console.log('subprocess invoked') +logger.info('subprocess invoked') process.on('uncaughtException', e => { - console.log('Uncaught exception inside Gun subprocess:') - console.log(e) + logger.error('Uncaught exception inside Gun subprocess:') + logger.error(e) }) process.on('unhandledRejection', e => { - console.log('Unhandled rejection inside Gun subprocess:') - console.log(e) + logger.error('Unhandled rejection inside Gun subprocess:') + logger.error(e) }) /** @@ -64,7 +63,7 @@ const waitForAuth = async () => { /** * @param {Smith.SmithMsg} msg */ -const handleMsg = msg => { +const handleMsg = async msg => { if (Array.isArray(msg)) { msg.forEach(handleMsg) return @@ -72,18 +71,23 @@ const handleMsg = msg => { if (msg.type === 'init') { gun = /** @type {any} */ (new Gun(msg.opts)) - let lastPeers = '' + let currentPeers = '' setInterval(() => { const newPeers = JSON.stringify( Object.values(gun.back('opt').peers) .filter(p => p.wire && p.wire.readyState) .map(p => p.url) ) - if (newPeers !== lastPeers) { - console.log('Connected peers:', newPeers) - lastPeers = newPeers + if (newPeers !== currentPeers) { + logger.info('Connected peers:', newPeers) + currentPeers = newPeers } }, 2000) + + setInterval(() => { + // Log regardless of change every 30 seconds + logger.info('Connected peers:', currentPeers) + }, 30000) user = gun.user() } if (msg.type === 'auth') {