[SER-279] Error Improvements

.env.example

@@ -1,6 +1,7 @@
 ## Shared ##
 NODE_ENV=development
 LOG_LEVEL=info
+ALWAYS_INCLUDE_ERROR_STACKS=false
 
 ## Auth Microservice ##
 JWT_SECRET=0a6b944d-d2fb-46fc-a85e-0295c986cd9f

.env.test

@@ -1,5 +1,6 @@
 NODE_ENV=test
 LOG_LEVEL=debug
+ALWAYS_INCLUDE_ERROR_STACKS=false
 
 JWT_MODE=hmac
 JWT_SECRET=0a6b944d-d2fb-46fc-a85e-0295c986cd9f

CHANGELOG.md

@@ -1,11 +1,17 @@
 # Changelog
 
 ## [Unreleased]
+### Added
+- ENV `ALWAYS_INCLUDE_ERROR_STACKS` to include full error stack, including any causal errors.
+  * Use with caution in production, because the full stack could leak sensitive information.
+
 ### Fixed
 - `auth.controller.js:login()` no longer throws duplicate errors for incorrect username or password
 - Use error handling middlware `winstonInstance.info(err)`
   * Previously, `winstonInstance.errorLogger()` always threw a `TypeError`, meaning the underlying error didn't actually show in the logs
-
+- `class:APIError` supports full stack traces, including causal errors.
+- Update `npm:winston` to `^3.2.1` and `npm:winston-json-formatter` to `^0.10.0` for logging bug fixes and formatting features (see https://github.com/amida-tech/winston-json-formatter/pull/5).
+  * Logs "operational errors" at the `warn` level and "programmer errors" at the `error` level.
 
 ## [2.7.0] -- 2019-02-04
 ### Added

README.md

@@ -334,6 +334,12 @@ A description of what the variable is or does.
 
 - Valid values are [winston](https://github.com/winstonjs/winston) logging levels (`error`, `warn`, etc.).
 
+##### `ALWAYS_INCLUDE_ERROR_STACKS` [`false`]
+
+The `APIError` class acts like a call-stackless "operational error" (https://www.joyent.com/node-js/production/design/errors) when called without a causal error as the first argument.
+- When `false`, `APIError`s without a causal error will not have call stacks.
+- When `true`, all `APIError`s will have call stacks.
+
 ##### `JWT_SECRET` (Required)
 
 First, see description of `AUTH_SERVICE_JWT_MODE`. When `AUTH_SERVICE_JWT_MODE=hmac`, this is the shared secret between this service an all services using this service for authentication. Therefore, all other such service must set their `JWT_SECRET` to match this value.

package.json

@@ -63,8 +63,8 @@
     "sequelize": "^4.40.0",
     "swagger-stats": "^0.95.6",
     "uuid": "3.1.0",
-    "winston": "^3.0.0",
-    "winston-json-formatter": "^0.9.2"
+    "winston": "^3.2.1",
+    "winston-json-formatter": "^0.10.0"
   },
   "devDependencies": {
     "@babel/cli": "^7.1.5",

src/config/config.js

@@ -16,6 +16,8 @@ const envVarsSchema = Joi.object({
         .default('production'),
     LOG_LEVEL: Joi.string()
         .default('info'),
+    ALWAYS_INCLUDE_ERROR_STACKS: Joi.bool()
+        .default(false),
     AUTH_SERVICE_PORT: Joi.number()
         .default(4000),
     AUTH_SERVICE_PUBLIC_REGISTRATION: Joi.bool()
@@ -127,9 +129,10 @@ if (error) {
     throw new Error(`Config validation error: ${error.message}`);
 }
 
-module.exports = {
+const config = {
     env: envVars.NODE_ENV,
     logLevel: envVars.LOG_LEVEL,
+    alwaysIncludeErrorStacks: envVars.ALWAYS_INCLUDE_ERROR_STACKS,
     port: envVars.AUTH_SERVICE_PORT,
     publicRegistration: envVars.AUTH_SERVICE_PUBLIC_REGISTRATION,
     registrarScopes: envVars.AUTH_SERVICE_REGISTRAR_SCOPES,
@@ -169,3 +172,5 @@ module.exports = {
         scopes: ['admin'],
     },
 };
+
+module.exports = config;

src/config/express.js

@@ -68,38 +68,48 @@ app.use('/api', routes);
 app.use((err, req, res, next) => {
     if (err instanceof Sequelize.ValidationError) {
         const status = err.errors[0].type === 'unique violation' ? httpStatus.CONFLICT : httpStatus.BAD_REQUEST;
-        const unifiedErrors = JSON.stringify(err.errors);
-        const error = new APIError(unifiedErrors, 'GENERIC_ERROR', status, true);
+        // err.errors[0].message has the most useful information from Sequelize, so we want it to
+        // end up in the nested message of the APIError. However, it could have PHI or PII, so it
+        // must be within the causal error message and must not be passed directly into APIError's
+        // message argument.
+        // eslint-disable-next-line no-param-reassign
+        err.message = `${err.message}: ${err.errors[0].message}`;
+        const error = new APIError(err, 'Sequelize Validation Error', 'GENERIC_ERROR', status, { isOperational: true });
         return next(error);
     } else if (err instanceof expressValidation.ValidationError) {
         // validation error contains errors which is an array of error each containing message[]
         const unifiedErrorMessage = err.errors.map(error => error.messages.join('. ')).join(' and ');
-        const error = new APIError(unifiedErrorMessage, 'GENERIC_ERROR', err.status, true);
+        const error = new APIError(unifiedErrorMessage, 'GENERIC_ERROR', err.status);
         return next(error);
     }
     return next(err);
 });
 
 // catch 404 and forward to error handler
 app.use((req, res, next) => {
-    const err = new APIError('API not found', 'UNKNOWN_API', httpStatus.NOT_FOUND);
+    const err = new APIError('Not Found', 'NOT_FOUND', httpStatus.NOT_FOUND, { isPublic: true });
     return next(err);
 });
 
 // Log errors.
 if (config.env !== 'test') {
     app.use((err, req, res, next) => {
-        winstonInstance.warn(err);
+        if (err.isOperational) {
+            winstonInstance.warn(err);
+        } else {
+            winstonInstance.error(err);
+        }
+
         return next(err);
     });
 }
 
 // error handler, send stacktrace only during development
 app.use((err, req, res, next) => // eslint-disable-line no-unused-vars
     res.status(err.status || 500).json({
-        code: err.isPublic ? err.message.code : 'UNKNOWN_ERROR',
+        code: err.isPublic ? err.code : 'UNKNOWN_ERROR',
         status: 'ERROR',
-        message: err.isPublic ? err.message.message : httpStatus[err.status],
+        message: err.isPublic ? err.message : httpStatus[err.status],
         stack: config.env === 'development' ? err.stack : {},
     })
 );

src/config/passport.js

@@ -47,7 +47,7 @@ module.exports = (passport) => {
             } })
             .spread((user) => {
                 if (user !== null) return done(null, user);
-                const err = new APIError('New facebook user not created', 'FACEBOOK_CREATION_ERROR', httpStatus.INTERNAL_SERVER_ERROR, true);
+                const err = new APIError('New facebook user not created', 'FACEBOOK_CREATION_ERROR', httpStatus.INTERNAL_SERVER_ERROR);
                 return done(err);
             });
         });

src/controllers/auth.controller.js

@@ -28,7 +28,7 @@ function login(req, res, next) {
         const validUserAndPassword = !_.isNull(user) && user.testPassword(params.password);
 
         if (!validUserAndPassword) {
-            const err = new APIError('Incorrect username or password', 'INCORRECT_USERNAME_OR_PASSWORD', httpStatus.NOT_FOUND, true);
+            const err = new APIError('Incorrect username or password', 'INCORRECT_USERNAME_OR_PASSWORD', httpStatus.UNAUTHORIZED);
             return next(err);
         }
 
@@ -82,7 +82,7 @@ function submitRefreshToken(req, res, next) {
         .findOne({ where: { token: params.refreshToken, userId: userResult.id } })
         .then((tokenResult) => {
             if (_.isNull(tokenResult)) {
-                const err = new APIError('Refresh token not found', 'MISSING_REFRESH_TOKEN', httpStatus.NOT_FOUND, true);
+                const err = new APIError('Refresh token not found', 'MISSING_REFRESH_TOKEN', httpStatus.NOT_FOUND);
                 return next(err);
             }
             const userInfo = {
@@ -122,7 +122,7 @@ function rejectRefreshToken(req, res, next) {
     return RefreshToken.findOne({ where: { token: params.refreshToken } })
     .then((tokenResult) => {
         if (_.isNull(tokenResult)) {
-            const err = new APIError('Refresh token not found', 'MISSING_REFRESH_TOKEN', httpStatus.NOT_FOUND, true);
+            const err = new APIError('Refresh token not found', 'MISSING_REFRESH_TOKEN', httpStatus.NOT_FOUND);
             return next(err);
         }
         // delete the refresh token
@@ -146,7 +146,7 @@ function updatePassword(req, res, next) {
     const params = _.pick(req.body, 'oldPassword', 'password');
 
     if (!user.testPassword(params.oldPassword)) {
-        const err = new APIError('Incorrect password', 'INCORRECT_PASSWORD', httpStatus.FORBIDDEN, true);
+        const err = new APIError('Incorrect password', 'INCORRECT_PASSWORD', httpStatus.FORBIDDEN);
         return next(err);
     }
 
@@ -171,7 +171,7 @@ function resetToken(req, res, next) {
     const email = _.get(req, 'body.email');
     const resetPageUrl = _.get(req, 'body.resetPageUrl');
     if (!email) {
-        const err = new APIError('Invalid email', 'INVALID_EMAIL', httpStatus.BAD_REQUEST, true);
+        const err = new APIError('Invalid email', 'INVALID_EMAIL', httpStatus.BAD_REQUEST);
         return next(err);
     }
     return User.resetPasswordToken(email, 3600)

src/controllers/user.controller.js

@@ -22,7 +22,7 @@ function load(req, res, next, id) {
     User.findById(id)
         .then((user) => {
             if (!user) {
-                const e = new APIError('User does not exist', 'UNKNOWN_USERNAME', httpStatus.NOT_FOUND, true);
+                const e = new APIError('User does not exist', 'UNKNOWN_USERNAME', httpStatus.NOT_FOUND);
                 return next(e);
             }
             req.user = user; // eslint-disable-line no-param-reassign
@@ -44,7 +44,7 @@ function get(req, res, next) {
     User.findById(req.params.userId)
         .then((user) => {
             if (req.user.username !== user.username && !req.user.isAdmin()) {
-                const e = new APIError('Cannot get another user\'s information', 'UNAUTHORIZED_REQUEST', httpStatus.FORBIDDEN, true);
+                const e = new APIError('Cannot get another user\'s information', 'UNAUTHORIZED_REQUEST', httpStatus.FORBIDDEN);
                 return next(e);
             }
             return res.json(user.getBasicUserInfo());
@@ -70,7 +70,7 @@ function getByEmail(req, res, next) {
                 return next(e);
             }
             if (req.user.username !== user.username && !req.user.isAdmin()) {
-                const e = new APIError('Cannot get another user\'s information', 'UNAUTHORIZED_REQUEST', httpStatus.FORBIDDEN, true);
+                const e = new APIError('Cannot get another user\'s information', 'UNAUTHORIZED_REQUEST', httpStatus.FORBIDDEN);
                 return next(e);
             }
             return res.json(user.getBasicUserInfo());
@@ -104,7 +104,7 @@ function create(req, res, next) {
             // we are not admin but are registrar
             // if trying to create new registrar or admin, return forbidden
             if (potentialScopes.some(scope => ['admin', ...config.registrarScopes].includes(scope))) {
-                const e = new APIError('Registrar not allowed to create new admin or registrar users', 'CANNOT_CREATE_ADMIN', httpStatus.FORBIDDEN, true);
+                const e = new APIError('Registrar not allowed to create new admin or registrar users', 'CANNOT_CREATE_ADMIN', httpStatus.FORBIDDEN);
                 return next(e);
             }
             // else go ahead
@@ -123,7 +123,7 @@ function update(req, res, next) {
     User.findById(req.params.userId)
         .then((user) => {
             if (req.user.username !== user.username && !req.user.isAdmin()) {
-                const e = new APIError('User not allowed to update email', 'CANNOT_UPDATE_EMAIL', httpStatus.FORBIDDEN, true);
+                const e = new APIError('User not allowed to update email', 'CANNOT_UPDATE_EMAIL', httpStatus.FORBIDDEN);
                 return next(e);
             }
             return user.update({ email: req.body.email });

src/helpers/APIError.js

@@ -1,35 +1,115 @@
-import httpStatus from 'http-status';
+import { initLogLevelGte } from 'winston-json-formatter';
+import config from '../config/config';
+
+// Read https://www.joyent.com/node-js/production/design/errors to understand the difference between
+// "programmer errors" (i.e. bugs) and "operational errors" (i.e. not actual bugs).
+// The APIError class assumes that if it was instantiated without a causal error, then it is being
+// used to define an "operational error", and there is no actual "programmer error"/bug.
+
+const alwaysIncludeErrorStacks = config.alwaysIncludeErrorStacks;
+
+// Errors thrown by 3rd party libraries might log data that we pass into them, such as PHI or PII.
+// And, devs might pass those errors as the causalError arg into APIError. So, to prevent accidental
+// logging of PHI/PII, only include and thus log causal errors if your config.logLevel is >= debug,
+// i.e. silly or debug.
+const includeCausalError = initLogLevelGte(config.logLevel)('debug');
 
 /**
  * @extends Error
  */
-class ExtendableError extends Error {
-    constructor(message, code, status, isPublic) {
-        super(message);
-        this.name = this.constructor.name;
-        this.message = { status: 'ERROR', message, code };
+class APIError extends Error {
+    /* eslint-disable max-len */
+    /**
+     * Create an APIError.
+     * @param {Error | string} arg1 - Either JS Error (the causal error) (optional), or error message (required).
+     * @param {string} arg2 - Either error message (required) or error code (required).
+     * @param {string | Number} arg3 - Either error code (required) or HTTP status (required)
+     * @param {Number | Object} arg4 - Either HTTP status (required) or options object (optional)
+     * @param {Object} arg5 - Options object (optional)
+     * @returns APIError
+     * @example new APIError('Create user failed. Please provide a username.', 'CREATE_USER_FAILED', 400, { includeStack: true })
+     * @example if (err) { throw new APIError(err, 'Create user failed. User already exists.', 'CREATE_USER_FAILED', 409, { isPublic: false }) }
+     */
+    /* eslint-enable max-len */
+    constructor(arg1, arg2, arg3, arg4, arg5) {
+        if (!(typeof arg1 === 'string' || arg1 instanceof String || arg1 instanceof Error)) {
+            // eslint-disable-next-line max-len
+            throw new Error('Attempting to run APIError constructor failed: The first arg to the constructor must be a string or object that is instanceof Error.');
+        }
+
+        // eslint-disable-next-line one-var,one-var-declaration-per-line
+        let causalError, message, code, status, options;
+
+        if (typeof arg1 === 'string' || arg1 instanceof String) {
+            causalError = undefined;
+            message = arg1;
+            code = arg2;
+            status = arg3;
+            options = arg4;
+        } else {
+            causalError = arg1;
+            message = arg2;
+            code = arg3;
+            status = arg4;
+            options = arg5;
+        }
+
+        // Default to empty object to prevent "Cannot read property 'X' of undefined" errors.
+        if (!options) {
+            options = {};
+        }
+
+        // If there is no causal error, assume this is an "operational error" (see comment above).
+        // (Define isOperational here because it must be used before the constructor, and therefore
+        // before this.isOperational is available for use.)
+        let isOperational = !causalError;
+
+        // `options.isOperational` can override the default isOperational behavior.
+        if (options.isOperational !== undefined) {
+            isOperational = options.isOperational;
+        }
+
+        // eslint-disable-next-line no-underscore-dangle
+        const _includeCausalError = includeCausalError || options.includeCausalError;
+
+        // eslint-disable-next-line no-underscore-dangle
+        let _message;
+        if (_includeCausalError && causalError && causalError.message) {
+            _message = `${message}: ${causalError.message}`;
+        } else {
+            _message = message;
+        }
+
+        super(_message);
+
+        this.message = _message;
         this.code = code;
         this.status = status;
-        this.isPublic = isPublic;
-        this.isOperational = true; // This is required since bluebird 4 doesn't append it anymore.
-        Error.captureStackTrace(this, this.constructor.name);
-    }
-}
+        this.options = options;
+        this.isOperational = isOperational;
 
-/**
- * Class representing an API error.
- * @extends ExtendableError
- */
-class APIError extends ExtendableError {
+        // When this.isPublic is truthy, the server's response body will include the error "code"
+        // and "message".
+        // We want isPublic to default to true. The reason is that most of the time we do want the
+        // code and message to be returned to the client rather than hidden, and we don't want to
+        // have to specify isPublic every time we create a new error. In fact, the primary purpose
+        // of the "code" is to support the front end's needs.
+        this.isPublic = (options.isPublic === undefined ? true : options.isPublic);
 
-    /**
-     * Creates an API error.
-     * @param {string} message - Error message.
-     * @param {number} status - HTTP status code of error.
-     * @param {boolean} isPublic - Whether the message should be visible to user or not.
-     */
-    constructor(message, code, status = httpStatus.INTERNAL_SERVER_ERROR, isPublic = false) {
-        super(message, code, status, isPublic);
+        // See comments at top of file about logging of causal errors.
+        if (_includeCausalError) {
+            this.cause = causalError;
+        }
+
+        // This class extends Error, so this.stack gets automatically generated; however we don't
+        // always want a stack, so we have to do something with it.
+        // We don't want a stack trace when there is an operational error because we don't want to
+        // mislead future developer maintainers into thinking there's a bug when there isn't.
+        // We only want this.stack when this class is being used for a "programmer error" OR if we
+        // override this behavior and always have stacks.
+        if (!(alwaysIncludeErrorStacks || options.includeStack || !this.isOperational)) {
+            delete this.stack;
+        }
     }
 }
 

src/helpers/jwt.js

@@ -19,7 +19,7 @@ module.exports = {
      */
     checkExternalProvider(req, res, next) {
         if (req.user.provider !== null) {
-            const err = new APIError('Cannot call this endpoint for user managed with external auth', 'EXTERNAL_AUTH_USED', httpStatus.FORBIDDEN, true);
+            const err = new APIError('Cannot call this endpoint for user managed with external auth', 'EXTERNAL_AUTH_USED', httpStatus.FORBIDDEN);
             return next(err);
         }
         return next();

src/helpers/owasp.js

@@ -13,7 +13,7 @@ module.exports = {
     checkPassword(req, res, next) {
         const result = owasp.test(req.body.password);
         if (!result.strong) {
-            const err = new APIError(result.errors.join('\r\n'), 'STRONG_PASS_REQUIRED', httpStatus.BAD_REQUEST, true);
+            const err = new APIError(result.errors.join('\r\n'), 'STRONG_PASS_REQUIRED', httpStatus.BAD_REQUEST);
             return next(err);
         }
         return next();