refactor(testing): Re-enable support shim, and extend to test options object not…

… being modified v2 (#5836)

* Update dev dependency `hints` used in tests support shim

* `Model.init` is not shimmed by test shims

* Tests support shim checks for options object being modified

* Fix JSDoc comments in tests shim

* Increase tests timeout to 30secs

* Environment var `SHIM` to trigger tests support shim

changelog.md

@@ -50,6 +50,7 @@
 - [FIXED] Type validation now works with non-strings due to updated validator@5.0.0 [#5861](https://github.com/sequelize/sequelize/pull/5861)
 - [FIXED] Improved offset and limit support for SQL server 2008 [#5616](https://github.com/sequelize/sequelize/pull/5616)
 - [FIXED] options object cloned in all Sequelize methods (so not modified within Sequelize)
+- [ADDED] Test coverage for options object not being modified
 
 # 3.23.1
 - [FIXED] Postgres DECIMAL precision. (PostgreSQL) [#4893](https://github.com/sequelize/sequelize/issues/4893)

lib/model.js

@@ -571,7 +571,7 @@ class Model {
     });
   }
 
-  static init(attributes, options, modelManager) {
+  static init(attributes, options, modelManager) { // testhint options:none
 
     this.options = Utils._.extend({
       timestamps: true,

package.json

@@ -97,14 +97,14 @@
     "docs": "node docs/docs-generator.js",
     "jshint": "./node_modules/.bin/jshint lib test",
     "teaser": "echo ''; node -pe \"Array(20 + process.env.DIALECT.length + 3).join('#')\"; echo '# Running tests for '$DIALECT' #'; node -pe \"Array(20 + process.env.DIALECT.length + 3).join('#')\";echo '';",
-    "test-unit": "./node_modules/.bin/mocha --globals setImmediate,clearImmediate --ui tdd --check-leaks --colors -t 15000 --reporter spec 'test/unit/**/*.js'",
+    "test-unit": "./node_modules/.bin/mocha --globals setImmediate,clearImmediate --ui tdd --check-leaks --colors -t 30000 --reporter spec 'test/unit/**/*.js'",
     "test-unit-mysql": "DIALECT=mysql npm run test-unit",
     "test-unit-postgres": "DIALECT=postgres npm run test-unit",
     "test-unit-postgres-native": "DIALECT=postgres-native npm run test-unit",
     "test-unit-sqlite": "DIALECT=sqlite npm run test-unit",
     "test-unit-mssql": "DIALECT=mssql npm run test-unit",
     "test-unit-all": "npm run test-unit-mysql && npm run test-unit-postgres && npm run test-unit-postgres-native && npm run test-unit-mssql && npm run test-unit-sqlite",
-    "test-integration": "./node_modules/.bin/mocha --globals setImmediate,clearImmediate --ui tdd --check-leaks --colors -t 15000 --reporter spec --grep \"$GREP\" 'test/integration/**/*.test.js'",
+    "test-integration": "./node_modules/.bin/mocha --globals setImmediate,clearImmediate --ui tdd --check-leaks --colors -t 30000 --reporter spec --grep \"$GREP\" 'test/integration/**/*.test.js'",
     "test-integration-mysql": "DIALECT=mysql npm run test-integration",
     "test-integration-postgres": "DIALECT=postgres npm run test-integration",
     "test-integration-postgres-native": "DIALECT=postgres-native npm run test-integration",
@@ -120,7 +120,7 @@
     "test-mssql": "DIALECT=mssql npm test",
     "test-all": "npm run test-mysql && npm run test-sqlite && npm run test-postgres && npm run test-postgres-native && npm run test-mssql",
     "cover": "rm -rf coverage && npm run teaser && npm run cover-integration && npm run cover-unit && npm run merge-coverage",
-    "cover-integration": "COVERAGE=true ./node_modules/.bin/istanbul cover ./node_modules/.bin/_mocha --report lcovonly -- -t 30000 --ui tdd 'test/integration/**/*.test.js' && mv coverage/lcov.info coverage/integration.info",
+    "cover-integration": "COVERAGE=true ./node_modules/.bin/istanbul cover ./node_modules/.bin/_mocha --report lcovonly -- -t 60000 --ui tdd 'test/integration/**/*.test.js' && mv coverage/lcov.info coverage/integration.info",
     "cover-unit": "COVERAGE=true ./node_modules/.bin/istanbul cover ./node_modules/.bin/_mocha --report lcovonly -- -t 30000 --ui tdd 'test/unit/**/*.test.js'&& mv coverage/lcov.info coverage/unit.info",
     "merge-coverage": "./node_modules/.bin/lcov-result-merger 'coverage/*.info' 'coverage/lcov.info'",
     "coveralls": "npm run cover && cat ./coverage/lcov.info | ./node_modules/coveralls/bin/coveralls.js && rm -rf ./coverage",

test/integration/include/schema.test.js

@@ -15,7 +15,6 @@ var sortById = function(a, b) {
 
 describe(Support.getTestDialectTeaser('Includes with schemas'), function() {
   describe('findAll', function() {
-    this.timeout(30000);
     beforeEach(function() {
       var self = this;
       this.fixtureA = function() {

test/integration/model.test.js

@@ -2605,7 +2605,7 @@ describe(Support.getTestDialectTeaser('Model'), function() {
 
   if (dialect !== 'sqlite' && current.dialect.supports.transactions) {
     it('supports multiple async transactions', function() {
-      this.timeout(50000);
+      this.timeout(90000);
       var self = this;
       return Support.prepareTransactionTest(this.sequelize).bind({}).then(function(sequelize) {
         var User = sequelize.define('User', { username: Sequelize.STRING });

test/integration/sequelize.transaction.test.js

@@ -51,7 +51,6 @@ describe(Support.getTestDialectTeaser('Sequelize#transaction'), function() {
 
     if (Support.getTestDialect() !== 'sqlite') {
       it('works for long running transactions', function() {
-        this.timeout(10000);
         return Support.prepareTransactionTest(this.sequelize).bind(this).then(function(sequelize) {
           this.sequelize = sequelize;
 

test/support.js

@@ -29,7 +29,8 @@ Sequelize.Promise.onPossiblyUnhandledRejection(function(e, promise) {
 Sequelize.Promise.longStackTraces();
 
 // shim all Sequelize methods for testing for correct `options.logging` passing
-if (!process.env.COVERAGE && false) supportShim(Sequelize);
+// and no modification of `options` objects
+if (!process.env.COVERAGE && process.env.SHIM) supportShim(Sequelize);
 
 var Support = {
   Sequelize: Sequelize,

test/supportShim.js

@@ -2,28 +2,33 @@
 
 var QueryInterface = require(__dirname + '/../lib/query-interface')
   , hintsModule = require('hints')
-  , _ = require('lodash');
+  , _ = require('lodash')
+  , util = require('util');
 
-/*
+/**
  * Shims all Sequelize methods to test for logging passing.
- * @param {Object} Sequelize Sequelize constructor
+ * @param {Object} Sequelize - Sequelize constructor
  */
 module.exports = function(Sequelize) {
   // Shim all Sequelize methods
-  shimAll(Sequelize.prototype);
-  shimAll(Sequelize.Model);
-  shimAll(Sequelize.Model.prototype);
-  shimAll(QueryInterface.prototype);
+  shimAll(Sequelize.prototype, 'Sequelize#');
+  shimAll(Sequelize.Model, 'Model.');
+  shimAll(Sequelize.Model.prototype, 'Model#');
+  shimAll(QueryInterface.prototype, 'QueryInterface#');
+  shimAll(Sequelize.Association.prototype, 'Association#');
+  _.forIn(Sequelize.Association, function(Association, name) {
+    shimAll(Association.prototype, 'Association.' + name + '#');
+  });
 
-  // Shim Model.prototype to then shim getter/setter methods
+  // Shim Model static methods to then shim getter/setter methods
   ['hasOne', 'belongsTo', 'hasMany', 'belongsToMany'].forEach(function(type) {
-    shimMethod(Sequelize.Model.prototype, type, function(original) {
+    shimMethod(Sequelize.Model, type, function(original) {
       return function(targetModel, options) {
         var model = this,
           association = original.apply(this, arguments);
 
-        _.forIn(association.accessors, function(accessor) {
-          shim(model.prototype, accessor, model.prototype[accessor].length);
+        _.forIn(association.accessors, function(accessor, accessorName) {
+          shim(model.prototype, accessor, model.prototype[accessor].length, null, 'Model#' + accessorName);
         });
 
         return association;
@@ -33,18 +38,19 @@ module.exports = function(Sequelize) {
 
   // Support functions
 
-  /*
+  /**
    * Shims all shimmable methods on obj.
    * @param {Object} obj
+   * @param {string} objName - Name of object for error reporting
    */
-  function shimAll(obj) {
-    _.forIn(obj, function(method, name) {
+  function shimAll(obj, objName) {
+    forOwn(obj, function(method, name) {
       var result = examine(method, name);
-      if (result) shim(obj, name, result.index, result.conform);
+      if (result) shim(obj, name, result.index, result.conform, objName + name);
     });
   }
 
-  /*
+  /**
    * Given a function, checks whether is suitable for shimming to modify `options`
    * and returns information about how to do that
    *
@@ -67,15 +73,20 @@ module.exports = function(Sequelize) {
    *   `// testhint argsConform.start` & `// testhint argsConform.end`
    *     - this part of the function body deals with conforming flexible arguments
    *
-   * @param {Function} method Function to examine
-   * @param {String} name Attribute name of this method on parent object
+   * @param {Function} method - Function to examine
+   * @param {string} name - Attribute name of this method on parent object
    * @returns {Object}
    */
   function examine(method, name) {
+    // skip if not a function
     if (typeof method !== 'function') return;
 
+    // skip classes, constructors and private methods
+    if (name === 'constructor' || !name.match(/^[a-z]/)) return;
+
     // find test hints if provided
-    var obj = hintsModule.full(method.toString(), 'testhint', {function: true}),
+    var fnStr = getFunctionCode(method),
+      obj = hintsModule.full(fnStr, 'testhint'),
       hints = obj.hints,
       tree = obj.tree;
 
@@ -95,9 +106,6 @@ module.exports = function(Sequelize) {
       return result;
     }
 
-    // skip if function name does not start with lower case letter
-    if (!name.match(/^[a-z]/)) return;
-
     // find 'options' argument - if none, then skip
     var index = args.indexOf('options');
     if (index === -1) return;
@@ -106,53 +114,80 @@ module.exports = function(Sequelize) {
     return result;
   }
 
-  /*
+  /**
    * Shims a method to check for `options.logging`.
    * The method then:
    *   Injects `options.logging` if called from within the tests.
    *   Throws if called from within Sequelize and not passed correct `options.logging`
    *
-   * @param {Object} obj Object which is parent of this method
-   * @param {String} name Name of method on object to shim
-   * @param {Integer} index Index of argument which is `options` (1-based)
-   * @param {Function} conform Function to conform function arguments
+   * @param {Object} obj - Object which is parent of this method
+   * @param {string} name - Name of method on object to shim
+   * @param {number} index - Index of argument which is `options` (1-based)
+   * @param {Function} conform - Function to conform function arguments
+   * @param {string} debugName - Full name of method for error reporting
    */
-  function shim(obj, name, index, conform) {
+  function shim(obj, name, index, conform, debugName) {
     index--;
 
     shimMethod(obj, name, function(original) {
+      var sequelizeProto = (obj === Sequelize.prototype);
+
       return function() {
+        var sequelize = (sequelizeProto ? this : this.sequelize);
+        if (this instanceof Sequelize.Association) sequelize = this.target.sequelize;
+        if (!sequelize) throw new Error('Object does not have a `sequelize` attribute');
+
         var args = Sequelize.Utils.sliceArgs(arguments),
           fromTests = calledFromTests();
 
         if (conform) args = conform.apply(this, arguments);
 
+        var options = args[index];
+
         if (fromTests) {
-          args[index] = addLogger(args[index]);
+          args[index] = options = addLogger(options, sequelize);
         } else {
-          testLogger(args[index]);
+          testLogger(options, debugName);
         }
 
-        var result;
-        // NB next line written as a single statement to avoid bug with uncaught rejection
-        return (result = original.apply(this, args)) instanceof Sequelize.Promise ?
-          result.finally(finish) :
-          finish();
+        var originalOptions = cloneOptions(options);
 
-        function finish() {
-          if (fromTests) removeLogger(args[index]);
-          return result;
+        var result = original.apply(this, args);
+
+        if (result && typeof result.then === 'function') {
+          var err;
+          try {
+            checkOptions(options, originalOptions, debugName);
+          } catch (e) {
+            err = e;
+          }
+
+          if (!(result instanceof Sequelize.Promise)) {
+            result = Sequelize.Promise.resolve(result);
+            err = new Error('Promise returned by ' + debugName + ' is not instance of Sequelize.Promise');
+          }
+
+          result = result.finally(function() {
+            if (err) throw err;
+            checkOptions(options, originalOptions, debugName);
+            if (fromTests) removeLogger(options);
+          });
+        } else {
+          checkOptions(options, originalOptions, debugName);
+          if (fromTests) removeLogger(options);
         }
+
+        return result;
       };
     });
   }
 
-  /*
+  /**
    * Shims a method with given wrapper function
    *
-   * @param {Object} obj Object which is parent of this method
-   * @param {String} name Name of method on object to shim
-   * @param {Function} wrapper Wrapper function
+   * @param {Object} obj - Object which is parent of this method
+   * @param {string} name - Name of method on object to shim
+   * @param {Function} wrapper - Wrapper function
    */
   function shimMethod(obj, name, wrapper) {
     var original = obj[name];
@@ -167,24 +202,27 @@ module.exports = function(Sequelize) {
     }
   }
 
-  /*
+  /**
    * Adds `logging` function to `options`.
    * If existing `logging` attribute, shims it.
    *
    * @param {Object} options
-   * @returns {Object} Options with `logging` attribute added
+   * @returns {Object} - Options with `logging` attribute added
    */
-  function addLogger(options) {
+  function addLogger(options, sequelize) {
     if (!options) options = {};
 
     var hadLogging = options.hasOwnProperty('logging'),
       originalLogging = options.logging;
 
-    options.logging = function(msg) {
-      if (originalLogging) {
-        return originalLogging.apply(this, arguments);
-      } else {
-        logger(msg);
+    options.logging = function() {
+      var logger = originalLogging !== undefined ? originalLogging : sequelize.options.logging;
+      if (logger) {
+        if ((sequelize.options.benchmark || options.benchmark) && logger === console.log) {
+          return logger.call(this, arguments[0] + ' Elapsed time: ' + arguments[1] + 'ms');
+        } else {
+          return logger.apply(this, arguments);
+        }
       }
     };
 
@@ -194,37 +232,35 @@ module.exports = function(Sequelize) {
     return options;
   }
 
-  /*
+  /**
    * Revert `options.logging` to original value
    *
    * @param {Object} options
-   * @returns {Object} Options with `logging` attribute reverted to original value
+   * @returns {Object} - Options with `logging` attribute reverted to original value
    */
   function removeLogger(options) {
-    if (options.logging && options.logging.__testLoggingFn) {
-      if (options.logging.hasOwnProperty('__originalLogging')) {
-        options.logging = options.logging.__originalLogging;
-      } else {
-        delete options.logging;
-      }
+    if (options.logging.hasOwnProperty('__originalLogging')) {
+      options.logging = options.logging.__originalLogging;
+    } else {
+      delete options.logging;
     }
   }
 
-  /*
+  /**
    * Checks if `options.logging` is an injected logging function
    *
    * @param {Object} options
-   * @throws {Error} Throws if `options.logging` is not a shimmed logging function
+   * @throws {Error} - Throws if `options.logging` is not a shimmed logging function
    */
-  function testLogger(options) {
-    if (!options || !options.logging || !options.logging.__testLoggingFn) throw new Error('options.logging has been lost');
+  function testLogger(options, name) {
+    if (!options || !options.logging || !options.logging.__testLoggingFn) throw new Error('options.logging has been lost in method ' + name);
   }
 
-  /*
+  /**
    * Checks if this method called from the tests
    * (as opposed to being called within Sequelize codebase).
    *
-   * @returns {Boolean} true if this method called from within the tests
+   * @returns {boolean} - true if this method called from within the tests
    */
   var pathRegStr = _.escapeRegExp(__dirname + '/'),
     regExp = new RegExp('^\\s+at\\s+(' + pathRegStr + '|.+ \\(' + pathRegStr + ')');
@@ -232,41 +268,64 @@ module.exports = function(Sequelize) {
   function calledFromTests() {
     return !!((new Error()).stack.split(/[\r\n]+/)[3].match(regExp));
   }
-
-  /*
-   * Logging function
-   *
-   * @param {String} msg Logging message
-   */
-  function logger(msg) {
-    if (process.env.SEQ_LOG) console.log(msg);
-  }
 };
 
 // Helper functions for examining code for hints
 
-/*
+/**
+ * Loop through own properties of object (including non-enumerable properties)
+ * and call `fn` for each property with argments `(value, key, object)`.
+ * Getters are skipped.
+ * Like `_.forIn()` except also includes non-enumarable properties, and skips getters.
+ *
+ * @param {Object} obj - Object to iterate over
+ * @param {Function} fn - Function to call for each property
+ * @returns {Object} - `obj` input
+ */
+function forOwn(obj, fn) {
+  Object.getOwnPropertyNames(obj).forEach(function(key) {
+    if (Object.getOwnPropertyDescriptor(obj, key).hasOwnProperty('value')) fn(obj[key], key, obj);
+  });
+  return obj;
+}
+
+/**
+ * Get code of function
+ * Adds 'function ' to start of code where fn has been defined with object method shortcut,
+ * and alters illegal function names ('import', 'delete'), so code can be parsed by `acorn`.
+ *
+ * @param {Function} fn - Function
+ * @returns {string} - Code of function
+ */
+function getFunctionCode(fn) {
+  var code = fn.toString();
+  if (code.match(/^function[\s\*\(]/) || code.match(/^class[\s\{]/)) return code;
+  if (code.match(/^(import|delete)[\s\*\(]/)) code = '_' + code.substr(1);
+  return 'function ' + code;
+}
+
+/**
  * Returns arguments of a function as an array, from it's AST
  *
- * @tree {Object} tree Abstract syntax tree of function's code
- * @returns {Array} Array of names of `method`'s arguments
+ * @param {Object} tree - Abstract syntax tree of function's code
+ * @returns {Array} - Array of names of `method`'s arguments
  */
 function getFunctionArguments(tree) {
   return tree.body[0].params.map(function(param) {return param.name;});
 }
 
-/*
+/**
  * Extracts conform arguments section from function body and turns into function.
  * That function is called with the same signature as the original function,
  * conforms them into the standard order, and returns the arguments as an array.
  *
  * Returns undefined if no conform arguments hints.
  *
- * @param {Function} method Function to inspect
- * @param {Array} args Array of names of `method`'s arguments
- * @param {Object} hints Hints object containing code hints parsed from code
- * @tree {Object} tree Abstract syntax tree of function's code
- * @returns {Function} Function which will conform method's arguments and return as an array
+ * @param {Function} method - Function to inspect
+ * @param {Array} args - Array of names of `method`'s arguments
+ * @param {Object} hints - Hints object containing code hints parsed from code
+ * @param {Object} tree - Abstract syntax tree of function's code
+ * @returns {Function} - Function which will conform method's arguments and return as an array
  */
 function getArgumentsConformFn(method, args, hints, tree) {
   // check if argsConform hints present
@@ -277,8 +336,45 @@ function getArgumentsConformFn(method, args, hints, tree) {
 
   // extract
   var start = hints.start ? hints.start.end : tree.body[0].body.start + 1,
-    body = method.toString().slice(start, hints.end.start);
+    body = getFunctionCode(method).slice(start, hints.end.start);
 
   // create function that conforms arguments
   return new Function(args, body + ';return [' + args + '];'); // jshint ignore:line
 }
+
+/**
+ * Clone options object
+ * @param {Object} options - Options object
+ * @returns {Object} - Clone of options
+ */
+function cloneOptions(options) {
+  return _.cloneDeepWith(options, function(value) {
+    if (typeof value === 'object' && !_.isPlainObject(value)) return value;
+  });
+}
+
+/**
+ * Checks options object has not been altered and throw if altered
+ *
+ * @param {Object} options - Options object
+ * @param {Object} original - Original options object
+ * @throws {Error} - Throws if options and original are not identical
+ */
+function checkOptions(options, original, name) {
+  if (!optionsEqual(options, original)) throw new Error('options modified in ' + name + ', input: ' + util.inspect(original) + ' output: ' + util.inspect(options));
+}
+
+/**
+ * Compares two options objects and returns if they are deep equal to each other.
+ * Objects which are not plain objects (e.g. Models) are compared by reference.
+ * Everything else deep-compared by value.
+ *
+ * @param {Object} options - Options object
+ * @param {Object} original - Original options object
+ * @returns {boolean} - true if options and original are same, false if not
+ */
+function optionsEqual(options, original) {
+  return _.isEqualWith(options, original, function(value1, value2) {
+    if ((typeof value1 === 'object' && !_.isPlainObject(value1)) || (typeof value2 === 'object' && !_.isPlainObject(value2))) return value1 === value2;
+  });
+}