diff --git a/README.md b/README.md index 2d0a755c..4f32ac2c 100644 --- a/README.md +++ b/README.md @@ -249,6 +249,16 @@ function handleErrors (fn) { } ``` +### Logging + +Micro provides built-in logging to help visualise requests. When `NODE_ENV` is set to `development`, micro will display the request along with any json body like this: + +![Development Logging](https://cloud.githubusercontent.com/assets/22048/19218565/2c6081ba-8db2-11e6-93df-9e256a8354fb.png) + +This behavior can be overridden by using the cli argument `--log` which can be set to `dev`, `prod`, or `off`. The `prod` version is a condensed log that will not show the json body: + +Production Logging + ### Testing Micro makes tests compact and a pleasure to read and write. diff --git a/bin/micro b/bin/micro index 12811762..cdf9c0c0 100755 --- a/bin/micro +++ b/bin/micro @@ -14,7 +14,8 @@ const args = parse(process.argv, { alias: { H: 'host', h: 'help', - p: 'port' + p: 'port', + L: 'log' }, boolean: ['h'], default: { @@ -28,6 +29,7 @@ const help = () => { console.log(`Usage: micro [opts] -H, --host Host to listen on [0.0.0.0] -p, --port Port to listen on [3000] + -L, --log dev|prod|off [off] -h, --help Show this help message`); } @@ -79,8 +81,8 @@ if ('function' !== typeof mod) { process.exit(1) } -const { port, host } = args -serve(mod).listen(port, host, err => { +const { port, host, log } = args +serve(mod, {log}).listen(port, host, err => { if (err) { console.error('micro:', err.stack) process.exit(1) diff --git a/lib/index.js b/lib/index.js index b016f24c..1837111a 100644 --- a/lib/index.js +++ b/lib/index.js @@ -5,8 +5,22 @@ const server = require('http').Server const getRawBody = require('raw-body') const typer = require('media-typer') const isStream = require('isstream') +const chalk = require('chalk') +const jsome = require('jsome') const DEV = 'development' === process.env.NODE_ENV +jsome.colors = { + num: 'cyan', + str: 'green', + bool: 'red', + regex: 'blue', + undef: 'grey', + null: 'grey', + attr: 'reset', + quot: 'reset', + punc: 'reset', + brack: 'reset' +} module.exports = exports = serve @@ -16,18 +30,26 @@ exports.send = send exports.sendError = sendError exports.createError = createError -function serve(fn, {onError = null} = {}) { +function serve(fn, {onError = null, log} = {}) { + if (typeof log === 'undefined' && DEV) { + log = 'dev' + } + if (onError) { console.warn('[DEPRECATED] onError is deprecated and will be removed in a future release. Please use your own try/catch as needed.') } return server((req, res) => { - run(req, res, fn, onError || sendError) + run(req, res, fn, onError || sendError, {log}) }) } -async function run(req, res, fn, onError) { +async function run(req, res, fn, onError, {log}) { try { + if (log === 'dev' || log === 'prod') { + await logRequest(req, res, log) + } + const val = await fn(req, res) // return a non-null value -> send @@ -44,7 +66,8 @@ async function json(req, {limit = '1mb'} = {}) { const type = req.headers['content-type'] const length = req.headers['content-length'] const encoding = typer.parse(type).parameters.charset - const str = await getRawBody(req, {limit, length, encoding}) + req.rawBody = req.rawBody || getRawBody(req, {limit, length, encoding}) + const str = await req.rawBody try { return JSON.parse(str) @@ -94,6 +117,7 @@ function send(res, code, obj = null) { str = JSON.stringify(obj) } res.setHeader('Content-Type', 'application/json') + res._logBody = obj } else { str = obj } @@ -122,3 +146,33 @@ function createError(code, msg, orig) { err.originalError = orig return err } + +let requestCounter = 0 + +async function logRequest(req, res, log) { + const start = new Date() + const requestIndex = ++requestCounter + const dateString = `${chalk.grey(start.toLocaleTimeString())}` + console.log(`> #${requestIndex} ${chalk.bold(req.method)} ${req.url}\t\t${dateString}`) + + if (log === 'dev') { + try { + const parsedJson = await json(req) + jsome(parsedJson) + } catch (err) { + console.log(`JSON body could not be parsed: ${err.message}`) + } + } + + res.once('finish', () => { + const delta = new Date() - start + const time = delta < 10000 ? `${delta}ms` : `${Math.round(delta / 1000)}s` + const endDateString = `${chalk.grey(new Date().toLocaleTimeString())}` + + console.log(`< #${requestIndex} ${chalk.bold(res.statusCode)} [+${time}]\t${endDateString}`) + + if (log === 'dev' && res._logBody) { + jsome(res._logBody) + } + }) +} diff --git a/package.json b/package.json index fbbbd17f..b09e97c4 100644 --- a/package.json +++ b/package.json @@ -69,8 +69,10 @@ }, "dependencies": { "async-to-gen": "1.3.0", + "chalk": "^1.1.3", "is-async-supported": "1.2.0", "isstream": "0.1.2", + "jsome": "^2.3.25", "media-typer": "0.3.0", "minimist": "1.2.0", "raw-body": "2.2.0" diff --git a/test/index.js b/test/index.js index 795aace0..40769921 100644 --- a/test/index.js +++ b/test/index.js @@ -90,6 +90,24 @@ test('send()', async t => { } }) +test('send(200, ) with log', async t => { + const fn = async (req, res) => { + send(res, 200, { + a: 'b' + }) + } + + const url = await listen(fn, {log: 'dev'}) + + const res = await request(url, { + json: true + }) + + t.deepEqual(res, { + a: 'b' + }) +}) + test('return ', async t => { const fn = async () => 'woot' @@ -294,6 +312,55 @@ test('json', async t => { t.deepEqual(body.response, 'json') }) +test('json parses twice', async t => { + const fn = async (req, res) => { + await json(req) + const body = await json(req) + + send(res, 200, { + response: body.some.cool + }) + } + + const url = await listen(fn) + + const body = await request(url, { + method: 'POST', + body: { + some: { + cool: 'json' + } + }, + json: true + }) + + t.deepEqual(body.response, 'json') +}) + +test('json with log', async t => { + const fn = async (req, res) => { + const body = await json(req) + + send(res, 200, { + response: body.some.cool + }) + } + + const url = await listen(fn, {log: 'dev'}) + + const body = await request(url, { + method: 'POST', + body: { + some: { + cool: 'json' + } + }, + json: true + }) + + t.deepEqual(body.response, 'json') +}) + test('json limit (below)', async t => { const fn = async (req, res) => { const body = await json(req, { diff --git a/yarn.lock b/yarn.lock index def4e5ef..fd389830 100644 --- a/yarn.lock +++ b/yarn.lock @@ -961,6 +961,10 @@ camelcase@^2.0.0, camelcase@^2.1.0: version "2.1.1" resolved "https://registry.yarnpkg.com/camelcase/-/camelcase-2.1.1.tgz#7c1d16d679a1bbe59ca02cacecfb011e201f5a1f" +camelcase@^3.0.0: + version "3.0.0" + resolved "https://registry.yarnpkg.com/camelcase/-/camelcase-3.0.0.tgz#32fc4b9fcdaf845fcdf7e73bb97cac2261f0ab0a" + capture-stack-trace@^1.0.0: version "1.0.0" resolved "https://registry.yarnpkg.com/capture-stack-trace/-/capture-stack-trace-1.0.0.tgz#4a6fa07399c26bba47f0b2496b4d0fb408c5550d" @@ -1039,6 +1043,14 @@ cli-width@^2.0.0: version "2.1.0" resolved "https://registry.yarnpkg.com/cli-width/-/cli-width-2.1.0.tgz#b234ca209b29ef66fc518d9b98d5847b00edf00a" +cliui@^3.2.0: + version "3.2.0" + resolved "https://registry.yarnpkg.com/cliui/-/cliui-3.2.0.tgz#120601537a916d29940f934da3b48d585a39213d" + dependencies: + string-width "^1.0.1" + strip-ansi "^3.0.1" + wrap-ansi "^2.0.0" + co-with-promise@^4.6.0: version "4.6.0" resolved "https://registry.yarnpkg.com/co-with-promise/-/co-with-promise-4.6.0.tgz#413e7db6f5893a60b942cf492c4bec93db415ab7" @@ -1179,7 +1191,7 @@ debug@^2.1.1, debug@^2.2.0: dependencies: ms "0.7.2" -decamelize@^1.1.2: +decamelize@^1.1.1, decamelize@^1.1.2: version "1.2.0" resolved "https://registry.yarnpkg.com/decamelize/-/decamelize-1.2.0.tgz#f6534d15148269b20352e7bee26f501f9a191290" @@ -1706,6 +1718,10 @@ generate-object-property@^1.1.0: dependencies: is-property "^1.0.0" +get-caller-file@^1.0.1: + version "1.0.2" + resolved "https://registry.yarnpkg.com/get-caller-file/-/get-caller-file-1.0.2.tgz#f702e63127e7e231c160a80c1554acb70d5047e5" + get-port@^2.1.0: version "2.1.0" resolved "https://registry.yarnpkg.com/get-port/-/get-port-2.1.0.tgz#8783f9dcebd1eea495a334e1a6a251e78887ab1a" @@ -1944,6 +1960,10 @@ invariant@^2.2.0: dependencies: loose-envify "^1.0.0" +invert-kv@^1.0.0: + version "1.0.0" + resolved "https://registry.yarnpkg.com/invert-kv/-/invert-kv-1.0.0.tgz#104a8e4aaca6d3d8cd157a8ef8bfab2d7a3ffdb6" + irregular-plurals@^1.0.0: version "1.2.0" resolved "https://registry.yarnpkg.com/irregular-plurals/-/irregular-plurals-1.2.0.tgz#38f299834ba8c00c30be9c554e137269752ff3ac" @@ -1952,7 +1972,7 @@ is-arrayish@^0.2.1: version "0.2.1" resolved "https://registry.yarnpkg.com/is-arrayish/-/is-arrayish-0.2.1.tgz#77c99840527aa8ecb1a8ba697b80645a7a926a9d" -is-async-supported@^1.2.0: +is-async-supported@1.2.0: version "1.2.0" resolved "https://registry.yarnpkg.com/is-async-supported/-/is-async-supported-1.2.0.tgz#20d58ac4d6707eb1cb3712dd38480c0536f27c07" @@ -2199,6 +2219,14 @@ jsesc@~0.5.0: version "0.5.0" resolved "https://registry.yarnpkg.com/jsesc/-/jsesc-0.5.0.tgz#e7dee66e35d6fc16f710fe91d5cf69f70f08911d" +jsome@^2.3.25: + version "2.3.25" + resolved "https://registry.yarnpkg.com/jsome/-/jsome-2.3.25.tgz#dfa0a41938bd2852d559ada632cd5c491e97cea2" + dependencies: + chalk "^1.1.3" + json-stringify-safe "^5.0.1" + yargs "^4.8.0" + json-schema@0.2.3: version "0.2.3" resolved "https://registry.yarnpkg.com/json-schema/-/json-schema-0.2.3.tgz#b480c892e59a2f05954ce727bd3f2a4e882f9e13" @@ -2209,7 +2237,7 @@ json-stable-stringify@^1.0.0, json-stable-stringify@^1.0.1: dependencies: jsonify "~0.0.0" -json-stringify-safe@~5.0.1: +json-stringify-safe@^5.0.1, json-stringify-safe@~5.0.1: version "5.0.1" resolved "https://registry.yarnpkg.com/json-stringify-safe/-/json-stringify-safe-5.0.1.tgz#1296a2d58fd45f19a0f6ce01d65701e2c735b6eb" @@ -2255,6 +2283,12 @@ lazy-req@^1.1.0: version "1.1.0" resolved "https://registry.yarnpkg.com/lazy-req/-/lazy-req-1.1.0.tgz#bdaebead30f8d824039ce0ce149d4daa07ba1fac" +lcid@^1.0.0: + version "1.0.0" + resolved "https://registry.yarnpkg.com/lcid/-/lcid-1.0.0.tgz#308accafa0bc483a3867b4b6f2b9506251d1b835" + dependencies: + invert-kv "^1.0.0" + levn@^0.3.0, levn@~0.3.0: version "0.3.0" resolved "https://registry.yarnpkg.com/levn/-/levn-0.3.0.tgz#3b09924edf9f083c0490fdd4c0bc4421e04764ee" @@ -2288,6 +2322,10 @@ locate-path@^2.0.0: p-locate "^2.0.0" path-exists "^3.0.0" +lodash.assign@^4.0.3, lodash.assign@^4.0.6: + version "4.2.0" + resolved "https://registry.yarnpkg.com/lodash.assign/-/lodash.assign-4.2.0.tgz#0d99f3ccd7a6d261d19bdaeb9245005d285808e7" + lodash.camelcase@^4.1.1: version "4.3.0" resolved "https://registry.yarnpkg.com/lodash.camelcase/-/lodash.camelcase-4.3.0.tgz#b28aa6288a2b9fc651035c7711f65ab6190331a6" @@ -2607,6 +2645,12 @@ os-homedir@^1.0.0: version "1.0.2" resolved "https://registry.yarnpkg.com/os-homedir/-/os-homedir-1.0.2.tgz#ffbc4988336e0e833de0c168c7ef152121aa7fb3" +os-locale@^1.4.0: + version "1.4.0" + resolved "https://registry.yarnpkg.com/os-locale/-/os-locale-1.4.0.tgz#20f9f17ae29ed345e8bde583b13d2009803c14d9" + dependencies: + lcid "^1.0.0" + os-tmpdir@^1.0.0, os-tmpdir@^1.0.1: version "1.0.2" resolved "https://registry.yarnpkg.com/os-tmpdir/-/os-tmpdir-1.0.2.tgz#bbe67406c79aa85c5cfec766fe5734555dfa1274" @@ -3101,6 +3145,14 @@ request@^2.74.0, request@^2.79.0: tunnel-agent "~0.4.1" uuid "^3.0.0" +require-directory@^2.1.1: + version "2.1.1" + resolved "https://registry.yarnpkg.com/require-directory/-/require-directory-2.1.1.tgz#8c64ad5fd30dab1c976e2344ffe7f792a6a6df42" + +require-main-filename@^1.0.1: + version "1.0.1" + resolved "https://registry.yarnpkg.com/require-main-filename/-/require-main-filename-1.0.1.tgz#97f717b69d48784f5f526a6c5aa8ffdda055a4d1" + require-precompiled@^0.1.0: version "0.1.0" resolved "https://registry.yarnpkg.com/require-precompiled/-/require-precompiled-0.1.0.tgz#5a1b52eb70ebed43eb982e974c85ab59571e56fa" @@ -3169,7 +3221,7 @@ semver-diff@^2.0.0: version "5.3.0" resolved "https://registry.yarnpkg.com/semver/-/semver-5.3.0.tgz#9b2ce5d3de02d17c6012ad326aa6b4d0cf54f94f" -set-blocking@~2.0.0: +set-blocking@^2.0.0, set-blocking@~2.0.0: version "2.0.0" resolved "https://registry.yarnpkg.com/set-blocking/-/set-blocking-2.0.0.tgz#045f9782d011ae9a6803ddd382b24392b3d890f7" @@ -3537,6 +3589,10 @@ vlq@^0.2.1: version "0.2.1" resolved "https://registry.yarnpkg.com/vlq/-/vlq-0.2.1.tgz#14439d711891e682535467f8587c5630e4222a6c" +which-module@^1.0.0: + version "1.0.0" + resolved "https://registry.yarnpkg.com/which-module/-/which-module-1.0.0.tgz#bba63ca861948994ff307736089e3b96026c2a4f" + which@^1.2.9: version "1.2.12" resolved "https://registry.yarnpkg.com/which/-/which-1.2.12.tgz#de67b5e450269f194909ef23ece4ebe416fa1192" @@ -3555,10 +3611,21 @@ widest-line@^1.0.0: dependencies: string-width "^1.0.1" +window-size@^0.2.0: + version "0.2.0" + resolved "https://registry.yarnpkg.com/window-size/-/window-size-0.2.0.tgz#b4315bb4214a3d7058ebeee892e13fa24d98b075" + wordwrap@~1.0.0: version "1.0.0" resolved "https://registry.yarnpkg.com/wordwrap/-/wordwrap-1.0.0.tgz#27584810891456a4171c8d0226441ade90cbcaeb" +wrap-ansi@^2.0.0: + version "2.1.0" + resolved "https://registry.yarnpkg.com/wrap-ansi/-/wrap-ansi-2.1.0.tgz#d8fc3d284dd05794fe84973caecdd1cf824fdd85" + dependencies: + string-width "^1.0.1" + strip-ansi "^3.0.1" + wrappy@1: version "1.0.2" resolved "https://registry.yarnpkg.com/wrappy/-/wrappy-1.0.2.tgz#b5243d8f3ec1aa35f1364605bc0d1036e30ab69f" @@ -3661,6 +3728,36 @@ xtend@^4.0.0, xtend@~4.0.1: version "4.0.1" resolved "https://registry.yarnpkg.com/xtend/-/xtend-4.0.1.tgz#a5c6d532be656e23db820efb943a1f04998d63af" +y18n@^3.2.1: + version "3.2.1" + resolved "https://registry.yarnpkg.com/y18n/-/y18n-3.2.1.tgz#6d15fba884c08679c0d77e88e7759e811e07fa41" + yallist@^2.0.0: version "2.0.0" resolved "https://registry.yarnpkg.com/yallist/-/yallist-2.0.0.tgz#306c543835f09ee1a4cb23b7bce9ab341c91cdd4" + +yargs-parser@^2.4.1: + version "2.4.1" + resolved "https://registry.yarnpkg.com/yargs-parser/-/yargs-parser-2.4.1.tgz#85568de3cf150ff49fa51825f03a8c880ddcc5c4" + dependencies: + camelcase "^3.0.0" + lodash.assign "^4.0.6" + +yargs@^4.8.0: + version "4.8.1" + resolved "https://registry.yarnpkg.com/yargs/-/yargs-4.8.1.tgz#c0c42924ca4aaa6b0e6da1739dfb216439f9ddc0" + dependencies: + cliui "^3.2.0" + decamelize "^1.1.1" + get-caller-file "^1.0.1" + lodash.assign "^4.0.3" + os-locale "^1.4.0" + read-pkg-up "^1.0.1" + require-directory "^2.1.1" + require-main-filename "^1.0.1" + set-blocking "^2.0.0" + string-width "^1.0.1" + which-module "^1.0.0" + window-size "^0.2.0" + y18n "^3.2.1" + yargs-parser "^2.4.1"