feat: log stderr from daemon

Renames process handlers to stderr and stdout to better
capture what they do.

Hooks up stderr handler to data event of daemon's stderr to
log data emitted.

Uses the callback to handle errors instead of an extra error
handler.

Specify stderr and stdout handlers in the method options instead
of in a separate argument.

No longer buffers all command output automatically as it can lead
to out of memory errors on long running processes.

src/ipfsd-daemon.js

@@ -248,39 +248,25 @@ class Daemon {
     }
 
     let output = ''
-    this.subprocess = run(this, args, { env: this.env }, {
-      error: (err) => {
-        let line = String(err)
-
-        // Only look at the last error
-        const input = line
-          .split('\n')
-          .map((l) => l.trim())
-          .filter(Boolean)
-          .slice(-1)[0] || ''
-
-        if (line) {
-          daemonLog.err(line.trim())
-        }
 
-        if (input.match(/(?:daemon is running|Daemon is ready)/)) {
-          // we're good
-          return callback(null, this.api)
-        }
-        // ignore when kill -9'd
-        if (!input.match('non-zero exit code')) {
-          callback(err)
+    this.subprocess = run(this, args, {
+      env: this.env,
+      stderr: (data) => {
+        data = String(data)
+
+        if (data) {
+          daemonLog.err(data.trim())
         }
       },
-      data: (data) => {
-        let line = String(data)
-
-        output += line
+      stdout: (data) => {
+        data = String(data)
 
-        if (line) {
-          daemonLog.info(line.trim())
+        if (data) {
+          daemonLog.info(data.trim())
         }
 
+        output += data
+
         const apiMatch = output.trim().match(/API (?:server|is) listening on[:]? (.*)/)
         const gwMatch = output.trim().match(/Gateway (?:.*) listening on[:]? (.*)/)
 
@@ -298,7 +284,7 @@ class Daemon {
           callback(null, this.api)
         }
       }
-    })
+    }, callback)
   }
 
   /**
@@ -401,21 +387,28 @@ class Daemon {
     if (!key) {
       key = 'show'
     }
+    let config = ''
 
-    waterfall([
+    series([
       (cb) => run(
         this,
         ['config', key],
-        { env: this.env },
+        {
+          env: this.env,
+          stdout: (data) => {
+            config += String(data)
+          }
+        },
         cb
       ),
-      (config, cb) => {
+      (cb) => {
         if (key === 'show') {
           return safeParse(config, cb)
         }
+
         cb(null, config.trim())
       }
-    ], callback)
+    ], (error, results) => callback(error, results && results[results.length - 1]))
   }
 
   /**
@@ -463,7 +456,13 @@ class Daemon {
    * @returns {undefined}
    */
   version (callback) {
-    run(this, ['version'], { env: this.env }, callback)
+    let stdout = ''
+    run(this, ['version'], {
+      env: this.env,
+      stdout: (data) => {
+        stdout += String(data)
+      }
+    }, (error) => callback(error, stdout.trim()))
   }
 }
 

src/utils/exec.js

@@ -4,66 +4,39 @@ const run = require('subcomandante')
 const once = require('once')
 const debug = require('debug')
 const log = debug('ipfsd-ctl:exec')
-
 const path = require('path')
+const noop = () => {}
 
-function exec (cmd, args, opts, handlers, callback) {
-  opts = opts || {}
-  let err = ''
-  let result = ''
-
-  // Handy method if we just want the result and err returned in a callback
-  if (typeof handlers === 'function') {
-    callback = once(handlers)
-
-    handlers = {
-      error: callback,
-      data (data) {
-        result += data
-      },
-      done () {
-        if (err) {
-          return callback(new Error(err))
-        }
-        callback(null, result.trim())
-      }
-    }
+function exec (cmd, args, opts, callback) {
+  if (typeof opts === 'function') {
+    callback = opts
+    opts = {}
   }
 
-  // The listeners that will actually be set on the process
-  const listeners = {
-    data: handlers.data,
-    error (data) {
-      err += data
-    },
-    done: once((code) => {
-      if (typeof code === 'number' && code !== 0) {
-        return handlers.error(
-          new Error(`non-zero exit code ${code}\n
-            while running: ${cmd} ${args.join(' ')}\n\n
-            ${err}`)
-        )
-      }
-      if (handlers.done) {
-        handlers.done()
-      }
-    })
-  }
+  callback = once(callback)
 
-  log(path.basename(cmd), args.join(' '))
-  const command = run(cmd, args, opts)
+  opts = Object.assign({}, {
+    stdout: noop,
+    stderr: noop
+  }, opts)
 
-  if (listeners.data) {
-    command.stdout.on('data', listeners.data)
+  const done = (code) => {
+    // if process exits with non-zero code, subcomandante will cause
+    // an error event to be emitted which will call the passed
+    // callback so we only need to handle the happy path
+    if (code === 0) {
+      callback()
+    }
   }
 
-  command.stderr.on('data', listeners.error)
-
-  // If command fails to execute return directly to the handler
-  command.on('error', handlers.error)
+  log(path.basename(cmd), args.join(' '))
 
-  command.on('close', listeners.done)
-  command.on('exit', listeners.done)
+  const command = run(cmd, args, opts)
+  command.on('error', callback)
+  command.on('close', done)
+  command.on('exit', done)
+  command.stdout.on('data', opts.stdout)
+  command.stderr.on('data', opts.stderr)
 
   return command
 }

test/api.spec.js

@@ -66,34 +66,20 @@ describe('ipfsd.api for Daemons', () => {
             recursive: true
           }, (err, res) => {
             expect(err).to.not.exist()
+            expect(res.length).to.equal(4)
 
-            const added = res[res.length - 1]
-
-            // TODO: Temporary: Need to see what is going on on windows
-            expect(res).to.eql([
-              {
-                path: 'fixtures/test.txt',
-                hash: 'Qmf412jQZiuVUtdgnB36FXFX7xg5V6KEbSJ4dpQuhkLyfD',
-                size: 19
-              },
-              {
-                path: 'fixtures',
-                hash: 'QmXkiTdnfRJjiQREtF5dWf2X4V9awNHQSn9YGofwVY4qUU',
-                size: 73
-              }
-            ])
-
-            expect(res.length).to.equal(2)
-            expect(added).to.have.property('path', 'fixtures')
-            expect(added).to.have.property(
+            const fixuresDir = res.find(file => file.path === 'fixtures')
+            expect(fixuresDir).to.have.property(
               'hash',
-              'QmXkiTdnfRJjiQREtF5dWf2X4V9awNHQSn9YGofwVY4qUU'
+              'QmR9731QMXHCjK2EvoQZNhMHVE77tGMbgPFXMWPHztMV4a'
             )
-            expect(res[0]).to.have.property('path', 'fixtures/test.txt')
-            expect(res[0]).to.have.property(
+
+            const testFile = res.find(file => file.path === 'fixtures/test.txt')
+            expect(testFile).to.have.property(
               'hash',
               'Qmf412jQZiuVUtdgnB36FXFX7xg5V6KEbSJ4dpQuhkLyfD'
             )
+
             cb()
           })
         },

test/exec.node.js

@@ -10,7 +10,6 @@ const isrunning = require('is-running')
 const cp = require('child_process')
 const path = require('path')
 const exec = require('../src/utils/exec')
-
 const os = require('os')
 
 const isWindows = os.platform() === 'win32'
@@ -73,6 +72,39 @@ describe('exec', () => {
     return
   }
 
+  it('captures stderr and stdout', (done) => {
+    let stdout = ''
+    let stderr = ''
+
+    exec(process.execPath, [
+      path.resolve(path.join(__dirname, 'fixtures', 'talky.js'))
+    ], {
+      stdout: (data) => {
+        stdout += String(data)
+      },
+      stderr: (data) => {
+        stderr += String(data)
+      }
+    }, (error) => {
+      expect(error).to.not.exist()
+      expect(stdout).to.equal('hello\n')
+      expect(stderr).to.equal('world\n')
+
+      done()
+    })
+  })
+
+  it('survives process errors and captures exit code and stderr', (done) => {
+    exec(process.execPath, [
+      path.resolve(path.join(__dirname, 'fixtures', 'error.js'))
+    ], {}, (error) => {
+      expect(error.message).to.contain('non-zero exit code 1')
+      expect(error.message).to.contain('Goodbye cruel world!')
+
+      done()
+    })
+  })
+
   it('SIGTERM kills hang', (done) => {
     const tok = token()
 
@@ -81,8 +113,7 @@ describe('exec', () => {
     const args = hang.concat(tok)
 
     const p = exec(args[0], args.slice(1), {}, (err) => {
-      // `tail -f /dev/null somerandom` errors out
-      expect(err).to.exist()
+      expect(err).to.not.exist()
 
       isRunningGrep(token, (err, running) => {
         expect(err).to.not.exist()

test/fixtures/error.js

@@ -0,0 +1,3 @@
+'use strict'
+
+throw new Error('Goodbye cruel world!')

test/fixtures/talky.js

@@ -0,0 +1,6 @@
+'use strict'
+
+console.info('hello')
+console.error('world')
+
+process.exit(0)

test/start-stop.node.js

@@ -141,7 +141,7 @@ tests.forEach((fOpts) => {
           ipfsd.start(['--should-not-exist'], (err) => {
             expect(err).to.exist()
             expect(err.message)
-              .to.match(/unknown option "should-not-exist"\n/)
+              .to.match(/unknown option "should-not-exist"/)
 
             done()
           })
@@ -253,7 +253,7 @@ tests.forEach((fOpts) => {
           ipfsd.start(['--should-not-exist'], (err) => {
             expect(err).to.exist()
             expect(err.message)
-              .to.match(/unknown option "should-not-exist"\n/)
+              .to.match(/unknown option "should-not-exist"/)
 
             done()
           })