Assorted bug fixes:

* Removed keys from log files (replaced with discovery keys).
* Periodically log mem/cpu usage
* Set preview: false in repl

Author: andrewosh

index.js

@@ -5,6 +5,7 @@ const mkdirp = require('mkdirp')
 const sub = require('subleveldown')
 const grpc = require('@grpc/grpc-js')
 const bjson = require('buffer-json-encoding')
+const processTop = require('process-top')
 const Corestore = require('corestore')
 const HypercoreCache = require('hypercore-cache')
 const SwarmNetworker = require('corestore-swarm-networking')
@@ -102,6 +103,7 @@ class HyperdriveDaemon extends EventEmitter {
 
     // Set in start.
     this.server = null
+    this._topTimer = null
     this._dbs = null
     this._isMain = !!opts.main
     this._cleanup = null
@@ -144,7 +146,6 @@ class HyperdriveDaemon extends EventEmitter {
 
     const seed = this.corestore._deriveSecret(NAMESPACE, 'replication-keypair')
     const swarmId = this.corestore._deriveSecret(NAMESPACE, 'swarm-id')
-    log.info({ swarmId: swarmId.toString('hex'), seed: seed.toString('hex') }, 'creating replication keypair and swarm ID')
     this._networkOpts.keyPair = HypercoreProtocol.keyPair(seed)
     this._networkOpts.id = swarmId
 
@@ -309,6 +310,10 @@ class HyperdriveDaemon extends EventEmitter {
     this._isClosed = true
 
     try {
+      if (this._topTimer) {
+        clearInterval(this._topTimer)
+        this._topTimer = null
+      }
       if (this.server) this.server.forceShutdown()
       log.info('waiting for fuse to unmount')
       if (this.fuse && this.fuse.fuseConfigured) await this.fuse.unmount()
@@ -340,6 +345,10 @@ class HyperdriveDaemon extends EventEmitter {
 
   async start () {
     await this.ready()
+    this._topTimer = setInterval(() => {
+      log.info(processTop().toJSON(), 'process stats')
+    }, 1000 * 60)
+
     this.server = new grpc.Server()
 
     this.server.addService(rpc.fuse.services.FuseService, {

lib/debug/index.js

@@ -34,7 +34,7 @@ module.exports = class DebugManager extends EventEmitter {
     const r = repl.start({
       input: pumpify(call, inputDecoder),
       output: pumpify.obj(outputEncoder, call),
-      preview: true,
+      preview: false,
       terminal: true,
       completer: line => {
         const keys = Object.keys(r.context)

lib/drives/index.js

@@ -134,6 +134,7 @@ class DriveManager extends EventEmitter {
     if (!drive) return null
 
     const driveKey = drive.key.toString('hex')
+    const driveDKey = drive.discoveryKey.toString('hex')
     const driveSessions = this._sessionsByKey.get(driveKey)
     this._sessions.delete(id)
     const idx = driveSessions.indexOf(id)
@@ -142,12 +143,12 @@ class DriveManager extends EventEmitter {
     // If there are still active sessions, don't close the drive.
     if (driveSessions.length) return null
 
-    log.debug({ id, key: driveKey }, 'closing drive because all associated sessions have closed')
+    log.debug({ id, discoveryKey: driveDKey }, 'closing drive because all associated sessions have closed')
     this._sessionsByKey.delete(driveKey)
 
     // If a drive is closed in memory-only mode, its storage will be deleted, so don't actually close.
     if (this.memoryOnly) {
-      log.debug({ id, key: driveKey }, 'aborting drive close because we\'re in memory-only mode')
+      log.debug({ id, discoveryKey: driveDKey }, 'aborting drive close because we\'re in memory-only mode')
       return null
     }
 
@@ -171,7 +172,7 @@ class DriveManager extends EventEmitter {
     return new Promise((resolve, reject) => {
       drive.close(err => {
         if (err) return reject(err)
-        log.debug({ id, key: driveKey }, 'closed drive and cleaned up any remaining watchers')
+        log.debug({ id, discoveryKey: driveDKey }, 'closed drive and cleaned up any remaining watchers')
         return resolve()
       })
     })
@@ -320,7 +321,7 @@ class DriveManager extends EventEmitter {
       const mountInfo = { version: trie.version }
       const mountKey = feed.key.toString('hex')
 
-      log.info({ key }, 'registering mountpoint in drive index')
+      log.info({ discoveryKey: feed.discoveryKey.toString('hex') }, 'registering mountpoint in drive index')
       const parentConfig = (await this.getNetworkConfiguration(drive)) || initialConfig || {}
       const existingMountConfig = (await this.getNetworkConfiguration(feed)) || {}
       const mountConfig = {
@@ -407,11 +408,11 @@ class DriveManager extends EventEmitter {
     }
 
     function configurationError (err) {
-      log.error({ err, encodedKey }, 'network configuration error')
+      log.error({ err, discoveryKey: encodedKey }, 'network configuration error')
     }
 
     function configurationSuccess () {
-      log.debug({ encodedKey }, 'network configuration succeeded')
+      log.debug({ discoveryKey: encodedKey }, 'network configuration succeeded')
     }
   }
 
@@ -977,7 +978,6 @@ class DriveManager extends EventEmitter {
             driveWatchers.splice(driveWatchers.indexOf(watcher), 1)
             if (!driveWatchers.length) self._watchers.delete(keyString)
           }
-          if (err) log.error({ id, path, err }, 'watch stream errored')
           call.end()
         }
       },

lib/fuse/index.js

@@ -63,7 +63,7 @@ class FuseManager extends EventEmitter {
     log.debug('attempting to refresh the root drive if it exists.')
     const rootDriveMeta = await this._getRootDriveInfo()
     const { opts = {}, mnt = constants.mountpoint } = rootDriveMeta || {}
-    log.debug({ opts, mnt }, 'refreshing root mount on restart')
+    log.debug('refreshing root mount on restart')
     await this.mount(mnt, opts)
     return true
   }
@@ -72,7 +72,7 @@ class FuseManager extends EventEmitter {
     log.debug('getting root drive metadata')
     try {
       const rootDriveMeta = await this.db.get('root-drive')
-      log.debug({ rootDriveMeta }, 'got root drive metadata')
+      log.debug('got root drive metadata')
       return rootDriveMeta
     } catch (err) {
       if (!err.notFound) throw err
@@ -259,7 +259,7 @@ class FuseManager extends EventEmitter {
 
           try {
             const key = datEncoding.decode(match.groups.key)
-            log.debug({ key: match.groups.key, filename }, 'opening stats file for drive')
+            log.debug({ filename }, 'opening stats file for drive')
             const drive = await this.driveManager.get(key)
             var stats = null
 
@@ -306,7 +306,7 @@ class FuseManager extends EventEmitter {
           if (!match.groups.key || !match.groups.filename) return cb(fuse.ENOENT)
           const filename = match.groups.filename
           if (filename !== 'networking.json' && filename !== 'storage.json') return cb(fuse.ENOENT)
-          log.debug({ key: match.groups.key, filename }, 'closing stats file')
+          log.debug({ filename }, 'closing stats file')
           return this._virtualFiles.close(...[...args, cb])
         }
 
@@ -472,7 +472,7 @@ class FuseManager extends EventEmitter {
     mnt = mnt || constants.mountpoint
 
     await ensureFuse()
-    log.debug({ mnt, mountOpts }, 'mounting a drive')
+    log.debug({ mnt }, 'mounting a drive')
 
     // TODO: Stop using the hash field to pass this flag once hashes are supported.
     if (mnt === constants.mountpoint && (!mountOpts.hash || (mountOpts.hash.toString() !== 'force'))) {
@@ -490,7 +490,7 @@ class FuseManager extends EventEmitter {
     return mountSubdrive(relativePath, drive)
 
     async function mountSubdrive (relativePath, drive) {
-      log.debug({ key: drive.key.toString('hex') }, 'mounting a sub-hyperdrive')
+      log.debug({ discoveryKey: drive.discoveryKey.toString('hex') }, 'mounting a sub-hyperdrive')
       mountOpts.uid = process.getuid()
       mountOpts.gid = process.getgid()
       return new Promise((resolve, reject) => {
@@ -502,7 +502,7 @@ class FuseManager extends EventEmitter {
     }
 
     async function mountRoot (drive) {
-      log.debug({ key: drive.key.toString('hex') }, 'mounting the root drive')
+      log.debug({ discoveryKey: drive.discoveryKey.toString('hex') }, 'mounting the root drive')
 
       const fuse = new HyperdriveFuse(drive, constants.mountpoint, {
         force: true,
@@ -514,7 +514,7 @@ class FuseManager extends EventEmitter {
       const wrappedHandlers = self._wrapHandlers(handlers)
       await fuse.mount(wrappedHandlers)
 
-      log.debug({ mnt, wrappedHandlers }, 'mounted the root drive')
+      log.debug({ mnt }, 'mounted the root drive')
       mountOpts.key = drive.key
 
       await self.db.put('root-drive', { mnt, opts: { ...mountOpts, key: datEncoding.encode(drive.key) } })
@@ -531,7 +531,7 @@ class FuseManager extends EventEmitter {
           if (err) log.error({ error: err }, 'mountpoint error')
           self.driveManager.createSession(null, feed.key)
             .then(() => {
-              log.info({ key: feed.key.toString('hex') }, 'created session for mountpoint')
+              log.info({ discoveryKey: feed.discoveryKey.toString('hex') }, 'created session for mountpoint')
             })
             .catch(err => {
               log.error({ error: err }, 'could not create session for mountpoint')
@@ -586,12 +586,12 @@ class FuseManager extends EventEmitter {
     // The corestore name is not very important here, since the initial drive will be discarded after mount.
     const drive = await this._createDrive(null, { ...this.opts, name: crypto.randomBytes(64).toString('hex') })
 
-    log.debug({ path, key: drive.key.toString('hex') }, 'mounting a drive at a path')
+    log.debug({ path, discoveryKey: drive.discoveryKey.toString('hex') }, 'mounting a drive at a path')
     return new Promise((resolve, reject) => {
       const innerPath = path.slice(this._rootMnt.length)
       this._rootDrive.mount(innerPath, opts, err => {
         if (err) return reject(err)
-        log.debug({ path, key: drive.key.toString('hex') }, 'drive mounted')
+        log.debug({ path, discoveryKey: drive.discoveryKey.toString('hex') }, 'drive mounted')
         return resolve()
       })
     })

manager.js

@@ -67,8 +67,7 @@ async function start (opts = {}) {
   else if (Array.isArray(opts.bootstrap) && opts.bootstrap.length) args.push('--bootstrap', opts.bootstrap.join(','))
 
   var interpreter = opts.interpreter || process.execPath
-  var interpreterArgs = `--max-old-space-size=${opts.heapSize}`
-  console.log('interpreterArgs:', interpreterArgs)
+  var interpreterArgs = [`--max-old-space-size=${opts.heapSize}`]
   if (!IS_WINDOWS) {
     const execArg = [interpreter, interpreterArgs, script].concat(args).map(escapeStringArg).join(' ')
     args = ['-c', execArg]
@@ -98,7 +97,6 @@ async function start (opts = {}) {
       await fs.rename(constants.unstructuredLog, constants.unstructuredLog.replace('.log', '.old.log'))
     }
   } catch (err) {
-    console.log('err:', err)
     // If the log file couldn't be rotated, it's OK.
   }
 

package.json

@@ -61,6 +61,7 @@
     "peersockets": "^0.3.0",
     "pino": "^5.12.6",
     "pm2": "^4.2.1",
+    "process-top": "^1.1.0",
     "pump": "^3.0.0",
     "pumpify": "^2.0.1",
     "random-access-memory": "^3.1.1",