diff --git a/.github/ISSUE_TEMPLATE.md b/.github/ISSUE_TEMPLATE.md new file mode 100644 index 00000000..0e7d5931 --- /dev/null +++ b/.github/ISSUE_TEMPLATE.md @@ -0,0 +1,2 @@ +# THIS REPO IS NO LONGER SUPPORTED +# PLEASE REFER TO THE [MAIN REPO](https://github.com/restify/node-restify) diff --git a/.github/PULL_REQUEST_TEMPLATE.MD b/.github/PULL_REQUEST_TEMPLATE.MD new file mode 100644 index 00000000..0e7d5931 --- /dev/null +++ b/.github/PULL_REQUEST_TEMPLATE.MD @@ -0,0 +1,2 @@ +# THIS REPO IS NO LONGER SUPPORTED +# PLEASE REFER TO THE [MAIN REPO](https://github.com/restify/node-restify) diff --git a/CHANGES.md b/CHANGES.md index e33efe5a..bbe932ee 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -1,5 +1,36 @@ +# 2.0.0 +- Breaking: Audit logger plugin no longer accepts a `opts.logBuffer` object. +- Breaking: Audit logger plugin requires a `opts.event` string which identifies + the restify event the logger is listening on. It must be one of `pre`,`routed`, + or `after` +- Breaking: Audit logger plugin no longer emits an `auditLog` event, but + instead emits an `audit` event. +- Breaking: Metrics plugin now returns `inflightRequests` instead of + `unfinishedRequests` +# 1.5.1 + +- FIX: staticServe plugin should not assume `req.connectionState()` method since + it's 5.x restify only. + +# 1.5.0 + +- #81: move `reqIdHeaders` option from restify 5.x core into the plugin repo. + Requires 5.x restify to work properly. + +# 1.4.1 +- #82: fix bug in context plugin where context bucket was shared between + requests. + +# 1.4.0 +- #79: audit log now uses `req.connectionState()` instead of `req.clientClosed` + field. Compatible only with restify@5.0.0-beta-3.0 or newer. +- #78: new metrics plugin for use with `server.on('after',...` event. + +# 1.3.0 +- Add assertions to context plugin. + # 1.2.0 -Add request context plugin. +- #73 Add request context plugin. # 1.0.2 diff --git a/README.md b/README.md index 3efdd4de..d192ad76 100644 --- a/README.md +++ b/README.md @@ -1,3 +1,11 @@ +# Deprecated! + +This repo is being kept for historical purposes and may be deleted in the future. To use the restify plugins, please use: + +```js +require('restify').plugins +``` + # restify-plugins [![NPM Version](https://img.shields.io/npm/v/restify-plugins.svg)](https://npmjs.org/package/restify-plugins) @@ -40,9 +48,6 @@ This module includes the following header parser plugins: This module includes the following data parsing plugins: -* `auditLogger(options)` - an audit logger for recording all handled requests - * `options.log` {Object} bunyan logger - * `options.body` {?} * `bodyParser(options)` - parses POST bodies to `req.body`. automatically uses one of the following parsers based on content type: * `urlEncodedBodyParser(options)` - parses url encoded form bodies * `jsonBodyParser(options)` - parses JSON POST bodies @@ -77,6 +82,13 @@ This module includes the following data parsing plugins: * `requestLogger(options)` - adds timers for each handler in your request chain * `options.properties` {Object} properties to pass to bunyan's `log.child()` method +The module includes the following request plugins: + +* `reqIdHeaders(options)` - a plugin that lets you use incoming request header + values to set the request id (5.x compatible only) + * `options.headers` {Array} an array of header names to use. lookup + precedence is left to right (lowest index first) + The module includes the following response plugins: * `dateParser(delta)` - expires requests based on current time + delta @@ -105,6 +117,37 @@ The module includes the following response plugins: * `options.startHeader` {String} header name for the start time of the request * `options.timeoutHeader` {String} The header name for the time in milliseconds that should ellapse before the request is considered expired. +The module includes the following plugins to be used with restify's `pre`, `routed`, and `after` +event, e.g., `server.on('after', plugins.auditLogger());`: + +* `auditLogger(options)` - an audit logger for recording all handled requests + * `options.event` {String} The name of the event, one of `pre`, `routed`, or `after` + * `options.log` {Object} bunyan logger + * `[options.server]` {Object} restify server. if passed in, causes server to + emit 'auditlog' event after audit logs are flushed + * `[options.printLog]` {Boolean} when true, prints audit logs. defaults to true. + +The module includes the following plugins to be used with restify's `after` +event, e.g., `server.on('after', plugins.metrics());`: +* `metrics(callback)` - a metrics plugin which will invoke callback with the + the following parameters (5.x compatible only): + * `err` {Object} an error if the request had an error + * `metrics` {Object} - metrics about the request + * `metrics.statusCode` {Number} status code of the response. can be undefined + in the case of an uncaughtException + * `metrics.method` {String} http request verb + * `metrics.latency` {Number} request latency + * `metrics.path` {String} req.path() value + * `metrics.inflightRequests` {Number} Number of inflight requests pending in restify. + * `metrics.unifinishedRequests` {Number} Same as `inflightRequests` + * `metrics.connectionState` {String} can be either 'close', 'aborted', or + undefined. If this value is set, err will be a corresponding + `RequestCloseError` or `RequestAbortedError`. If connectionState is either + 'close' or 'aborted', then the statusCode is not applicable since the + connection was severed before a response was written. + * `req` {Object} the request obj + * `res` {Object} the response obj + * `route` {Object} the route obj that serviced the request ## Contributing diff --git a/lib/index.js b/lib/index.js index 135bc43a..e493dadf 100644 --- a/lib/index.js +++ b/lib/index.js @@ -8,27 +8,30 @@ module.exports = { acceptParser: require('./plugins/accept'), auditLogger: require('./plugins/audit'), authorizationParser: require('./plugins/authorization'), - bodyReader: require('./plugins/bodyReader'), bodyParser: require('./plugins/bodyParser'), + bodyReader: require('./plugins/bodyReader'), conditionalRequest: require('./plugins/conditionalRequest'), dateParser: require('./plugins/date'), - jsonp: require('./plugins/jsonp'), - urlEncodedBodyParser: require('./plugins/formBodyParser'), - requestLogger: require('./plugins/bunyan'), - gzipResponse: require('./plugins/gzip'), fullResponse: require('./plugins/fullResponse'), + gzipResponse: require('./plugins/gzip'), jsonBodyParser: require('./plugins/jsonBodyParser'), + jsonp: require('./plugins/jsonp'), multipartBodyParser: require('./plugins/multipartBodyParser'), + oauth2TokenParser: require('./plugins/oauth2TokenParser'), queryParser: require('./plugins/query'), + metrics: require('./plugins/metrics'), requestExpiry: require('./plugins/requestExpiry'), + requestLogger: require('./plugins/bunyan'), serveStatic: require('./plugins/static'), throttle: require('./plugins/throttle'), - oauth2TokenParser: require('./plugins/oauth2TokenParser'), + urlEncodedBodyParser: require('./plugins/formBodyParser'), + pre: { context: require('./pre/context'), dedupeSlashes: require('./pre/dedupeSlashes'), pause: require('./pre/pause'), + reqIdHeaders: require('./pre/reqIdHeaders'), sanitizePath: require('./pre/prePath'), strictQueryParams: require('./pre/strictQueryParams'), userAgentConnection: require('./pre/userAgent') diff --git a/lib/plugins/audit.js b/lib/plugins/audit.js index 292acd6f..bda5b3a3 100644 --- a/lib/plugins/audit.js +++ b/lib/plugins/audit.js @@ -5,52 +5,54 @@ var assert = require('assert-plus'); var bunyan = require('bunyan'); var HttpError = require('restify-errors').HttpError; +var VError = require('verror'); ///--- API + /** - * Returns a Bunyan audit logger suitable to be used in a server.on('after') - * event. I.e.: - * - * server.on('after', restify.auditLogger({ log: myAuditStream })); - * - * This logs at the INFO level. + * @param {object} opts The options object. + * @param {object} opts.log The logger. + * @param {string} opts.event The event from the server which initiates the + * log, one of 'pre', 'routed', or 'after' + * @param {object} [opts.server] The restify server, used to emit the audit log + * object programttically + * @param {boolean} [opts.printLog] Whether to print the log via the logger. * * @public * @function auditLogger - * @param {Object} options at least a bunyan logger (log). - * optionally .server object to emit log. .logBuffer which is a - * ringbuffer object to store certain amount of log, - * printLog flag, default is true, - * if printlog set to false, user need to pass in server object - * listen to auditlog event to get log information - * @returns {Function} to be used in server.after. + * @returns {Function} + * @emits audit when an audit log has been generated */ -function auditLogger(options) { - assert.object(options, 'options'); - assert.object(options.log, 'options.log'); - assert.optionalObject(options.server, 'options.server'); - assert.optionalObject(options.logBuffer, 'options.logBuffer'); - assert.optionalBool(options.printLog, 'options.printLog'); - //use server object to emit log data - var server = options.server; - //use logMetrics ringbuffer to store certain period of log records - var logMetrics = options.logBuffer; - //default always print log - var printLog = options.printLog; +function auditLogger(opts) { + assert.object(opts, 'opts'); + assert.object(opts.log, 'opts.log'); + assert.string(opts.event, 'opts.event'); + assert.optionalObject(opts.server, 'opts.server'); + assert.optionalBool(opts.printLog, 'opts.printLog'); + + if (opts.event !== 'after' && opts.event !== 'pre' && + opts.event !== 'routed') { + throw new VError('opts.event must be %s, %s, or %s, but is %s', 'pre', + 'routed', 'after', opts.event); + } + + var server = opts.server; + var printLog = opts.printLog; if (typeof printLog === 'undefined') { printLog = true; } var errSerializer = bunyan.stdSerializers.err; - if (options.log.serializers && options.log.serializers.err) { - errSerializer = options.log.serializers.err; + if (opts.log.serializers && opts.log.serializers.err) { + errSerializer = opts.log.serializers.err; } - var log = options.log.child({ + var log = opts.log.child({ audit: true, + component: opts.event, serializers: { err: errSerializer, req: function auditRequestSerializer(req) { @@ -61,8 +63,7 @@ function auditLogger(options) { var timers = {}; (req.timers || []).forEach(function (time) { var t = time.time; - var _t = Math.floor((1000000 * t[0]) + - (t[1] / 1000)); + var _t = Math.floor((1000000 * t[0]) + (t[1] / 1000)); timers[time.name] = _t; }); return ({ @@ -75,10 +76,10 @@ function auditLogger(options) { httpVersion: req.httpVersion, trailers: req.trailers, version: req.version(), - body: options.body === true ? - req.body : undefined, + body: opts.body === true ? req.body : undefined, timers: timers, - clientClosed: req.clientClosed + connectionState: (req.connectionState && + req.connectionState()) }); }, res: function auditResponseSerializer(res) { @@ -86,10 +87,9 @@ function auditLogger(options) { return (false); } - var body; - if (options.body === true) { + if (opts.body === true) { if (res._body instanceof HttpError) { body = res._body.body; } else { @@ -109,7 +109,6 @@ function auditLogger(options) { function audit(req, res, route, err) { var latency = res.get('Response-Time'); - var timestamp = new Date().getTime(); if (typeof (latency) !== 'number') { latency = Date.now() - req._time; @@ -124,20 +123,28 @@ function auditLogger(options) { err: err, latency: latency, secure: req.secure, - _audit: true + _audit: true, + event: opts.event }; if (printLog) { - log.info(obj, 'handled: %d', res.statusCode); - } - - if (logMetrics && logMetrics instanceof bunyan.RingBuffer) { - obj.timestamp = timestamp; - logMetrics.write(obj); + switch (opts.event) { + case 'after': + log.info(obj, 'handled: %d', res.statusCode); + break; + case 'pre': + log.info(obj, 'pre'); + break; + case 'routed': + log.info(obj, 'routed'); + break; + default: + throw new Error('Unexpected audit event: ' + opts.event); + } } if (server) { - server.emit('auditlog', obj); + server.emit('audit', obj); } return (true); @@ -149,4 +156,5 @@ function auditLogger(options) { ///-- Exports + module.exports = auditLogger; diff --git a/lib/plugins/bodyParser.js b/lib/plugins/bodyParser.js index 726ae36c..e54607f4 100644 --- a/lib/plugins/bodyParser.js +++ b/lib/plugins/bodyParser.js @@ -39,6 +39,13 @@ function bodyParser(options) { var parseFieldedText = fieldedTextParser(opts); function parseBody(req, res, next) { + // #100 don't parse the body again if we've read it once + if (req._parsedBody) { + next(); + return; + } else { + req._parsedBody = true; + } // Allow use of 'requestBodyOnGet' flag to allow for merging of // the request body of a GET request into req.params if (req.method === 'HEAD') { diff --git a/lib/plugins/bodyReader.js b/lib/plugins/bodyReader.js index b2b92472..3c26f8e3 100644 --- a/lib/plugins/bodyReader.js +++ b/lib/plugins/bodyReader.js @@ -14,6 +14,7 @@ var errors = require('restify-errors'); var BadDigestError = errors.BadDigestError; var RequestEntityTooLargeError = errors.RequestEntityTooLargeError; var PayloadTooLargeError = errors.PayloadTooLargeError; +var UnsupportedMediaTypeError = errors.UnsupportedMediaTypeError; var MD5_MSG = 'Content-MD5 \'%s\' didn\'t match \'%s\''; @@ -67,6 +68,14 @@ function bodyReader(options) { var maxBodySize = opts.maxBodySize || 0; function readBody(req, res, next) { + // #100 don't read the body again if we've read it once + if (req._readBody) { + next(); + return; + } else { + req._readBody = true; + } + if ((req.getContentLength() === 0 && !req.isChunked()) || req.contentType() === 'multipart/form-data' || req.contentType() === 'application/octet-stream') { @@ -81,6 +90,8 @@ function bodyReader(options) { var hash; var md5; + var unsupportedCompression; + if ((md5 = req.headers['content-md5'])) { hash = crypto.createHash('md5'); } @@ -88,6 +99,12 @@ function bodyReader(options) { function done() { bodyWriter.end(); + if (unsupportedCompression) { + var error = unsupportedCompression + ' not supported'; + next(new UnsupportedMediaTypeError(error)); + return; + } + if (maxBodySize && bytesReceived > maxBodySize) { var msg = 'Request body size exceeds ' + maxBodySize; var err; @@ -118,12 +135,17 @@ function bodyReader(options) { next(); } - if (req.headers['content-encoding'] === 'gzip') { + if (req.headers['content-encoding'] === undefined) { + // This handles the original else branch + req.once('end', done); + } else if (req.headers['content-encoding'] === 'gzip') { gz = zlib.createGunzip(); gz.on('data', bodyWriter.write); gz.once('end', done); req.once('end', gz.end.bind(gz)); } else { + unsupportedCompression = req.headers['content-encoding']; + res.setHeader('Accept-Encoding', 'gzip'); req.once('end', done); } diff --git a/lib/plugins/cors.js b/lib/plugins/cors.js deleted file mode 100644 index 23690ca2..00000000 --- a/lib/plugins/cors.js +++ /dev/null @@ -1,138 +0,0 @@ -// Copyright 2013 Mark Cavage, Inc. All rights reserved. - -'use strict'; - -var assert = require('assert-plus'); - - -///--- Globals - -var ALLOW_HEADERS = [ - 'accept', - 'accept-version', - 'content-type', - 'request-id', - 'origin', - 'x-api-version', - 'x-request-id' -]; - -var EXPOSE_HEADERS = [ - 'api-version', - 'content-length', - 'content-md5', - 'content-type', - 'date', - 'request-id', - 'response-time' -]; - -// Normal -var AC_ALLOW_ORIGIN = 'Access-Control-Allow-Origin'; -var AC_ALLOW_CREDS = 'Access-Control-Allow-Credentials'; -var AC_EXPOSE_HEADERS = 'Access-Control-Expose-Headers'; - - -///--- Internal Functions - -function matchOrigin(req, origins) { - var origin = req.headers.origin; - - function belongs(o) { - if (origin === o || o === '*') { - origin = o; - return (true); - } - - return (false); - } - - return ((origin && origins.some(belongs)) ? origin : false); -} - - -///--- API - -/** - * From http://www.w3.org/TR/cors/#resource-processing-model - * - * If "simple" request (paraphrased): - * - * 1. If the Origin header is not set, or if the value of Origin is not a - * case-sensitive match to any values listed in `opts.origins`, do not - * send any CORS headers - * - * 2. If the resource supports credentials add a single - * 'Access-Control-Allow-Credentials' header with the value as "true", and - * ensure 'AC-Allow-Origin' is not '*', but is the request header value, - * otherwise add a single Access-Control-Allow-Origin header, with either the - * value of the Origin header or the string "*" as value - * - * 3. Add Access-Control-Expose-Headers as appropriate - * - * Pre-flight requests are handled by the router internally - * - * @public - * @function cors - * @param {Object} options an options object - * @returns {Function} - */ -function cors(options) { - assert.optionalObject(options, 'options'); - var opts = options || {}; - assert.optionalArrayOfString(opts.origins, 'options.origins'); - assert.optionalBool(opts.credentials, 'options.credentials'); - assert.optionalArrayOfString(opts.headers, 'options.headers'); - - cors.credentials = opts.credentials; - cors.origins = opts.origins || ['*']; - - var headers = (opts.headers || []).slice(0); - var origins = opts.origins || ['*']; - - EXPOSE_HEADERS.forEach(function (h) { - if (headers.indexOf(h) === -1) { - headers.push(h); - } - }); - - // Handler for simple requests - function restifyCORSSimple(req, res, next) { - var origin; - - if (!(origin = matchOrigin(req, origins))) { - next(); - return; - } - - function corsOnHeader() { - origin = req.headers.origin; - - if (opts.credentials) { - res.setHeader(AC_ALLOW_ORIGIN, origin); - res.setHeader(AC_ALLOW_CREDS, 'true'); - } else { - res.setHeader(AC_ALLOW_ORIGIN, origin); - } - - res.setHeader(AC_EXPOSE_HEADERS, headers.join(', ')); - } - - res.once('header', corsOnHeader); - next(); - } - - return (restifyCORSSimple); -} - - -///--- Exports - -module.exports = cors; - -// All of these are needed for the pre-flight code over in lib/router.js -cors.ALLOW_HEADERS = ALLOW_HEADERS; -cors.EXPOSE_HEADERS = EXPOSE_HEADERS; -cors.credentials = false; -cors.origins = []; -cors.matchOrigin = matchOrigin; diff --git a/lib/plugins/fullResponse.js b/lib/plugins/fullResponse.js index 3907307b..d4ee5a67 100644 --- a/lib/plugins/fullResponse.js +++ b/lib/plugins/fullResponse.js @@ -6,51 +6,11 @@ var crypto = require('crypto'); var httpDate = require('../utils/httpDate'); -///--- Globals - -var ALLOW_HEADERS = [ - 'Accept', - 'Accept-Version', - 'Content-Length', - 'Content-MD5', - 'Content-Type', - 'Date', - 'Api-Version', - 'Response-Time' -].join(', '); - -var EXPOSE_HEADERS = [ - 'Api-Version', - 'Request-Id', - 'Response-Time' -].join(', '); - - ///--- API function setHeaders(req, res) { var hash; var now = new Date(); - var methods; - - if (!res.getHeader('Access-Control-Allow-Origin')) { - res.setHeader('Access-Control-Allow-Origin', '*'); - } - - if (!res.getHeader('Access-Control-Allow-Headers')) { - res.setHeader('Access-Control-Allow-Headers', ALLOW_HEADERS); - } - - if (!res.getHeader('Access-Control-Allow-Methods')) { - if (res.methods && res.methods.length > 0) { - methods = res.methods.join(', '); - res.setHeader('Access-Control-Allow-Methods', methods); - } - } - - if (!res.getHeader('Access-Control-Expose-Headers')) { - res.setHeader('Access-Control-Expose-Headers', EXPOSE_HEADERS); - } if (!res.getHeader('Connection')) { res.setHeader('Connection', diff --git a/lib/plugins/gzip.js b/lib/plugins/gzip.js index 84a80126..8ad16616 100644 --- a/lib/plugins/gzip.js +++ b/lib/plugins/gzip.js @@ -9,7 +9,13 @@ var assert = require('assert-plus'); function _writeHead(originalFunction) { this.removeHeader('Content-Length'); - originalFunction.apply(this, Array.prototype.slice.call(arguments, 1)); + var argsLength = arguments.length; + var args = new Array(argsLength - 1); + + for (var i = 1; i < argsLength; i++) { + args[i - 1] = arguments[i]; + } + originalFunction.apply(this, args); } ///--- API diff --git a/lib/plugins/metrics.js b/lib/plugins/metrics.js new file mode 100644 index 00000000..d3789b3f --- /dev/null +++ b/lib/plugins/metrics.js @@ -0,0 +1,68 @@ +'use strict'; + +var assert = require('assert-plus'); + + +///--- API + +/* + * a plugin that listens to the server's after event and emits information + * about that request. + * + * server.on('after', plugins.metrics(function onMetrics(err, metrics) { + * // metrics is an object containing information about the request + * })); + * @public + * @function createMetrics + * @param {Object} opts an options obj + * @param {Object} opts.server restify server + * @param {Function} callback a callback fn + * @returns {Function} returns a function suitable to be used with restify + * server's `after` event + */ +function createMetrics(opts, callback) { + + assert.object(opts, 'opts'); + assert.object(opts.server, 'opts.server'); + assert.func(callback, 'callback'); + + return function metrics(req, res, route, err) { + + var data = { + // response status code. in most cases this should be a proper + // http status code, but in the case of an uncaughtException it can + // be undefined. otherwise, in most normal scenarios, even calling + // res.send() or res.end() should result in a 200 by default. + statusCode: res.statusCode, + // REST verb + method: req.method, + // overall request latency + latency: Date.now() - req._time, + // the cleaned up url path + // e.g., /foo?a=1 => /foo + path: req.path(), + // connection state can currently only have the following values: + // 'close' | 'aborted' | undefined. + // + // it is possible to get a 200 statusCode with a connectionState + // value of 'close' or 'aborted'. i.e., the client timed out, + // but restify thinks it "sent" a response. connectionState should + // always be the primary source of truth here, and check it first + // before consuming statusCode. otherwise, it may result in skewed + // metrics. + connectionState: (req.connectionState && + req.connectionState()), + unfinishedRequests: (opts.server.inflightRequests && + opts.server.inflightRequests()), + inflightRequests: (opts.server.inflightRequests && + opts.server.inflightRequests()) + }; + + return callback(err, data, req, res, route); + }; +} + + +///-- Exports + +module.exports = createMetrics; diff --git a/lib/plugins/static.js b/lib/plugins/static.js index 3db15fa6..cede1c10 100644 --- a/lib/plugins/static.js +++ b/lib/plugins/static.js @@ -49,7 +49,10 @@ function serveStatic(options) { var re = new RegExp('^' + escapeRE(p) + '/?.*'); function serveFileFromStats(file, err, stats, isGzip, req, res, next) { - if (req.clientClosed) { + + if (typeof req.connectionState === 'function' && + (req.connectionState() === 'close' || + req.connectionState() === 'aborted')) { next(false); return; } diff --git a/lib/pre/context.js b/lib/pre/context.js index 868e5ade..43411dfa 100644 --- a/lib/pre/context.js +++ b/lib/pre/context.js @@ -13,8 +13,9 @@ var assert = require('assert-plus'); * @returns {Function} */ function ctx() { - var data = {}; return function context(req, res, next) { + var data = {}; + req.set = function set(key, value) { assert.string(key, 'key must be string'); diff --git a/lib/pre/reqIdHeaders.js b/lib/pre/reqIdHeaders.js new file mode 100644 index 00000000..da012017 --- /dev/null +++ b/lib/pre/reqIdHeaders.js @@ -0,0 +1,42 @@ +'use strict'; + +var assert = require('assert-plus'); + +var DEFAULT_HEADERS = ['request-id', 'x-request-id']; + + +/** + * Automatically reuse incoming request header as the request id. + * @public + * @function createReqIdHeaders + * @param {Object} opts an options object + * @param {Array} opts.headers array of headers from where to pull existing + * request id headers + * @returns {Function} + */ +function createReqIdHeaders(opts) { + + assert.object(opts, 'opts'); + assert.arrayOfString(opts.headers, 'opts.headers'); + + var headers = opts.headers.concat(DEFAULT_HEADERS); + + return function reqIdHeaders(req, res, next) { + + for (var i = 0; i < headers.length; i++) { + var val = req.header(headers[i]); + + if (val) { + req.id(val); + break; + } + } + + return next(); + }; +} + + +///--- Exports + +module.exports = createReqIdHeaders; diff --git a/package.json b/package.json index 9978119a..4f519919 100644 --- a/package.json +++ b/package.json @@ -46,7 +46,7 @@ "Jorge Serrano" ], "name": "restify-plugins", - "version": "1.3.0", + "version": "1.5.1", "description": "A collection of core restify plugins", "main": "lib/index.js", "homepage": "https://github.com/restify/plugins", @@ -65,7 +65,6 @@ "prehandlers", "queryparser", "bodyparser", - "cors", "accept", "audit", "authorization", @@ -83,20 +82,22 @@ }, "devDependencies": { "chai": "^3.4.1", - "coveralls": "^2.11.6", - "eslint": "^3.0.1", + "eslint": "^3.19.0", + "coveralls": "^2.13.0", "istanbul": "^0.4.1", "jscs": "^3.0.0", + "lodash": "^4.17.4", "mkdirp": "^0.5.1", - "mocha": "^2.5.3", + "mocha": "^3.2.0", "nsp": "^2.4.0", "restify": "git+https://git@github.com/restify/node-restify.git#5.x", "restify-clients": "^1.1.1", - "rimraf": "^2.4.3" + "rimraf": "^2.4.3", + "validator": "^7.0.0" }, "dependencies": { "assert-plus": "^1.0.0", - "bunyan": "^1.8.0", + "bunyan": "^1.8.10", "csv": "^1.1.0", "escape-regexp-component": "^1.0.2", "formidable": "^1.0.17", @@ -106,6 +107,7 @@ "once": "^1.3.2", "qs": "^6.2.1", "restify-errors": "^4.2.3", - "vasync": "^1.6.3" + "vasync": "^1.6.3", + "verror": "^1.9.0" } } diff --git a/test/audit.test.js b/test/audit.test.js index d022298d..7788e35d 100644 --- a/test/audit.test.js +++ b/test/audit.test.js @@ -1,11 +1,14 @@ 'use strict'; +// runtime modules +var PassThrough = require('stream').PassThrough; + // external requires var assert = require('chai').assert; var bunyan = require('bunyan'); +var lodash = require('lodash'); var restify = require('restify'); var restifyClients = require('restify-clients'); -//var util = require('util'); // local files var helper = require('./lib/helper'); @@ -17,6 +20,7 @@ var SERVER; var CLIENT; var PORT; + describe('audit logger', function () { beforeEach(function (done) { @@ -42,82 +46,8 @@ describe('audit logger', function () { SERVER.close(done); }); - it('should buffer audit logger', function (done) { - var logBuffer = new bunyan.RingBuffer({ - limit: 1000 - }); - var fooRequest, barRequest, collectLog; - SERVER.on('after', plugins.auditLogger({ - log: bunyan.createLogger({ - name: 'audit', - streams: [{ - level: 'info', - stream: process.stdout - }] - }), - server: SERVER, - logMetrics : logBuffer, - printLog : false - })); - - var self = this; - SERVER.get('/foo', function (req, res, next) { - res.send(200, {testdata : 'foo'}); - next(); - }); - - SERVER.get('/bar', function (req, res, next) { - res.send(200, {testdata : 'bar'}); - next(); - }); - - SERVER.get('/auditrecords', function (req, res, next) { - var data = logBuffer.records; - res.send(200, data); - next(); - }); - - - fooRequest = function foo(_, callback) { - CLIENT.get('/foo', function (err, req, res) { - assert.ifError(err); - assert.equal(JSON.parse(res.body).testdata, 'foo'); - return callback(err, true); - }); - }; - - barRequest = function bar(_, callback) { - CLIENT.get('/bar', function (err, req, res) { - assert.ifError(err); - assert.equal(JSON.parse(res.body).testdata, 'bar'); - return callback(err, res.body); - }); - }; - collectLog = function log(_, callback) { - CLIENT.get('/auditrecords', function (err, req, res) { - assert.ifError(err); - var data = JSON.parse(res.body); - assert.ok(data); - data.forEach(function (d) { - assert.isNumber(d.latency); - }); - return callback(err, true); - }); - }; - vasync.pipeline({ - funcs: [ - fooRequest, - barRequest, - collectLog - ], - args: self - }, function (err, results) { - assert.ifError(err); - //console.log('results: %s', util.inspect(results, null, 3)); - done(); - }); - }); it('audit logger should print log by default', function (done) { + var logBuffer = new bunyan.RingBuffer({ limit: 1000 }); @@ -131,7 +61,7 @@ describe('audit logger', function () { }] }), server: SERVER, - logMetrics : logBuffer + event: 'after' })); @@ -146,7 +76,11 @@ describe('audit logger', function () { }); SERVER.get('/auditrecords', function (req, res, next) { - var data = logBuffer.records; + // strip log records of req/res as they will cause + // serialization issues. + var data = logBuffer.records.map(function (record) { + return lodash.omit(record, 'req', 'res'); + }, []); res.send(200, data); next(); }); @@ -162,6 +96,7 @@ describe('audit logger', function () { done(); }); }; + vasync.forEachParallel({ func: function clientRequest(urlPath, callback) { CLIENT.get(urlPath, function (err, req, res) { @@ -173,12 +108,13 @@ describe('audit logger', function () { inputs: ['/foo', '/bar'] }, function (err, results) { assert.ifError(err); - //console.log('results: %s', util.inspect(results, null, 2)); collectLog(); }); }); + + it('test audit logger emit', function (done) { - var auditLoggerObj = plugins.auditLogger({ + SERVER.once('after', plugins.auditLogger({ log: bunyan.createLogger({ name: 'audit', streams: [{ @@ -186,11 +122,11 @@ describe('audit logger', function () { stream: process.stdout }] }), - server: SERVER - }); + server: SERVER, + event: 'after' + })); - SERVER.on('after', auditLoggerObj); - SERVER.on('auditlog', function (data) { + SERVER.once('audit', function (data) { assert.ok(data); assert.ok(data.req_id); assert.equal(data.req.url, '/audit', @@ -198,6 +134,7 @@ describe('audit logger', function () { assert.isNumber(data.latency); done(); }); + SERVER.get('/audit', [ plugins.queryParser(), function (req, res, next) { @@ -205,12 +142,13 @@ describe('audit logger', function () { next(); } ]); + CLIENT.get('/audit', function (err, req, res) { assert.ifError(err); }); + }); - }); it('should log handler timers', function (done) { // Dirty hack to capture the log record using a ring buffer. var ringbuffer = new bunyan.RingBuffer({ limit: 1 }); @@ -223,7 +161,8 @@ describe('audit logger', function () { type: 'raw', stream: ringbuffer }] - }) + }), + event: 'after' })); SERVER.get('/audit', function aTestHandler(req, res, next) { @@ -288,7 +227,8 @@ describe('audit logger', function () { type: 'raw', stream: ringbuffer }] - }) + }), + event: 'after' })); SERVER.get('/audit', function (req, res, next) { @@ -351,7 +291,8 @@ describe('audit logger', function () { type: 'raw', stream: ringbuffer }] - }) + }), + event: 'after' })); SERVER.get('/audit', function (req, res, next) { @@ -387,7 +328,8 @@ describe('audit logger', function () { type: 'raw', stream: ringbuffer }] - }) + }), + event: 'after' })); SERVER.get('/audit', [ @@ -415,4 +357,77 @@ describe('audit logger', function () { }); }); + it('should work with pre events', function (done) { + + var ptStream = new PassThrough(); + + SERVER.once('pre', plugins.auditLogger({ + log: bunyan.createLogger({ + name: 'audit', + streams:[ { + level: 'info', + stream: ptStream + }] + }), + event: 'pre' + })); + + SERVER.get('/audit', [ + plugins.queryParser(), + function (req, res, next) { + res.send(); + next(); + } + ]); + + ptStream.on('data', function (data) { + var log = JSON.parse(data); + assert.equal('pre', log.component); + assert.ok(log.req_id); + assert.ok(log.req); + assert.ok(log.res); + }); + + CLIENT.get('/audit?a=1&b=2', function (err, req, res) { + assert.ifError(err); + done(); + }); + }); + + it('should work with routed events', function (done) { + + var ptStream = new PassThrough(); + + SERVER.once('routed', plugins.auditLogger({ + log: bunyan.createLogger({ + name: 'audit', + streams:[ { + level: 'info', + stream: ptStream + }] + }), + event: 'routed' + })); + + SERVER.get('/audit', [ + plugins.queryParser(), + function (req, res, next) { + res.send(); + next(); + } + ]); + + ptStream.on('data', function (data) { + var log = JSON.parse(data); + assert.equal('routed', log.component); + assert.ok(log.req_id); + assert.ok(log.req); + assert.ok(log.res); + }); + + CLIENT.get('/audit?a=1&b=2', function (err, req, res) { + assert.ifError(err); + done(); + }); + }); }); diff --git a/test/bodyReader.js b/test/bodyReader.js new file mode 100644 index 00000000..bc61cad2 --- /dev/null +++ b/test/bodyReader.js @@ -0,0 +1,117 @@ +'use strict'; + +// core requires + +// external requires +var assert = require('chai').assert; +var restify = require('restify'); +var restifyClients = require('restify-clients'); + +// local files +var helper = require('./lib/helper'); +var plugins = require('../lib'); + +// local globals +var SERVER; +var CLIENT; +var PORT; + + +describe('body reader', function () { + + describe('gzip content encoding', function () { + + beforeEach(function (done) { + SERVER = restify.createServer({ + dtrace: helper.dtrace, + log: helper.getLog('server') + }); + + SERVER.listen(0, '127.0.0.1', function () { + PORT = SERVER.address().port; + + done(); + }); + }); + + afterEach(function (done) { + CLIENT.close(); + SERVER.close(done); + }); + + it('should parse gzip encoded content', function (done) { + SERVER.use(plugins.bodyParser()); + + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + retry: false, + gzip: {} + }); + + SERVER.post('/compressed', function (req, res, next) { + assert.equal(req.body.apple, 'red'); + res.send(); + next(); + }); + + CLIENT.post('/compressed', { + apple: 'red' + }, function (err, _, res) { + assert.ifError(err); + assert.equal(res.statusCode, 200); + done(); + }); + }); + + it('should not accept unsupported content encoding', function (done) { + SERVER.use(plugins.bodyParser()); + + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + retry: false, + headers: { + 'content-encoding': 'unsupported' + } + }); + + SERVER.post('/compressed', function (req, res, next) { + assert.equal(req.body.apple, 'red'); + res.send(); + next(); + }); + + CLIENT.post('/compressed', { + apple: 'red' + }, function (err, _, res) { + assert.isOk(err, 'should fail'); + assert.equal(res.statusCode, 415); + assert.equal(res.headers['accept-encoding'], 'gzip'); + done(); + }); + }); + + it('should parse unencoded content', function (done) { + SERVER.use(plugins.bodyParser()); + + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + retry: false + }); + + SERVER.post('/compressed', function (req, res, next) { + assert.equal(req.body.apple, 'red'); + res.send(); + next(); + }); + + CLIENT.post('/compressed', { + apple: 'red' + }, function (err, _, res) { + assert.ifError(err); + assert.equal(res.statusCode, 200); + done(); + }); + }); + }); + +}); diff --git a/test/context.test.js b/test/context.test.js index e69de29b..9ed111e1 100644 --- a/test/context.test.js +++ b/test/context.test.js @@ -0,0 +1,96 @@ +'use strict'; + +// external requires +var assert = require('chai').assert; +var restify = require('restify'); +var restifyClients = require('restify-clients'); + +// local files +var helper = require('./lib/helper'); +var plugins = require('../lib'); + +// local globals +var SERVER; +var CLIENT; +var PORT; + +describe('accept parser', function () { + + before(function (done) { + SERVER = restify.createServer({ + dtrace: helper.dtrace, + log: helper.getLog('server') + }); + + SERVER.use(plugins.pre.context()); + + SERVER.listen(0, '127.0.0.1', function () { + PORT = SERVER.address().port; + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + dtrace: helper.dtrace, + retry: false + }); + + done(); + }); + }); + + after(function (done) { + CLIENT.close(); + SERVER.close(done); + }); + + + it('should use context', function (done) { + + SERVER.get('/', [ + function one(req, res, next) { + req.set('foo', { + a: 1 + }); + return next(); + }, + function two(req, res, next) { + assert.deepEqual(req.get('foo'), { + a: 1 + }); + req.get('foo').b = 2; + req.set('bar', [1]); + return next(); + }, + function three(req, res, next) { + assert.deepEqual(req.get('foo'), { + a: 1, + b: 2 + }); + assert.deepEqual(req.get('bar'), [1]); + res.send(); + return next(); + } + ]); + + CLIENT.get('/', function (err, _, res) { + assert.ifError(err); + assert.equal(res.statusCode, 200); + return done(); + }); + }); + + + it('should not share context', function (done) { + + SERVER.get('/1', function one(req, res, next) { + // ensure we don't get context from previous request + assert.equal(req.get('foo', null)); + res.end(); + return next(); + }); + + CLIENT.get('/1', function (err, _, res) { + assert.ifError(err); + assert.equal(res.statusCode, 200); + return done(); + }); + }); +}); diff --git a/test/fieldedTextParser.test.js b/test/fieldedTextParser.test.js index ded1e6a9..f3145c15 100644 --- a/test/fieldedTextParser.test.js +++ b/test/fieldedTextParser.test.js @@ -55,7 +55,6 @@ describe('fielded text parser', function () { SERVER.close(done); }); - it('should parse CSV body', function (done) { var options = { path: '/data', @@ -94,6 +93,46 @@ describe('fielded text parser', function () { }); }); + it('#100 should parse CSV body even if bodyparser declared twice', + function (done) { + SERVER.use(plugins.bodyParser()); + var options = { + path: '/data', + headers: { + 'Content-Type': 'text/csv' + } + }; + + SERVER.post('/data', function respond(req, res, next) { + res.send({ + status: 'okay', + parsedReq: req.body + }); + return next(); + }); + + CLIENT.post(options, function (err, req) { + assert.ifError(err); + req.on('result', function (errReq, res) { + assert.ifError(errReq); + res.body = ''; + res.setEncoding('utf8'); + res.on('data', function (chunk) { + res.body += chunk; + }); + res.on('end', function () { + res.body = JSON.parse(res.body); + var parsedReqStr = JSON.stringify(res.body.parsedReq); + var objectStr = JSON.stringify(OBJECT_CSV); + assert.equal(parsedReqStr, objectStr); + done(); + }); + }); + req.write(DATA_CSV); + req.end(); + }); + }); + it('should parse TSV body', function (done) { var options = { path: '/data', @@ -161,6 +200,5 @@ describe('fielded text parser', function () { req.end(); }); }); - }); diff --git a/test/metrics.test.js b/test/metrics.test.js new file mode 100644 index 00000000..df9daefc --- /dev/null +++ b/test/metrics.test.js @@ -0,0 +1,186 @@ +'use strict'; + +// external requires +var assert = require('chai').assert; +var restify = require('restify'); +var restifyClients = require('restify-clients'); + +// local files +var helper = require('./lib/helper'); +var plugins = require('../lib'); + +// local globals +var SERVER; +var CLIENT; +var PORT; + + +describe('request metrics plugin', function () { + + beforeEach(function (done) { + SERVER = restify.createServer({ + dtrace: helper.dtrace, + log: helper.getLog('server'), + handleUncaughtExceptions: true + }); + + SERVER.listen(0, '127.0.0.1', function () { + PORT = SERVER.address().port; + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + dtrace: helper.dtrace, + retry: false, + requestTimeout: 200 + }); + + done(); + }); + }); + + afterEach(function (done) { + CLIENT.close(); + SERVER.removeAllListeners(); + SERVER.close(done); + }); + + + it('should return metrics for a given request', function (done) { + + SERVER.on('after', plugins.metrics({ + server: SERVER + }, function (err, metrics, req, res, route) { + assert.ifError(err); + + assert.isObject(metrics, 'metrics'); + assert.equal(metrics.statusCode, 202); + assert.isAtLeast(metrics.latency, 100); + assert.equal(metrics.path, '/foo'); + assert.equal(metrics.connectionState, undefined); + assert.equal(metrics.method, 'GET'); + assert.isNumber(metrics.inflightRequests); + + assert.isObject(req, 'req'); + assert.isObject(res, 'res'); + assert.isObject(route, 'route'); + })); + + SERVER.get('/foo', function (req, res, next) { + setTimeout(function () { + res.send(202, 'hello world'); + return next(); + }, 100); + }); + + CLIENT.get('/foo?a=1', function (err, _, res) { + assert.ifError(err); + assert.equal(res.statusCode, 202); + return done(); + }); + }); + + + it('should return \'RequestCloseError\' err', function (done) { + + // we test that the client times out and closes the request. server + // flushes request responsibly but connectionState should indicate it + // was closed by the server. + + SERVER.on('after', plugins.metrics({ + server: SERVER + }, function (err, metrics, req, res, route) { + assert.ok(err); + assert.equal(err.name, 'RequestCloseError'); + + assert.isObject(metrics, 'metrics'); + assert.equal(metrics.statusCode, 202); + assert.isAtLeast(metrics.latency, 200); + assert.equal(metrics.path, '/foo'); + assert.equal(metrics.method, 'GET'); + assert.equal(metrics.connectionState, 'close'); + assert.isNumber(metrics.inflightRequests); + return done(); + })); + + SERVER.get('/foo', function (req, res, next) { + setTimeout(function () { + res.send(202, 'hello world'); + return next(); + }, 250); + }); + + CLIENT.get('/foo?a=1', function (err, _, res) { + // request should timeout + assert.ok(err); + assert.equal(err.name, 'RequestTimeoutError'); + }); + }); + + + it('should return \'RequestAbortedError\' err', function (done) { + + // we test that the client times out and closes the request. server + // flushes request responsibly but connectionState should indicate it + // was closed by the server. + + SERVER.on('after', plugins.metrics({ + server: SERVER + }, function (err, metrics, req, res, route) { + assert.ok(err); + assert.equal(err.name, 'RequestAbortedError'); + + assert.isObject(metrics, 'metrics'); + assert.equal(metrics.statusCode, 202); + assert.isAtLeast(metrics.latency, 200); + assert.equal(metrics.path, '/foo'); + assert.equal(metrics.method, 'GET'); + assert.equal(metrics.connectionState, 'aborted'); + assert.isNumber(metrics.inflightRequests); + })); + + SERVER.get('/foo', function (req, res, next) { + // simulate request being aborted by TCP socket being closed + req.emit('aborted'); + res.send(202, 'hello world'); + return next(); + }); + + CLIENT.get('/foo?a=1', function (err, _, res) { + assert.ifError(err); + return done(); + }); + }); + + + it('should handle uncaught exceptions', function (done) { + + // we test that the client times out and closes the request. server + // flushes request responsibly but connectionState should indicate it + // was closed by the server. + + SERVER.on('after', plugins.metrics({ + server: SERVER + }, function (err, metrics, req, res, route) { + assert.ok(err); + assert.equal(err.name, 'Error'); + assert.equal(err.message, 'boom'); + assert.isObject(err.domain); + + assert.isObject(metrics, 'metrics'); + assert.equal(metrics.statusCode, 500); + assert.isNumber(metrics.latency, 200); + assert.equal(metrics.path, '/foo'); + assert.equal(metrics.method, 'GET'); + assert.equal(metrics.connectionState, undefined); + assert.isNumber(metrics.inflightRequests); + })); + + SERVER.get('/foo', function (req, res, next) { + throw new Error('boom'); + }); + + CLIENT.get('/foo?a=1', function (err, _, res) { + assert.ok(err); + return done(); + }); + }); +}); diff --git a/test/plugins.test.js b/test/plugins.test.js index 8039095e..1edc3261 100644 --- a/test/plugins.test.js +++ b/test/plugins.test.js @@ -117,10 +117,6 @@ describe('all other plugins', function () { assert.equal(res.statusCode, 200); var headers = res.headers; assert.ok(headers, 'headers ok'); - assert.ok(headers['access-control-allow-origin']); - assert.ok(headers['access-control-allow-headers']); - assert.ok(headers['access-control-expose-headers']); - assert.ok(headers['access-control-allow-methods']); assert.ok(headers.date); assert.ok(headers['request-id']); assert.ok(headers['response-time'] >= 0); diff --git a/test/reqIdHeaders.test.js b/test/reqIdHeaders.test.js new file mode 100644 index 00000000..4cc1669a --- /dev/null +++ b/test/reqIdHeaders.test.js @@ -0,0 +1,151 @@ +'use strict'; + +// external modules +var assert = require('chai').assert; +var restify = require('restify'); +var restifyClients = require('restify-clients'); +var validator = require('validator'); + +// internal files +var helper = require('./lib/helper'); +var plugins = require('../lib'); + + +describe('request id headers', function () { + + var SERVER; + var CLIENT; + var PORT; + + beforeEach(function (done) { + SERVER = restify.createServer({ + dtrace: helper.dtrace, + log: helper.getLog('server') + }); + + SERVER.pre(plugins.pre.reqIdHeaders({ + headers: ['x-req-id-a', 'x-req-id-b'] + })); + + SERVER.listen(0, '127.0.0.1', function () { + PORT = SERVER.address().port; + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + dtrace: helper.dtrace, + retry: false + }); + return done(); + }); + }); + + + afterEach(function (done) { + CLIENT.close(); + SERVER.close(function () { + CLIENT = null; + SERVER = null; + return done(); + }); + }); + + it('GH-1086: should reuse request id when available', + function (done) { + + SERVER.get('/1', function (req, res, next) { + // the 12345 value is set when the client is created. + assert.ok(req.headers.hasOwnProperty('x-req-id-a')); + assert.equal(req.getId(), req.headers['x-req-id-a']); + res.send('hello world'); + return next(); + }); + + // create new client since we new specific headers + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + headers:{ + 'x-req-id-a': 12345 + } + }); + + CLIENT.get('/1', function (err, req, res, data) { + assert.ifError(err); + assert.equal(data, 'hello world'); + return done(); + }); + }); + + + it('GH-1086: should use second request id when available', + function (done) { + + SERVER.get('/1', function (req, res, next) { + assert.ok(req.headers.hasOwnProperty('x-req-id-b')); + assert.equal(req.getId(), req.headers['x-req-id-b']); + res.send('hello world'); + return next(); + }); + + // create new client since we new specific headers + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + headers:{ + 'x-req-id-b': 678910 + } + }); + + CLIENT.get('/1', function (err, req, res, data) { + assert.ifError(err); + assert.equal(data, 'hello world'); + return done(); + }); + }); + + + it('GH-1086: should use default uuid request id if none provided', + function (done) { + + SERVER.get('/1', function (req, res, next) { + assert.ok(req.getId()); + assert.ok(validator.isUUID(req.getId())); + res.send('hello world'); + return next(); + }); + + // create new client since we new specific headers + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT + }); + + CLIENT.get('/1', function (err, req, res, data) { + assert.ifError(err); + assert.equal(data, 'hello world'); + return done(); + }); + }); + + + it('GH-1086: empty request id should be ignored', function (done) { + + SERVER.get('/1', function (req, res, next) { + assert.ok(req.headers.hasOwnProperty('x-req-id-b')); + assert.equal(req.getId(), req.headers['x-req-id-b']); + res.send('hello world'); + return next(); + }); + + // create new client since we new specific headers + CLIENT = restifyClients.createJsonClient({ + url: 'http://127.0.0.1:' + PORT, + headers:{ + 'x-req-id-a': '', + 'x-req-id-b': 12345 + } + }); + + CLIENT.get('/1', function (err, req, res, data) { + assert.ifError(err); + assert.equal(data, 'hello world'); + return done(); + }); + }); +});