Demonstration for https://github.com/isaacs/npm/pull/2166

npmissue2166.js

/** Dependency: 'colors', `npm install colors` first **/

/**
 *
 * This file demonstrates some broken parts of NPM's API, in particular the use of
 * outfd and logfd options. This module will span 4 child processes to run NPM via
 * its API, first for npm.commands.search and then for npm.commands.install. The 4
 * child processes use different outfd & logfd options:
 *   (1) stdout (i.e. `1`)
 *   (2) an actual file descriptor
 *   (3) a net.Stream object pointing to an actual file descriptor
 *   (4) `null`
 * As demonstrated, option (1) is the only usable option that works consistently.
 *
 */

require('colors')
var fs = require('fs')
  , net = require('net')
  , util = require('util')
  , npm = require('npm')
  , childProcess = require('child_process')

    // not interesting, just pretty logging
  , log = function (msg) {
      if (/^\(C\)\d+ /.test(msg))
        console.log(msg)
      else if (msg) {
        util.print(
            (process.argv.length == 2 ? '(P)' : '(C)')
          + process.pid + ' '
          + (Array.isArray(msg) ? msg.join(' ') : msg)
          + '\n')
      } else
        console.log()
    }

    // make a temp file with a random name that we can get npm to log to
  , openTempFile = function (cb) {
      var file = '/tmp/npm2166.' + String(Math.random()).substr(2) + '.log'
      fs.open(file, 'w', cb.bind(null, file))
    }

    // count lines in a file
  , lineCount = function (file) {
      return fs.readFileSync(file, 'utf-8').split('\n').length
    }

    // run an npm command through the API, intended to show 'search' and 'install'
  , npmCmd = function (cmd, fd, cb) {
      npm.load({ logfd: fd, outfd: fd }, function (err) {
        if (err) throw err

        npm.commands[cmd]([ 'traversty' ], function (err, results) {
          if (err) throw err

          log('Got results: ' + Object.keys(results).join(', '))
          cb && cb()
        })
      })
    }

    // spawn a child process on this file
  , spawn = function (type, cmd, cb) {
      var child = childProcess.spawn('node', [ __filename, type, cmd ], { env: process.env })
      child.stdout.on('data', function (data) { String(data).replace(/\n$/, '').split('\n').forEach(log) })
      child.on('exit', function () { cb() })
    }

    // run npm.commands.X in 4 different ways in spawned child processes
  , runCmdSpawned = function (cmd, cb) {
      // (1) pass in logfd=1,outfd=1 (i.e. stdout)
      log()
      log(('Running npm.commands.' + cmd + '() with fd=stdout...').green)
      log('-----------------------------------------------\n'.green)
      spawn('stdout', cmd, function () {
        // (2) make a temp file and pass in the fd for that file as logfd&outfd
        log()
        log(('Running npm.commands.' + cmd + '() with fd=file...').green)
        log('-----------------------------------------------\n'.green)
        spawn('file', cmd, function () {
          // (3) make a temp file and pass in a stream to that file's fd as logfd&outfd
          log()
          log(('Running npm.commands.' + cmd + '() with fd=stream...').green)
          log('-----------------------------------------------\n'.green)
          spawn('stream', cmd, function () {
            // (4) pass in logfd=null,outfd=null (i.e. no output please, this used to work in Node 0.4)
            log()
            log(('Running npm.commands.' + cmd + '() with fd=null...').green)
            log('-----------------------------------------------\n'.green)
            spawn('nullfd', cmd, function () {
              log()
              cb && cb()
            })
          })
        })
      })
    }

    // the 3 different child process methods
  , childExec = {
        // plain command execute with out & log to fd=1 (stdout)
        stdout: function () {
          npmCmd(process.argv[3], 1, function () {
            log('Normal exit...'.yellow)
          })
        }

        // open file, pass fd to npm, close file
      , file: function () {
          openTempFile(function (file, err, fd) {
            if (err) throw err
            log(('Writing output to ' + file + ' via fd').yellow)
            npmCmd(process.argv[3], fd, function () { // callback needed to clean this baby up
              /**
               *
               * Here we have our first NPM output issues. We have no way (as far as I can tell)
               * to know when NPM has finished its business. Our callback is called before NPM
               * is finished so we don't know when to close the output file, missing out on some
               * of the output. Comment out the first setTimeout() and you'll see the file is 4
               * rather than 5 lines.
               *
               * The second issue is that the process just won't die if we use a file fd, hence
               * the process.exit(), there isn't even an uncaught exception and no clue regarding
               * what's holding the process up.
               *
               */
              log('Forcing fd close in 2.5s...'.yellow)
              setTimeout(function () {
                fs.closeSync(fd)
                log(('Output file has ' + lineCount(file) + ' lines').yellow)
                log('Closed fd.. Now what? Forcing exit after 1s or else this won\'t die...'.red)
                setTimeout(process.exit.bind(null, 1), 1000)
              }, 2500)
            })
          })
        }

        // open file, pass new net.Stream to that file's fd
      , stream: function () {
          openTempFile(function (file, err, fd) {
            if (err) throw err
            log(('Writing output to ' + file + ' via stream').yellow)
            /**
             *
             * Here we have the same issue as with using an fd, if we close the stream prematurely
             * then we don't get the full NPM output (4 lines instead of 5). But, at least this
             * time if we close the stream with destroySoon() our process doesn't hang and need
             * a forced exit.
             *
             * Unfortunately this doesn't work for npm.commands.install() because logfd&outfd
             * are passed to JSON.stringify() in makeEnv() in NPM (see NPM issue #2166). So we
             * get an uncaught exception that we then have to force a process.exit() from
             * (otherwise it will never exit).
             *
             */
            var stream = new net.Stream(fd)
            npmCmd(process.argv[3], stream, function () {
              log('Requesting stream close in 2.5s...'.yellow)
              stream.destroySoon()
            })
            stream.on('close', function () {
              log(('Output file has ' + lineCount(file) + ' lines').yellow)
              log('Stream closed, hoping for a normal exit...'.yellow)
            })
          })
        }

        /**
         *
         * And here is our last issue, NPM used to support null for logfd&outfd but that broke
         * with Node 0.6 (apparently a Node thing, not an NPM thing). Ender was using null to
         * omit output but the process wouldn't end so now uses logfd&outfd=1.
         * Using null causes an uncaught exception in both search() and install().
         *
         */
      , nullfd: function () {
          npmCmd(process.argv[3], null, function () {
            log('Exiting... hopefully'.yellow)
          })
        }
    }

// make sure we can see anything interesting
process.on('uncaughtException', function (err) {
  log(('Caught exception: ' + err + ':').red)
  log(err.stack)
  log('Forcing exit after 1s in case this process won\'t die...'.red)
  setTimeout(process.exit.bind(null, 1), 1000)
})

// main execute, parent runs spawned children, children run command depending on first argument
if (process.argv.length == 2) {
  runCmdSpawned('search', function () {
    runCmdSpawned('install', function () {
      log('Finished, parent process ending...'.green)
    })
  })
} else
  childExec[process.argv[2]]()