Adding the ability to log warnings if they are present in MySQL. (#5902)

* Adding the ability to log warnings if they are present in MySQL.

* Reset spy between tests...

* Pass options over. Make changes for jshint.

* Ack, forgot debug code.

* Finishing up, added tests. Refactored promise chain a little to support the new logging.

* Fixed automated test issue.

* Changes per pull request feedback.

* Adding the ability to log warnings if they are present in MySQL.

* Pass options over. Make changes for jshint.

* Rebased.

* Adding the ability to log warnings if they are present in MySQL.

* Pass options over. Make changes for jshint.

* Finishing up, added tests. Refactored promise chain a little to support the new logging.

* Fixed automated test issue.

* Changes per pull request feedback.

* Fixing per tests, conflicts, and formatting requests from pull request.

* Fixed issue (hopefully) with the bad regex in the test.

* Changed test to being MySQL only.

* Adding the ability to log warnings if they are present in MySQL.

* Reset spy between tests...

* Pass options over. Make changes for jshint.

* Ack, forgot debug code.

* Adding the ability to log warnings if they are present in MySQL.

* Adding the ability to log warnings if they are present in MySQL.

* Pass options over. Make changes for jshint.

* Pass options over. Make changes for jshint.

* Finishing up, added tests. Refactored promise chain a little to support the new logging.

* Finishing up, added tests. Refactored promise chain a little to support the new logging.

* Fixed automated test issue.

* Fixed automated test issue.

* Changes per pull request feedback.

* Changes per pull request feedback.

* Rebased.

* Fixing per tests, conflicts, and formatting requests from pull request.

* Fixed issue (hopefully) with the bad regex in the test.

* Changed test to being MySQL only.

changelog.md

@@ -5,11 +5,12 @@
 - [CHANGED] Throw `bluebird.AggregateError` instead of array from `bulkCreate` when validation fails
 - [FIXED] `$notIn: []` is now converted to `NOT IN (NULL)`  [#4859](https://github.com/sequelize/sequelize/issues/4859)
 - [FIXED] Add `raw` support to `instance.get()` [#5815](https://github.com/sequelize/sequelize/issues/5815)
-- [ADDED] Compare `deletedAt` against current timestamp when using paranoid [#5880](https://github.com/sequelize/sequelize/pull/5880)
+- [ADDED] Compare deletedAt against current timestamp when using paranoid [#5880](https://github.com/sequelize/sequelize/pull/5880)
 - [FIXED] `BIGINT` gets truncated [#5176](https://github.com/sequelize/sequelize/issues/5176)
 - [FIXED] Trigger afterCreate hook after all nested includes (for hasMany or belongsToMany associations) have been created to be consistent with hasOne.
 - [REMOVED] Support for `pool:false`
 - [REMOVED] Default transaction isolation level [#5094](https://github.com/sequelize/sequelize/issues/5094)
+- [ADDED] Add logging for mysql warnings, observant of the `showWarnings` option. [#5900](https://github.com/sequelize/sequelize/issues/5900)
 
 ## BC breaks:
 - `hookValidate` removed in favor of `validate` with `hooks: true | false`. `validate` returns a promise which is rejected if validation fails

lib/dialects/mysql/query.js

@@ -15,7 +15,8 @@ var Query = function(connection, sequelize, options) {
   this.options = Utils._.extend({
     logging: console.log,
     plain: false,
-    raw: false
+    raw: false,
+    showWarnings: false
   }, options || {});
 
   this.checkLoggingOption();
@@ -26,9 +27,10 @@ Query.formatBindParameters = AbstractQuery.formatBindParameters;
 Query.prototype.run = function(sql, parameters) {
   var self = this;
   this.sql = sql;
-
+  
   //do we need benchmark for this query execution
   var benchmark = this.sequelize.options.benchmark || this.options.benchmark;
+  var showWarnings = this.sequelize.options.showWarnings || this.options.showWarnings;
 
   if (benchmark) {
     var queryBegin = Date.now();
@@ -48,9 +50,20 @@ Query.prototype.run = function(sql, parameters) {
 
         reject(self.formatError(err));
       } else {
-        resolve(self.formatResults(results));
+        resolve(results);
       }
     }).setMaxListeners(100);
+  })
+  // Log warnings if we've got them.
+  .then(function(results){
+    if (showWarnings && results && results.warningCount > 0) {
+      return self.logWarnings(results);
+    }
+    return results;
+  })
+  // Return formatted results...
+  .then(function(results){
+    return self.formatResults(results);
   });
 
   return promise;
@@ -118,6 +131,29 @@ Query.prototype.formatResults = function(data) {
   return result;
 };
 
+Query.prototype.logWarnings = function (results) {
+  var self = this;
+  return this.run('SHOW WARNINGS').then(function(warningResults) {
+    var warningMessage = 'MySQL Warnings (' + (self.connection.uuid||'default') + '): ';
+    var messages = [];
+        
+    warningResults.forEach(function(_warningRow){
+      _warningRow.forEach(function(_warningResult) {
+        if (_warningResult.hasOwnProperty('Message')) {
+          messages.push(_warningResult.Message);
+        } else {
+          _warningResult.keys().forEach( function(_objectKey) {
+            messages.push([_objectKey, _warningResult[_objectKey]].join(': '));
+          });
+        }
+      });
+  });
+    
+    self.sequelize.log(warningMessage + messages.join('; '), self.options);
+    
+    return results;
+  });
+};
 
 Query.prototype.formatError = function (err) {
   var match;

test/integration/sequelize.test.js

@@ -252,6 +252,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), function() {
       return this.sequelize.query(this.insertQuery);
     });
 
+
     describe('logging', function () {
       it('executes a query with global benchmarking option and default logger', function() {
         var logger = sinon.spy(console, 'log');
@@ -265,6 +266,27 @@ describe(Support.getTestDialectTeaser('Sequelize'), function() {
           expect(logger.args[0][0]).to.be.match(/Executed \(default\): select 1; Elapsed time: \d+ms/);
         });
       });
+    
+      // We can only test MySQL warnings when using MySQL.
+      if (Support.dialectIsMySQL()) {
+        it('logs warnings when there are warnings', function() {
+          var logger = sinon.spy();
+          var sequelize = Support.createSequelizeInstance({
+            logging: logger,
+            benchmark: false,
+            showWarnings: true
+          });
+          var insertWarningQuery = 'INSERT INTO ' + qq(this.User.tableName) + ' (username, email_address, ' +
+            qq('createdAt') + ', ' + qq('updatedAt') +
+            ") VALUES ('john', 'john@gmail.com', 'HORSE', '2012-01-01 10:10:10')";
+
+          return sequelize.query(insertWarningQuery)
+          .then(function(results) {
+            expect(logger.callCount).to.equal(3);
+            expect(logger.args[2][0]).to.be.match(/^MySQL Warnings \(default\):.*?'createdAt'/m);
+          });
+        });
+      }
 
       it('executes a query with global benchmarking option and custom logger', function() {
         var logger = sinon.spy();
@@ -1197,6 +1219,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), function() {
 
       it('through Sequelize.sync()', function() {
         var self = this;
+        self.spy.reset();
         return this.sequelize.sync({ force: true, logging: false }).then(function() {
           expect(self.spy.notCalled).to.be.true;
         });
@@ -1204,6 +1227,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), function() {
 
       it('through DAOFactory.sync()', function() {
         var self = this;
+        self.spy.reset();
         return this.User.sync({ force: true, logging: false }).then(function() {
           expect(self.spy.notCalled).to.be.true;
         });