Permalink
Browse files

Configurable log levels for builder itself.

* Refactor `builder.js` to pass a buffer of messages to builder to be
  later logged.
* Refactor to queue up log statements until `log.setLevel()` is called. The
  issue we're solving is logging in "./environment" when environment is
  needed to determine what level to log at.
* Adds `--log-level=info|warn|error|none` flag. Fixes #6
* Adds `--quiet` flag as alias for `--log-level=none`.
* Adds env variable `_BUILDER_ARGS_LOG_LEVEL=info|warn|error|none` to also
  control.
* Add tests and docs.
  • Loading branch information...
ryan-roemer committed Mar 5, 2016
1 parent 6988513 commit 2a7ec9099b73ca6bd2a37fdf0342402f5e5b0bf8
@@ -11,3 +11,4 @@ globals:
rules:
no-unused-expressions: 0 # Disable for Chai expression assertions.
max-nested-callbacks: 0 # Disable for nested describes.
max-statements: [2, 20] # More statements allowed in tests.
@@ -1,6 +1,11 @@
History
=======
## Current
* Add configurable log levels via `--log-level=LEVEL` and `--quiet`.
[#6](https://github.com/FormidableLabs/builder/issues/6)
## 2.8.0
* Revises `PATH`, `NODE_PATH` ordering to place archetype first, then root
@@ -219,10 +219,12 @@ $ builder run <task>
Flags:
* `--builderrc`: Path to builder config file (default: `.builderrc`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--tries`: Number of times to attempt a task (default: `1`)
* `--setup`: Single task to run for the entirety of `<action>`.
* `--setup`: Single task to run for the entirety of `<action>`
* `--quiet`: Silence logging
* `--log-level`: Level to log at (`info`, `warn`, `error`, `none`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--builderrc`: Path to builder config file (default: `.builderrc`)
##### builder concurrent
@@ -237,13 +239,15 @@ $ builder concurrent <task1> <task2> <task3>
Flags:
* `--builderrc`: Path to builder config file (default: `.builderrc`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--tries`: Number of times to attempt a task (default: `1`)
* `--setup`: Single task to run for the entirety of `<action>`.
* `--setup`: Single task to run for the entirety of `<action>`
* `--queue`: Number of concurrent processes to run (default: unlimited - `0|null`)
* `--[no-]buffer`: Buffer output until process end (default: `false`)
* `--[no-]bail`: End all processes after the first failure (default: `true`)
* `--quiet`: Silence logging
* `--log-level`: Level to log at (`info`, `warn`, `error`, `none`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--builderrc`: Path to builder config file (default: `.builderrc`)
Note that `tries` will retry _individual_ tasks that are part of the concurrent
group, not the group itself. So, if `builder concurrent --tries=3 foo bar baz`
@@ -276,14 +280,16 @@ $ builder envs <task> '[{ "FOO": "VAL1", "BAR": "VAL2" }, { "FOO": "VAL3" }]'
Flags:
* `--builderrc`: Path to builder config file (default: `.builderrc`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--tries`: Number of times to attempt a task (default: `1`)
* `--setup`: Single task to run for the entirety of `<action>`.
* `--setup`: Single task to run for the entirety of `<action>`
* `--queue`: Number of concurrent processes to run (default: unlimited - `0|null`)
* `--[no-]buffer`: Buffer output until process end (default: `false`)
* `--[no-]bail`: End all processes after the first failure (default: `true`)
* `--envs-path`: Path to JSON env variable array file (default: `null`)
* `--quiet`: Silence logging
* `--log-level`: Level to log at (`info`, `warn`, `error`, `none`)
* `--expand-archetype`: Expand `node_modules/<archetype>` with full path (default: `false`)
* `--builderrc`: Path to builder config file (default: `.builderrc`)
_Note_: The environments JSON array will overwrite **existing** values in the
environment.
@@ -14,6 +14,7 @@ var log = require("../lib/log");
* @param {Object} [opts] Options object
* @param {Object} [opts.env] Environment object to mutate (Default `process.env`)
* @param {Array} [opts.argv] Arguments array (Default: `process.argv`)
* @param {Array} [opts.msgs] Array of log messages (`{ level, type, msg }`)
* @param {Function} callback Callback `(err)`
* @returns {void}
*/
@@ -30,6 +31,17 @@ module.exports = function (opts, callback) {
env: opts.env
});
// Set up logger state.
log.setLevel({
env: env,
argv: opts.argv
});
// Drain outer `builder` messages manually (may be global or locally-sourced).
(opts.msgs || []).forEach(function (obj) {
log[obj.level](obj.type, obj.msg);
});
// Infer task to run
var task = new Task({
config: config,
@@ -2,7 +2,17 @@
"use strict";
var path = require("path");
var log = require("../lib/log");
// Buffer up log messages to pass on.
//
// **Scenario**: We can't import `log` here and use it's internal queue because
// this might be the _global_ builder in this script, which if we then switch
// to _local_ builder below, we'll import a different (local) `log` and when
// that gets called, it wouldn't have any internal queue / notion of these log
// events here. So, instead of using the internal log queue, we manually create
// an array of messages in the same format and drain in `builder-core`
// explicitly.
var msgs = [];
// Infer if we are global and there is a local version available.
var builderPath = require.resolve("./builder-core");
@@ -12,16 +22,27 @@ var localPath = path.resolve(process.cwd(), "node_modules/builder/bin/builder-co
if (builderPath !== localPath) {
try {
builderPath = require.resolve(localPath);
log.info("local-detect", "Switched to local builder at: " + localPath);
msgs.push({
level: "info", type: "local-detect",
msg: "Switched to local builder at: " + localPath
});
} catch (err) {
log.warn("local-detect", "Error importing local builder: " + err.message);
log.info("local-detect", "Using global builder at: " + builderPath);
msgs.push({
level: "warn", type: "local-detect",
msg: "Error importing local builder: " + err.message
});
msgs.push({
level: "info", type: "local-detect",
msg: "Using global builder at: " + builderPath
});
}
}
// Import and run.
var builder = require(builderPath);
builder(function (err) {
builder({
msgs: msgs
}, function (err) {
/*eslint-disable no-process-exit*/
process.exit(err ? err.code || 1 : 0);
});
@@ -61,7 +61,17 @@ var FLAGS = {
default: ".builderrc"
},
help: FLAG_HELP,
version: FLAG_VERSION
version: FLAG_VERSION,
quiet: {
desc: "Silence logging",
types: [Boolean],
default: false
},
"log-level": {
desc: "Level to log at (`info`, `warn`, `error`, `none`)",
types: [String],
default: "info"
}
},
run: {
@@ -1,31 +1,105 @@
"use strict";
var chalk = require("chalk");
var args = require("./args");
// Wrap "type".
var wrapType = function (type) {
return "[builder" + (type ? ":" + type : "") + "]";
};
// Levels
var LEVELS = {
info: 0,
warn: 1,
error: 2,
none: 3
};
/**
* A super-small logger.
*/
module.exports = {
// TODO(6): Configurable log levels.
// https://github.com/FormidableLabs/builder/issues/6
_logger: function () {
return console;
var log = module.exports = {
/**
* Set log level from command flags or environment.
*
* **NOTE - Side Effects**: Mutates environment.
*
* @param {Object} opts Options object
* @param {Object} opts.argv Arguments array.
* @param {Object} opts.env Environment object to mutate (Default `process.env`)
* @returns {void}
*/
setLevel: function (opts) {
opts = opts || {};
var env = opts.env && opts.env.env || process.env;
// Try to determine log level from environment.
var level = env._BUILDER_ARGS_LOG_LEVEL;
// If not, determine log level from command line.
if (!level) {
var parsed = args.general(opts.argv);
level = parsed.quiet === true ? "none" : parsed.logLevel;
}
// Statefully set level.
env._BUILDER_ARGS_LOG_LEVEL = level;
log._level = LEVELS[level];
if (typeof log._level === "undefined") {
throw new Error("Unknown log level: " + level);
}
// Drain message queue.
log._drainQueue();
},
info: function (type, msg) {
this._logger().info([chalk.green(wrapType(type)), msg].join(" "));
// Nuke everything for test runs.
_unsetLevel: function () {
delete process.env._BUILDER_ARGS_LOG_LEVEL;
delete log._level;
delete log._queue;
},
warn: function (type, msg) {
this._logger().warn([chalk.yellow(wrapType(type)), msg].join(" "));
// Drain internal queue and emit log events.
_drainQueue: function () {
(log._queue || []).forEach(function (obj) {
log[obj.level](obj.type, obj.msg);
});
log._queue = null;
},
error: function (type, msg) {
this._logger().error([chalk.red(wrapType(type)), msg].join(" "));
_logger: function () {
return console;
},
_wrapper: function (level, color, type, msg) { // eslint-disable-line max-params
// Queue if level is unset.
//
// **Scenario**: This queue is used when `log` has been imported from the
// actual builder instance that is running. However, we have calls to log
// events before we can call `log.setLevel`, so need to queue until that
// happens.
if (typeof log._level === "undefined") {
log._queue = log._queue || [];
log._queue.push({ level: level, type: type, msg: msg });
return;
}
// Should only get to here, _after_ `log.setlevel()` is imported.
// Check if logging at this integer level.
if (LEVELS[level] < log._level) {
return;
}
// Call directly once level is set.
// This is also used to drain the queue.
var formattedMsg = [chalk[color](wrapType(type)), msg].join(" ");
log._logger()[level](formattedMsg);
}
};
// Actual implementation methods.
log.info = log._wrapper.bind(log, "info", "green");
log.warn = log._wrapper.bind(log, "warn", "yellow");
log.error = log._wrapper.bind(log, "error", "red");
@@ -11,6 +11,7 @@
var mockFs = require("mock-fs");
var fs = require("fs");
var sinon = require("sinon");
var log = require("../../../lib/log");
var base = module.exports = {
// Generic test helpers.
@@ -43,4 +44,5 @@ beforeEach(function () {
afterEach(function () {
base.mockFs.restore();
base.sandbox.restore();
log._unsetLevel();
});
@@ -97,6 +97,26 @@ describe("bin/builder-core", function () {
throw new Error("should have already thrown");
});
it("errors on bad log level", function () {
base.mockFs({
"package.json": "{}"
});
var callback = base.sandbox.spy();
try {
run({
argv: ["node", "builder", "help", "--log-level=BAD"]
}, callback);
} catch (err) {
expect(err).to.have.property("message").that.contains("Unknown log level: BAD");
expect(callback).to.not.be.called;
return;
}
throw new Error("should have already thrown");
});
});
describe("builder --version", function () {
@@ -223,6 +243,62 @@ describe("bin/builder-core", function () {
}));
it("runs with quiet log output", stdioWrap(function (done) {
base.sandbox.spy(Task.prototype, "run");
base.mockFs({
"package.json": JSON.stringify({
"scripts": {
"bar": "echo BAR_TASK"
}
}, null, 2)
});
run({
argv: ["node", "builder", "run", "--quiet", "bar"]
}, function (err) {
if (err) { return done(err); }
expect(Task.prototype.run).to.be.calledOnce;
expect(process.stdout.write).to.be.calledWithMatch("BAR_TASK");
expect(logStubs.info).not.be.called;
expect(logStubs.warn).not.be.called;
expect(logStubs.error).not.be.called;
done();
});
}));
it("runs with specified log level", stdioWrap(function (done) {
base.sandbox.stub(process.stderr, "write");
base.sandbox.spy(Task.prototype, "run");
base.mockFs({
"package.json": JSON.stringify({
"scripts": {
"bar": "BAD_COMMAND"
}
}, null, 2)
});
run({
argv: ["node", "builder", "run", "--log-level=error", "bar"]
}, function (err) {
expect(err).to.have.property("message")
.that.contains("Command failed").and
.that.contains("BAD_COMMAND");
expect(Task.prototype.run).to.be.calledOnce;
expect(process.stderr.write).to.be.calledWithMatch("BAD_COMMAND");
expect(logStubs.info).not.be.called;
expect(logStubs.warn).not.be.called;
expect(logStubs.error)
.to.be.calledWithMatch("Command failed").and
.to.be.calledWithMatch("BAD_COMMAND");
done();
});
}));
it("runs an <archetype>/package.json command", stdioWrap(function (done) {
base.sandbox.spy(Task.prototype, "run");
base.mockFs({
Oops, something went wrong.

0 comments on commit 2a7ec90

Please sign in to comment.