Merge pull request #74 from testdouble/silent-default

Shore up logging behavior

.codeclimate.yml

@@ -1,17 +1,7 @@
-engines:
-  duplication:
-    enabled: true
-    config:
-      languages:
-        - javascript
-  fixme:
-    enabled: true
+version: 2
 
-ratings:
-  paths:
-    - lib/**
-    - test/**
-
-exclude_paths:
-  - example/**/*
-  - node_modules/**/*
+exclude_patterns:
+  - example/
+  - node_modules/
+  - test/
+  - "**/*.test.js"

README.md

@@ -271,25 +271,37 @@ Worth mentioning, like all options this can be set in package.json under a
 }
 ```
 
-### Silent mode
+### Log output
 
-In case you don't want to the output to be cluttered by the script contents, you
-can run scripty in silent mode:
+Scripty is now quieter by default.
+The output can be configured to a level of `verbose`, `info`, `warn`, or `error`.
+Any logs equal to or higher than the setting are shown.
+All logs are printed to STDERR (to aid in redirection and piping).
 
 ```
-$ SCRIPTY_SILENT=true npm run publish:danger:stuff
+$ SCRIPTY_LOG_LEVEL=verbose npm run publish:danger:stuff
 ```
 
-This will omit printing the path and contents of each script the command executes.
+This will print the path and contents of each script the command executes.
 
-If you always want scripty to run your scripts silently, you can set it in
-your package.json under a `"scripty"` entry:
+If you always want scripty to run your scripts at a certain level,
+you can set it in your package.json under a `"scripty"` entry:
 
 ```json
 "scripty": {
-  "silent": true
+  "logLevel": "warn"
 }
 ```
+
+`SCRIPTY_SILENT` and `SCRIPTY_QUIET` are aliases for `SCRIPTY_LOG_LEVEL=silent`
+`SCRIPTY_VERBOSE` is an alias for `SCRIPTY_LOG_LEVEL=verbose`
+(also `"silent": true`, etc in package.json#scripty)
+
+`SCRIPTY_DRY_RUN=true` implies log level `info`
+
+Explicit setting from logLevel takes precedence; otherwise,
+conflicting values between silent/verbose/dryRun will respect the highest level.
+
 ## Likely questions
 
 * **Is this black magic?** - Nope! For once, instilling some convention didn't

cli.js

@@ -4,10 +4,8 @@ var lifecycleEvent = process.env.npm_lifecycle_event
 
 if (!lifecycleEvent) {
   console.error(
-    'Error: scripty - it seems you may be running scripty from the ' +
-    'command-line directly.\n' +
-    'At this time, scripty can only be run within an ' +
-    'npm script specified in your package.json.\n\n' +
+    'scripty ERR! It seems you may be running scripty from the command-line directly.\n' +
+    'At this time, scripty can only be run within an npm script specified in your package.json.\n\n' +
     'Example package.json entry:\n\n' +
     '  "scripts": {\n' +
     '    "foo:bar": "scripty"\n' +
@@ -21,12 +19,16 @@ if (!lifecycleEvent) {
 } else {
   var scripty = require('./lib/scripty')
   var loadOption = require('./lib/load-option')
+  var log = require('./lib/log')
 
   scripty(lifecycleEvent, {
     userArgs: process.argv.slice(2),
     parallel: loadOption('parallel'),
     dryRun: loadOption('dryRun'),
+    logLevel: loadOption('logLevel'),
+    quiet: loadOption('quiet'),
     silent: loadOption('silent'),
+    verbose: loadOption('verbose'),
     spawn: {
       stdio: 'inherit'
     },
@@ -37,7 +39,7 @@ if (!lifecycleEvent) {
     }
   }, function (er, code) {
     if (er) {
-      console.error(er)
+      log.error(er)
       code = code || er.code || 1
     }
     process.exitCode = code

lib/derive-log-level.js

@@ -0,0 +1,13 @@
+var log = require('./log')
+
+module.exports = function deriveLogLevel (userOptions) {
+  if (!userOptions) return
+
+  if (userOptions.logLevel) return userOptions.logLevel
+
+  if (userOptions.verbose) return log.verbose
+
+  if (userOptions.dryRun) return log.info
+
+  if (userOptions.silent || userOptions.quiet) return log.silent
+}

lib/derive-log-level.test.js

@@ -0,0 +1,36 @@
+var subject = require('./derive-log-level')
+var log = require('./log')
+
+module.exports = {
+  'does not default': function () {
+    assert.equal(subject(), undefined)
+  },
+
+  'explicit logLevel takes precedence': function () {
+    assert.equal(subject({
+      silent: true,
+      dryRun: true,
+      verbose: true,
+      logLevel: 'warn' }), 'warn')
+  },
+
+  'passes through unrecognized values': function () {
+    assert.equal(subject({ logLevel: 'worn' }), 'worn')
+  },
+
+  'verbose preempts dry-run and silent': function () {
+    assert.equal(subject({ silent: true, dryRun: true, verbose: true }), log.verbose)
+  },
+
+  'dry-run preempts silent': function () {
+    assert.equal(subject({ silent: true, dryRun: true }), log.info)
+  },
+
+  'silent is read last': function () {
+    assert.equal(subject({ silent: true }), log.silent)
+  },
+
+  'quiet is alias for silent': function () {
+    assert.equal(subject({ quiet: true }), log.silent)
+  }
+}

lib/log.js

@@ -0,0 +1,52 @@
+const util = require('util')
+
+const constant = val => () => val
+
+const formatError = args =>
+  args.map(arg => arg instanceof Error ? arg.message : arg)
+
+const loggerWithPrefix = (prefix, writer) => (...args) =>
+  writer()(prefix, util.format(...formatError(args))
+    .replace(/(\r?\n)(?=[\s\S]+)/g, `$1${prefix} `))
+
+const silentLogger = (...args) => {
+  output += util.format(...args) + '\n'
+}
+
+let level
+let output
+
+module.exports = {
+  get level () {
+    return level.toString()
+  },
+
+  set level (l) {
+    level = module.exports[String(l).toLowerCase()]
+  },
+
+  read: () => output,
+
+  reset: () => {
+    output = ''
+    module.exports.level = 'info'
+  }
+}
+
+;[
+  ['verbose', '>'],
+  ['info', '>'],
+  ['warn', 'WARN'],
+  ['error', 'ERR!'],
+  ['silent']
+].forEach(([name, prefix], index) => {
+  const logger = loggerWithPrefix(`scripty ${prefix}`, () =>
+    level <= logger ? console.error : silentLogger)
+
+  logger.valueOf = constant(index + 1)
+  logger.toString = constant(name)
+
+  module.exports[name] = logger
+})
+
+module.exports.reset()

lib/log.test.js

@@ -0,0 +1,72 @@
+var subject = require('./log')
+
+module.exports = {
+  beforeEach: function () {
+    td.replace(console, 'error')
+    subject.reset()
+  },
+  writesToStderr: function () {
+    subject.info('foo')
+
+    td.verify(console.error('scripty >', 'foo'))
+  },
+  setTheLogLevel: {
+    verbose: function () {
+      subject.level = subject.verbose
+      subject.verbose('ity')
+      td.verify(console.error('scripty >', 'ity'))
+    },
+    info: function () {
+      subject.level = subject.info
+      td.when(console.error('ity')).thenThrow(new Error('Should not log verbose calls at INFO level'))
+      subject.verbose('ity')
+      subject.info('mation')
+      td.verify(console.error('scripty >', 'mation'))
+    },
+    warn: function () {
+      subject.level = subject.warn
+      td.when(console.error('mation')).thenThrow(new Error('Should not log info calls at WARN level'))
+      subject.info('mation')
+      subject.warn('ing')
+      td.verify(console.error('scripty WARN', 'ing'))
+    },
+    error: function () {
+      subject.level = subject.error
+      td.when(console.error('ing')).thenThrow(new Error('Should not log warn calls at ERROR level'))
+      subject.warn('ing')
+      subject.error('fail')
+      td.verify(console.error('scripty ERR!', 'fail'))
+    },
+    silent: function () {
+      subject.level = subject.silent
+      td.when(console.error('fail')).thenThrow(new Error('Should not log error calls at SILENT level'))
+      subject.error('fail')
+    }
+  },
+  modeSwitchCapturesLogs: function () {
+    subject.level = subject.silent
+
+    subject.info('bar')
+    subject.info('baz', 'noz')
+
+    td.verify(console.error(), { ignoreExtraArgs: true, times: 0 })
+    assert.equal(subject.read(), 'scripty > bar\nscripty > baz noz\n')
+  },
+  resetResetsMode: function () {
+    subject.level = subject.silent
+
+    subject.reset()
+
+    subject.info('biz')
+    td.verify(console.error('scripty >', 'biz'))
+  },
+  resetResetsLog: function () {
+    subject.level = subject.silent
+
+    subject.info('lalalal')
+
+    subject.reset()
+
+    assert.equal(subject.read(), '')
+  }
+}

lib/optionify.js

@@ -1,4 +1,5 @@
 var _ = require('lodash')
+var deriveLogLevel = require('./derive-log-level')
 
 var NULL_CB = function () {}
 module.exports = function (rawFunc, defaultOptions) {
@@ -9,6 +10,10 @@ module.exports = function (rawFunc, defaultOptions) {
     if (!cb) {
       cb = NULL_CB
     }
+
+    var logLevel = deriveLogLevel(userOptions)
+    if (logLevel) userOptions.logLevel = logLevel
+
     var fullOptions = _.defaultsDeep({}, userOptions, defaultOptions)
     return rawFunc(mainArg, fullOptions, cb)
   }

lib/resolve-script/find-executables.js

@@ -1,28 +1,21 @@
 var _ = require('lodash')
-var globFirst = require('./glob-first')
-var path = require('path')
 var async = require('async')
+var fs = require('fs')
+var path = require('path')
+var globFirst = require('./glob-first')
+var log = require('../log')
 
-var isExecutable = require('./is-executable')
-
-module.exports = function (patterns, cb) {
-  globFirst(patterns, function (er, results) {
+module.exports = (patterns, cb) =>
+  globFirst(patterns, (er, results) => {
     if (er) return cb(er)
-    async.map(results, function (result, cb) {
-      isExecutable(result, function (er, itIsExecutable) {
-        if (itIsExecutable) {
-          cb(er, path.resolve(result))
-        } else {
-          console.warn(
-            'Warning: scripty - ignoring script "' + result + '" because it' +
-            ' was not executable. Run `chmod +x "' + result + '" if you want' +
-            ' scripty to run it.'
-          )
-          cb(er, undefined)
-        }
-      })
-    }, function (er, results) {
-      cb(er, _.compact(results))
-    })
+
+    async.map(results,
+      (result, cb) => fs.access(result, fs.constants.R_OK | fs.constants.X_OK,
+        er => cb(null, er
+          ? log.warn(`Ignoring script '${result}' because it was not readable/executable.\n` +
+            `Run \`chmod u+rx '${result}'\` if you want scripty to run it.`)
+          : path.resolve(result))
+      ),
+      (er, results) => cb(er, _.compact(results))
+    )
   })
-}

lib/resolve-script/find-executables.test.js

@@ -1,5 +1,6 @@
 var _ = require('lodash')
 var path = require('path')
+var log = require('../log')
 
 var base = function (glob) {
   return path.resolve('test/fixtures/unit/find-executables', glob)
@@ -8,7 +9,7 @@ var subject = require('./find-executables')
 
 module.exports = {
   beforeEach: function () {
-    td.replace(console, 'warn')
+    log.level = 'silent'
   },
   noFilesFound: function (done) {
     subject([base('does-not-exist*')], function (er, result) {
@@ -26,11 +27,10 @@ module.exports = {
     if (process.platform === 'win32') return done()
     subject([base('file.*')], function (er, result) {
       assert.deepEqual(result, [base('file.executable')])
-      td.verify(console.warn(
-        'Warning: scripty - ignoring script "' + base('file.not.executable') +
-        '" because it was not executable. Run `chmod +x "' +
-        base('file.not.executable') + '" if you want scripty to run it.'
-      ))
+      assert.includes(log.read(),
+        `scripty WARN Ignoring script '${base('file.not.executable')}' because it was not readable/executable.\n` +
+        `scripty WARN Run \`chmod u+rx '${base('file.not.executable')}'\` if you want scripty to run it.`
+      )
       done(er)
     })
   },

lib/resolve-script/index.js

@@ -14,11 +14,10 @@ module.exports = function (name, options, cb) {
         if (ourPaths.length > 0) {
           cb(er, ourPaths)
         } else {
-          cb(new Error(
-            'Error: scripty - no script found for npm lifecycle "' + name + '"' +
-            ' matching either "' + userGlob + '" or "' + ourGlob + '". Either' +
-            ' define a script or remove "scripty" from "' + name + '" under' +
-            ' "scripts" in your package.json.'
+          cb(new Error(`No script found for npm lifecycle '${name}' matching any of:\n` +
+            `  ${String(userGlob).replace(/,/g, '\n  ')}\n` +
+            `  ${String(ourGlob).replace(/,/g, '\n  ')}\n` +
+            `Either define a script or remove "scripty" from 'scripts.${name}' in your package.json.`
           ), null)
         }
       })