Feat(#488): Use getTime() to benchmark query execution

lib/dialects/mssql/query.js

@@ -3,8 +3,7 @@
 var Utils = require('../../utils')
 var Utils = require('../../utils')
   , AbstractQuery = require('../abstract/query')
   , AbstractQuery = require('../abstract/query')
   , sequelizeErrors = require('../../errors.js')
   , sequelizeErrors = require('../../errors.js')
-  , parserStore = require('../parserStore')('mssql')
-  , microtime = require('microtime');
+  , parserStore = require('../parserStore')('mssql');
 
 
 var Query = function(connection, sequelize, options) {
 var Query = function(connection, sequelize, options) {
   this.connection = connection;
   this.connection = connection;
@@ -37,7 +36,7 @@ Query.prototype.run = function(sql, parameters) {
   if (!benchmark) {
   if (!benchmark) {
     this.sequelize.log('Executing (' + (this.connection.uuid || 'default') + '): ' + this.sql, this.options);
     this.sequelize.log('Executing (' + (this.connection.uuid || 'default') + '): ' + this.sql, this.options);
   } else {
   } else {
-    var queryBegin = microtime.now();
+    var queryBegin = (new Date()).getTime();
   }
   }
 
 
   var promise = new Utils.Promise(function(resolve, reject) {
   var promise = new Utils.Promise(function(resolve, reject) {
@@ -73,7 +72,7 @@ Query.prototype.run = function(sql, parameters) {
         var request = new self.connection.lib.Request(self.sql, function(err) {
         var request = new self.connection.lib.Request(self.sql, function(err) {
 
 
           if (benchmark) {
           if (benchmark) {
-            self.sequelize.log('Executed (' + (self.connection.uuid || 'default') + '): ' + self.sql + ' in ' + (microtime.now() - queryBegin) + 'μs', self.options);
+            self.sequelize.log('Executed (' + (self.connection.uuid || 'default') + '): ' + self.sql + ' in ' + ((new Date()).getTime() - queryBegin) + 'ms', self.options);
           }
           }
 
 
           if (err) {
           if (err) {

lib/dialects/mysql/query.js

@@ -3,8 +3,7 @@
 var Utils = require('../../utils')
 var Utils = require('../../utils')
   , AbstractQuery = require('../abstract/query')
   , AbstractQuery = require('../abstract/query')
   , uuid = require('node-uuid')
   , uuid = require('node-uuid')
-  , sequelizeErrors = require('../../errors.js')
-  , microtime = require('microtime');
+  , sequelizeErrors = require('../../errors.js');
 
 
 var Query = function(connection, sequelize, options) {
 var Query = function(connection, sequelize, options) {
   this.connection = connection;
   this.connection = connection;
@@ -33,14 +32,14 @@ Query.prototype.run = function(sql, parameters) {
   if (!benchmark) {
   if (!benchmark) {
     this.sequelize.log('Executing (' + (this.connection.uuid || 'default') + '): ' + this.sql, this.options);
     this.sequelize.log('Executing (' + (this.connection.uuid || 'default') + '): ' + this.sql, this.options);
   } else {
   } else {
-    var queryBegin = microtime.now();
+    var queryBegin = (new Date()).getTime();
   }
   }
 
 
   var promise = new Utils.Promise(function(resolve, reject) {
   var promise = new Utils.Promise(function(resolve, reject) {
     self.connection.query(self.sql, function(err, results) {
     self.connection.query(self.sql, function(err, results) {
 
 
       if (benchmark) {
       if (benchmark) {
-        self.sequelize.log('Executed (' + (self.connection.uuid || 'default') + '): ' + self.sql + ' in ' + (microtime.now() - queryBegin) + 'μs', self.options);
+        self.sequelize.log('Executed (' + (self.connection.uuid || 'default') + '): ' + self.sql + ' in ' + ((new Date()).getTime() - queryBegin) + 'ms', self.options);
       }
       }
 
 
       if (err) {
       if (err) {

lib/dialects/postgres/query.js

@@ -5,8 +5,7 @@ var Utils = require('../../utils')
   , QueryTypes = require('../../query-types')
   , QueryTypes = require('../../query-types')
   , Promise = require('../../promise')
   , Promise = require('../../promise')
   , sequelizeErrors = require('../../errors.js')
   , sequelizeErrors = require('../../errors.js')
-  , _ = require('lodash')
-  , microtime = require('microtime');
+  , _ = require('lodash');
 
 
 var Query = function(client, sequelize, options) {
 var Query = function(client, sequelize, options) {
   this.client = client;
   this.client = client;
@@ -69,7 +68,7 @@ Query.prototype.run = function(sql, parameters) {
   if (!benchmark) {
   if (!benchmark) {
     this.sequelize.log('Executing (' + (this.client.uuid || 'default') + '): ' + this.sql, this.options);
     this.sequelize.log('Executing (' + (this.client.uuid || 'default') + '): ' + this.sql, this.options);
   } else {
   } else {
-    var queryBegin = microtime.now();
+    var queryBegin = (new Date()).getTime();
   }
   }
 
 
   var promise = new Promise(function(resolve, reject) {
   var promise = new Promise(function(resolve, reject) {
@@ -92,7 +91,7 @@ Query.prototype.run = function(sql, parameters) {
     query.on('end', function(result) {
     query.on('end', function(result) {
 
 
       if (benchmark) {
       if (benchmark) {
-        self.sequelize.log('Executed (' + (self.client.uuid || 'default') + '): ' + self.sql + ' in ' + (microtime.now() - queryBegin) + 'μs', self.options);
+        self.sequelize.log('Executed (' + (self.client.uuid || 'default') + '): ' + self.sql + ' in ' + ((new Date()).getTime() - queryBegin) + 'ms', self.options);
       }
       }
 
 
       if (receivedError) {
       if (receivedError) {

lib/dialects/sqlite/query.js

@@ -6,8 +6,7 @@ var Utils = require('../../utils')
   , AbstractQuery = require('../abstract/query')
   , AbstractQuery = require('../abstract/query')
   , QueryTypes = require('../../query-types')
   , QueryTypes = require('../../query-types')
   , sequelizeErrors = require('../../errors.js')
   , sequelizeErrors = require('../../errors.js')
-  , parserStore = require('../parserStore')('sqlite')
-  , microtime = require('microtime');
+  , parserStore = require('../parserStore')('sqlite');
 
 
 var Query = function(database, sequelize, options) {
 var Query = function(database, sequelize, options) {
   this.database = database;
   this.database = database;
@@ -91,7 +90,7 @@ Query.prototype.run = function(sql, parameters) {
   if (!benchmark) {
   if (!benchmark) {
     this.sequelize.log('Executing (' + (this.database.uuid || 'default') + '): ' + this.sql, this.options);
     this.sequelize.log('Executing (' + (this.database.uuid || 'default') + '): ' + this.sql, this.options);
   } else {
   } else {
-    var queryBegin = microtime.now();
+    var queryBegin = (new Date()).getTime();
   }
   }
 
 
   promise = new Promise(function(resolve) {
   promise = new Promise(function(resolve) {
@@ -105,7 +104,7 @@ Query.prototype.run = function(sql, parameters) {
             var afterExecute = function(err, results) {
             var afterExecute = function(err, results) {
 
 
               if (benchmark) {
               if (benchmark) {
-                self.sequelize.log('Executed (' + (self.database.uuid || 'default') + '): ' + self.sql + ' in ' + (microtime.now() - queryBegin) + 'μs', self.options);
+                self.sequelize.log('Executed (' + (self.database.uuid || 'default') + '): ' + self.sql + ' in ' + ((new Date()).getTime() - queryBegin) + 'ms', self.options);
               }
               }
 
 
               if (err) {
               if (err) {

lib/model.js

@@ -1006,7 +1006,7 @@ Model.prototype.sync = function(options) {
  * @param {Object}   [options]
  * @param {Object}   [options]
  * @param {Boolean}  [options.cascade=false]   Also drop all objects depending on this table, such as views. Only works in postgres
  * @param {Boolean}  [options.cascade=false]   Also drop all objects depending on this table, such as views. Only works in postgres
  * @param {Function} [options.logging=false]   A function that gets executed while running the query to log the sql.
  * @param {Function} [options.logging=false]   A function that gets executed while running the query to log the sql.
- * @param {Boolean}  [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}  [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  * @return {Promise}
  * @return {Promise}
  */
  */
 Model.prototype.drop = function(options) {
 Model.prototype.drop = function(options) {
@@ -1025,7 +1025,7 @@ Model.prototype.dropSchema = function(schema) {
  * @param {Object}   [options]
  * @param {Object}   [options]
  * @param {String}   [options.schemaDelimiter='.'] The character(s) that separates the schema name from the table name
  * @param {String}   [options.schemaDelimiter='.'] The character(s) that separates the schema name from the table name
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
- * @param {Boolean}  [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}  [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  * @return {this}
  * @return {this}
  */
  */
 Model.prototype.schema = function(schema, options) { // testhint options:none
 Model.prototype.schema = function(schema, options) { // testhint options:none
@@ -1059,7 +1059,7 @@ Model.prototype.schema = function(schema, options) { // testhint options:none
  *
  *
  * @param {Object}   [options] The hash of options from any query. You can use one model to access tables with matching schemas by overriding `getTableName` and using custom key/values to alter the name of the table. (eg. subscribers_1, subscribers_2)
  * @param {Object}   [options] The hash of options from any query. You can use one model to access tables with matching schemas by overriding `getTableName` and using custom key/values to alter the name of the table. (eg. subscribers_1, subscribers_2)
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
- * @param {Boolean}  [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}  [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  * @return {String|Object}
  * @return {String|Object}
  */
  */
 Model.prototype.getTableName = function(options) { // testhint options:none
 Model.prototype.getTableName = function(options) { // testhint options:none
@@ -1307,7 +1307,7 @@ Model.prototype.all = function(options) {
  * @param  {Function}                  [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param  {Function}                  [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param  {Object}                    [options.having]
  * @param  {Object}                    [options.having]
  * @param  {String}                    [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param  {String}                    [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param  {Boolean}                   [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}                   [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @see    {Sequelize#query}
  * @see    {Sequelize#query}
  * @return {Promise<Array<Instance>>}
  * @return {Promise<Array<Instance>>}
@@ -1509,7 +1509,7 @@ Model.prototype.find = Model.prototype.findOne;
  * @param {Boolean}         [options.distinct] Applies DISTINCT to the field being aggregated over
  * @param {Boolean}         [options.distinct] Applies DISTINCT to the field being aggregated over
  * @param {Transaction}     [options.transaction] Transaction to run query under
  * @param {Transaction}     [options.transaction] Transaction to run query under
  * @param {Boolean}         [options.plain] When `true`, the first returned value of `aggregateFunction` is cast to `dataType` and returned. If additional attributes are specified, along with `group` clauses, set `plain` to `false` to return all values of all returned rows.  Defaults to `true`
  * @param {Boolean}         [options.plain] When `true`, the first returned value of `aggregateFunction` is cast to `dataType` and returned. If additional attributes are specified, along with `group` clauses, set `plain` to `false` to return all values of all returned rows.  Defaults to `true`
- * @param {Boolean}         [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}         [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise<options.dataType|object>}                Returns the aggregate result cast to `options.dataType`, unless `options.plain` is false, in which case the complete data result is returned.
  * @return {Promise<options.dataType|object>}                Returns the aggregate result cast to `options.dataType`, unless `options.plain` is false, in which case the complete data result is returned.
  */
  */
@@ -1563,7 +1563,7 @@ Model.prototype.aggregate = function(attribute, aggregateFunction, options) {
  * @param {Transaction}   [options.transaction] Transaction to run query under
  * @param {Transaction}   [options.transaction] Transaction to run query under
  * @param {Function}      [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {Function}      [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {String}        [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param {String}        [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param {Boolean}       [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}       [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise<Integer>}
  * @return {Promise<Integer>}
  */
  */
@@ -1799,7 +1799,7 @@ Model.prototype.bulkBuild = function(valueSets, options) { // testhint options:n
  * @param {Transaction}   [options.transaction] Transaction to run query under
  * @param {Transaction}   [options.transaction] Transaction to run query under
  * @param {Function}      [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {Function}      [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {String}        [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param {String}        [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param {Boolean}       [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}       [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise<Instance>}
  * @return {Promise<Instance>}
  */
  */
@@ -1824,7 +1824,7 @@ Model.prototype.create = function(values, options) {
  * @param {Object}   [options.defaults] Default values to use if building a new instance
  * @param {Object}   [options.defaults] Default values to use if building a new instance
  * @param {Object}   [options.transaction] Transaction to run query under
  * @param {Object}   [options.transaction] Transaction to run query under
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param {Function} [options.logging=false] A function that gets executed while running the query to log the sql.
- * @param {Boolean}  [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}  [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise<Instance,initialized>}
  * @return {Promise<Instance,initialized>}
  * @alias findOrBuild
  * @alias findOrBuild
@@ -2001,7 +2001,7 @@ Model.prototype.findCreateFind = function(options) {
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  * @param  {Function}     [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param  {Function}     [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param  {String}       [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param  {String}       [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param  {Boolean}      [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}      [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @alias insertOrUpdate
  * @alias insertOrUpdate
  * @return {Promise<created>} Returns a boolean indicating whether the row was created or updated.
  * @return {Promise<created>} Returns a boolean indicating whether the row was created or updated.
@@ -2065,7 +2065,7 @@ Model.prototype.insertOrUpdate = Model.prototype.upsert;
  * @param  {Function}     [options.logging=false]          A function that gets executed while running the query to log the sql.
  * @param  {Function}     [options.logging=false]          A function that gets executed while running the query to log the sql.
  * @param  {Boolean}      [options.returning=false] Append RETURNING * to get back auto generated values (Postgres only)
  * @param  {Boolean}      [options.returning=false] Append RETURNING * to get back auto generated values (Postgres only)
  * @param  {String}       [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param  {String}       [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param  {Boolean}      [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}      [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise<Array<Instance>>}
  * @return {Promise<Array<Instance>>}
  */
  */
@@ -2216,7 +2216,7 @@ Model.prototype.bulkCreate = function(records, options) {
  * @param {Transaction}      [options.transaction] Transaction to run query under
  * @param {Transaction}      [options.transaction] Transaction to run query under
  * @param {Boolean|function} [options.logging] A function that logs sql queries, or false for no logging
  * @param {Boolean|function} [options.logging] A function that logs sql queries, or false for no logging
  * @param {String}           [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
  * @param {String}           [options.searchPath=DEFAULT] An optional parameter to specify the schema search_path (Postgres only)
- * @param {Boolean}          [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}          [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  *
  *
  * @return {Promise}
  * @return {Promise}
  *
  *
@@ -2241,7 +2241,7 @@ Model.prototype.truncate = function(options) {
  * @param  {Boolean}      [options.cascade=false]         Only used in conjunction with TRUNCATE. Truncates  all tables that have foreign-key references to the named table, or to any tables added to the group due to CASCADE.
  * @param  {Boolean}      [options.cascade=false]         Only used in conjunction with TRUNCATE. Truncates  all tables that have foreign-key references to the named table, or to any tables added to the group due to CASCADE.
  * @param  {Transaction}  [options.transaction]           Transaction to run query under
  * @param  {Transaction}  [options.transaction]           Transaction to run query under
  * @param  {Function}     [options.logging=false]         A function that gets executed while running the query to log the sql.
  * @param  {Function}     [options.logging=false]         A function that gets executed while running the query to log the sql.
- * @param  {Boolean}      [options.benchmark=false]       Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}      [options.benchmark=false]       Print query execution time in milliseconds when logging SQL.
  * @return {Promise<Integer>} The number of destroyed rows
  * @return {Promise<Integer>} The number of destroyed rows
  */
  */
 Model.prototype.destroy = function(options) {
 Model.prototype.destroy = function(options) {
@@ -2321,7 +2321,7 @@ Model.prototype.destroy = function(options) {
  * @param  {Boolean}      [options.individualHooks=false] If set to true, restore will find all records within the where parameter and will execute before / after bulkRestore hooks on each row
  * @param  {Boolean}      [options.individualHooks=false] If set to true, restore will find all records within the where parameter and will execute before / after bulkRestore hooks on each row
  * @param  {Number}       [options.limit]                 How many rows to undelete
  * @param  {Number}       [options.limit]                 How many rows to undelete
  * @param  {Function}     [options.logging=false]         A function that gets executed while running the query to log the sql.
  * @param  {Function}     [options.logging=false]         A function that gets executed while running the query to log the sql.
- * @param  {Boolean}      [options.benchmark=false]       Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}      [options.benchmark=false]       Print query execution time in milliseconds when logging SQL.
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  *
  *
  * @return {Promise<undefined>}
  * @return {Promise<undefined>}
@@ -2399,7 +2399,7 @@ Model.prototype.restore = function(options) {
  * @param  {Boolean}      [options.returning=false]       Return the affected rows (only for postgres)
  * @param  {Boolean}      [options.returning=false]       Return the affected rows (only for postgres)
  * @param  {Number}       [options.limit]                 How many rows to update (only for mysql and mariadb)
  * @param  {Number}       [options.limit]                 How many rows to update (only for mysql and mariadb)
  * @param  {Function}     [options.logging=false] A function that gets executed while running the query to log the sql.
  * @param  {Function}     [options.logging=false] A function that gets executed while running the query to log the sql.
- * @param  {Boolean}      [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param  {Boolean}      [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  * @param  {Transaction}  [options.transaction] Transaction to run query under
  *
  *
  * @return {Promise<Array<affectedCount,affectedRows>>}
  * @return {Promise<Array<affectedCount,affectedRows>>}

lib/sequelize.js

@@ -82,7 +82,7 @@ var url = require('url')
  * @param {String}   [options.transactionType='DEFERRED'] Set the default transaction type. See `Sequelize.Transaction.TYPES` for possible options. Sqlite only.
  * @param {String}   [options.transactionType='DEFERRED'] Set the default transaction type. See `Sequelize.Transaction.TYPES` for possible options. Sqlite only.
  * @param {String}   [options.isolationLevel='REPEATABLE_READ'] Set the default transaction isolation level. See `Sequelize.Transaction.ISOLATION_LEVELS` for possible options.
  * @param {String}   [options.isolationLevel='REPEATABLE_READ'] Set the default transaction isolation level. See `Sequelize.Transaction.ISOLATION_LEVELS` for possible options.
  * @param {Boolean}  [options.typeValidation=false] Run built in type validators on insert and update, e.g. validate that arguments passed to integer fields are integer-like.
  * @param {Boolean}  [options.typeValidation=false] Run built in type validators on insert and update, e.g. validate that arguments passed to integer fields are integer-like.
- * @param {Boolean}  [options.benchmark=false] Print query execution time in microseconds when logging SQL.
+ * @param {Boolean}  [options.benchmark=false] Print query execution time in milliseconds when logging SQL.
 */
 */
 
 
 /**
 /**

package.json

@@ -39,7 +39,6 @@
     "inflection": "^1.6.0",
     "inflection": "^1.6.0",
     "lodash": "^3.9.3",
     "lodash": "^3.9.3",
     "moment": "^2.11.0",
     "moment": "^2.11.0",
-    "microtime": "^2.0.0",
     "moment-timezone": "^0.5.0",
     "moment-timezone": "^0.5.0",
     "node-uuid": "~1.4.4",
     "node-uuid": "~1.4.4",
     "semver": "^5.0.1",
     "semver": "^5.0.1",