Merge pull request #1566 from sequelize/feature/logging

Refactored logging

changelog.md

@@ -11,6 +11,7 @@ Notice: All 1.7.x changes are present in 2.0.x aswell
 - [BUG] Fix a case where createdAt timestamp would not be set when updatedAt was disabled  Thanks to @fixe [#1543](https://github.com/sequelize/sequelize/pull/1543)
 - [BUG] Fix a case where createdAt timestamp would not be set when updatedAt was disabled  Thanks to @fixe [#1543](https://github.com/sequelize/sequelize/pull/1543)
 - [BUG] Fix a case where timestamps were not being write protected in `set` when underscored=true. janmeier [#1523](https://github.com/sequelize/sequelize/pull/1523)
 - [BUG] Fix a case where timestamps were not being write protected in `set` when underscored=true. janmeier [#1523](https://github.com/sequelize/sequelize/pull/1523)
 - [FEATURE/BUG] Prefetching/includes now fully support schemas
 - [FEATURE/BUG] Prefetching/includes now fully support schemas
+- [FEATURE] Centralize logging. [#1566](https://github.com/sequelize/sequelize/pull/1566)
 - [FEATURE/BUG] hstore values are now parsed on find/findAll. Thanks to @nunofgs [#1560](https://github.com/sequelize/sequelize/pull/1560)
 - [FEATURE/BUG] hstore values are now parsed on find/findAll. Thanks to @nunofgs [#1560](https://github.com/sequelize/sequelize/pull/1560)
 - [FEATURE] Read cli options from a file. Thanks to @codeinvain  [#1540](https://github.com/sequelize/sequelize/pull/1540)
 - [FEATURE] Read cli options from a file. Thanks to @codeinvain  [#1540](https://github.com/sequelize/sequelize/pull/1540)
 
 

lib/dialects/mariadb/query.js

@@ -20,7 +20,7 @@ module.exports = (function() {
     this.sql = sql
     this.sql = sql
 
 
     if (this.options.logging !== false) {
     if (this.options.logging !== false) {
-      this.options.logging('Executing (' + this.options.uuid + '): ' + this.sql)
+      this.sequelize.log('Executing (' + this.options.uuid + '): ' + this.sql)
     }
     }
 
 
     var resultSet = [],
     var resultSet = [],

lib/dialects/mysql/query.js

@@ -20,7 +20,7 @@ module.exports = (function() {
     this.sql = sql
     this.sql = sql
 
 
     if (this.options.logging !== false) {
     if (this.options.logging !== false) {
-      this.options.logging('Executing (' + this.options.uuid + '): ' + this.sql)
+      this.sequelize.log('Executing (' + this.options.uuid + '): ' + this.sql)
     }
     }
 
 
     this.client.query(this.sql, function(err, results, fields) {
     this.client.query(this.sql, function(err, results, fields) {

lib/dialects/postgres/query.js

@@ -28,7 +28,7 @@ module.exports = (function() {
       , rows          = []
       , rows          = []
 
 
     if (this.options.logging !== false) {
     if (this.options.logging !== false) {
-      this.options.logging('Executing (' + this.options.uuid + '): ' + this.sql)
+      this.sequelize.log('Executing (' + this.options.uuid + '): ' + this.sql)
     }
     }
 
 
     query.on('row', function(row) {
     query.on('row', function(row) {

lib/dialects/sqlite/query.js

@@ -27,7 +27,7 @@ module.exports = (function() {
     this.sql = sql
     this.sql = sql
 
 
     if (this.options.logging !== false) {
     if (this.options.logging !== false) {
-      this.options.logging('Executing (' + this.options.uuid + '): ' + this.sql)
+      this.sequelize.log('Executing (' + this.options.uuid + '): ' + this.sql)
     }
     }
 
 
     var columnTypes = {}
     var columnTypes = {}

lib/migrator.js

@@ -15,16 +15,6 @@ module.exports = (function() {
       logging:     console.log,
       logging:     console.log,
       filesFilter: /\.js$/
       filesFilter: /\.js$/
     }, options || {})
     }, options || {})
-
-    if (this.options.logging === true) {
-      console.log('DEPRECATION WARNING: The logging-option should be either a function or false. Default: console.log')
-      this.options.logging = console.log
-    }
-
-    if (this.options.logging == console.log) {
-      // using just console.log will break in node < 0.6
-      this.options.logging = function(s) { console.log(s) }
-    }
   }
   }
 
 
   Object.defineProperty(Migrator.prototype, "queryInterface", {
   Object.defineProperty(Migrator.prototype, "queryInterface", {
@@ -53,9 +43,9 @@ module.exports = (function() {
           }
           }
 
 
           if (migrations.length === 0) {
           if (migrations.length === 0) {
-            self.options.logging("There are no pending migrations.")
+            self.sequelize.log("There are no pending migrations.")
           } else {
           } else {
-            self.options.logging("Running migrations...")
+            self.sequelize.log("Running migrations...")
           }
           }
 
 
           migrations.forEach(function(migration) {
           migrations.forEach(function(migration) {
@@ -63,9 +53,7 @@ module.exports = (function() {
 
 
             chainer.add(migration, 'execute', [options], {
             chainer.add(migration, 'execute', [options], {
               before: function(migration) {
               before: function(migration) {
-                if (self.options.logging !== false) {
-                  self.options.logging(migration.filename)
-                }
+                self.sequelize.log(migration.filename)
                 migrationTime = process.hrtime()
                 migrationTime = process.hrtime()
               },
               },
 
 
@@ -73,9 +61,7 @@ module.exports = (function() {
                 migrationTime = process.hrtime(migrationTime)
                 migrationTime = process.hrtime(migrationTime)
                 migrationTime = Math.round( (migrationTime[0] * 1000) + (migrationTime[1] / 1000000));
                 migrationTime = Math.round( (migrationTime[0] * 1000) + (migrationTime[1] / 1000000));
 
 
-                if (self.options.logging !== false) {
-                  self.options.logging('Completed in ' + migrationTime + 'ms')
-                }
+                self.sequelize.log('Completed in ' + migrationTime + 'ms')
               },
               },
 
 
               success: function(migration, callback) {
               success: function(migration, callback) {
@@ -193,8 +179,10 @@ module.exports = (function() {
     return new Utils.CustomEventEmitter(function(emitter) {
     return new Utils.CustomEventEmitter(function(emitter) {
       var chainer = new Utils.QueryChainer()
       var chainer = new Utils.QueryChainer()
       var addMigration = function(filename) {
       var addMigration = function(filename) {
-        self.options.logging('Adding migration script at ' + filename)
         var migration = new Migration(self, filename)
         var migration = new Migration(self, filename)
+
+        self.sequelize.log('Adding migration script at ' + filename)
+
         chainer.add(migration, 'execute', [{ method: 'up' }], {
         chainer.add(migration, 'execute', [{ method: 'up' }], {
           before: function(migration) {
           before: function(migration) {
             if (options && Utils._.isFunction(options.before)) {
             if (options && Utils._.isFunction(options.before)) {

lib/sequelize.js

@@ -493,5 +493,18 @@ module.exports = (function() {
     return transaction
     return transaction
   }
   }
 
 
+  Sequelize.prototype.log = function() {
+    var args = [].slice.call(arguments)
+
+    if (this.options.logging) {
+      if (this.options.logging === true) {
+        console.log('DEPRECATION WARNING: The logging-option should be either a function or false. Default: console.log')
+        this.options.logging = console.log
+      }
+
+      this.options.logging.apply(null, args)
+    }
+  }
+
   return Sequelize
   return Sequelize
 })()
 })()

package.json

@@ -69,7 +69,8 @@
     "istanbul": "~0.1.45",
     "istanbul": "~0.1.45",
     "coveralls": "~2.7.1",
     "coveralls": "~2.7.1",
     "async": "~0.2.10",
     "async": "~0.2.10",
-    "coffee-script": "~1.7.1"
+    "coffee-script": "~1.7.1",
+    "sinon-chai": "~2.5.0"
   },
   },
   "keywords": [
   "keywords": [
     "mysql",
     "mysql",

test/sequelize/log.test.js

+var chai      = require('chai')
+  , sinonChai = require("sinon-chai")
+  , sinon     = require('sinon')
+  , fs        = require('fs')
+  , path      = require('path')
+  , expect    = chai.expect
+  , assert    = chai.assert
+  , Support   = require(__dirname + '/../support')
+
+chai.use(sinonChai)
+chai.config.includeStack = true
+
+describe(Support.getTestDialectTeaser("Sequelize"), function () {
+  describe('log', function() {
+    beforeEach(function() {
+      this.spy = sinon.spy(console, 'log')
+    })
+
+    afterEach(function() {
+      console.log.restore()
+    })
+
+    describe("with disabled logging", function() {
+      beforeEach(function() {
+        this.sequelize = new Support.Sequelize('db', 'user', 'pw', { logging: false })
+      })
+
+      it("does not call the log method of the logger", function() {
+        this.sequelize.log()
+        expect(this.spy.calledOnce).to.be.false
+      })
+    })
+
+    describe('with default logging options', function() {
+      beforeEach(function() {
+        this.sequelize = new Support.Sequelize('db', 'user', 'pw')
+      })
+
+      describe("called with no arguments", function() {
+        it('calls the log method', function() {
+          this.sequelize.log()
+          expect(this.spy.calledOnce).to.be.true
+        })
+
+        it('logs an empty string as info event', function() {
+          this.sequelize.log()
+          expect(this.spy.calledOnce).to.be.true
+        })
+      })
+
+      describe("called with one argument", function() {
+        it('logs the passed string as info event', function() {
+          this.sequelize.log('my message')
+          expect(this.spy.withArgs('my message').calledOnce).to.be.true
+        })
+      })
+
+      describe("called with more than two arguments", function() {
+        it("passes the arguments to the logger", function() {
+          this.sequelize.log('error', 'my message', 1, { a: 1 })
+          expect(this.spy.withArgs('error', 'my message', 1, { a: 1 }).calledOnce).to.be.true
+        })
+      })
+    })
+
+    describe("with a custom function for logging", function() {
+      beforeEach(function() {
+        this.spy       = sinon.spy()
+        this.sequelize = new Support.Sequelize('db', 'user', 'pw', { logging: this.spy })
+      })
+
+      it("calls the custom logger method", function() {
+        this.sequelize.log('om nom')
+        expect(this.spy.calledOnce).to.be.true
+      })
+    })
+  })
+})