Better logging from subprocess, now uses winston

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<GunT.UserPair>}
  */
-const auth = (alias, pass) =>
+const auth = (alias, pass) => {
-  new Promise((res, rej) => {
+  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)
-
+  logger.info('Sent init msg')
-  currentGun.on('message', handleMsg)
 
   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'
       }
+      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() {
+    reforge() {
-      if (currentGun) {
+      forge()
-        currentGun.off('message', handleMsg)
-        currentGun.disconnect()
-        currentGun.kill()
-      }
     }
   }
 }

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()
     }
   })
 

utils/GunSmith/gun.js

@@ -8,8 +8,7 @@ const Gun = require('gun')
 require('gun/nts')
 require('gun/lib/load')
 
-// @ts-ignore
+const logger = require('../../config/log')
-Gun.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:')
+  logger.error('Uncaught exception inside Gun subprocess:')
-  console.log(e)
+  logger.error(e)
 })
 
 process.on('unhandledRejection', e => {
-  console.log('Unhandled rejection inside Gun subprocess:')
+  logger.error('Unhandled rejection inside Gun subprocess:')
-  console.log(e)
+  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) {
+      if (newPeers !== currentPeers) {
-        console.log('Connected peers:', newPeers)
+        logger.info('Connected peers:', newPeers)
-        lastPeers = 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') {