不要怂,就是干,撸起袖子干!

Commit 7445423b by Simon Schick Committed by Sushant

chore(logger): streamline logging (#10630)

1 parent a9a32f23
...@@ -7,7 +7,7 @@ const sequelizeErrors = require('./errors'); ...@@ -7,7 +7,7 @@ const sequelizeErrors = require('./errors');
const Validator = require('./utils/validator-extras').validator; const Validator = require('./utils/validator-extras').validator;
const momentTz = require('moment-timezone'); const momentTz = require('moment-timezone');
const moment = require('moment'); const moment = require('moment');
const logger = require('./utils/logger'); const { logger } = require('./utils/logger');
const warnings = {}; const warnings = {};
const { classToInvokable } = require('./utils/classToInvokable'); const { classToInvokable } = require('./utils/classToInvokable');
......
...@@ -5,8 +5,8 @@ const _ = require('lodash'); ...@@ -5,8 +5,8 @@ const _ = require('lodash');
const semver = require('semver'); const semver = require('semver');
const Promise = require('../../promise'); const Promise = require('../../promise');
const errors = require('../../errors'); const errors = require('../../errors');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const debug = logger.getLogger().debugContext('pool'); const debug = logger.debugContext('pool');
/** /**
* Abstract Connection Manager * Abstract Connection Manager
......
...@@ -14,12 +14,11 @@ class AbstractQuery { ...@@ -14,12 +14,11 @@ class AbstractQuery {
this.model = options.model; this.model = options.model;
this.sequelize = sequelize; this.sequelize = sequelize;
this.options = Object.assign({ this.options = Object.assign({
// eslint-disable-next-line no-console
logging: console.log,
plain: false, plain: false,
raw: false raw: false,
// eslint-disable-next-line no-console
logging: console.log
}, options || {}); }, options || {});
this.checkLoggingOption(); this.checkLoggingOption();
} }
...@@ -321,6 +320,31 @@ class AbstractQuery { ...@@ -321,6 +320,31 @@ class AbstractQuery {
} }
/** /**
* @param {string} sql
* @param {Function} debugContext
* @protected
* @returns {Function} A function to call after the query was completed.
*/
_logQuery(sql, debugContext) {
const { connection, options } = this;
const benchmark = this.sequelize.options.benchmark || options.benchmark;
const startTime = Date.now();
const fmt = `(${connection.uuid || 'default'}): ${sql}`;
const msg = `Executing ${fmt}`;
debugContext(msg);
if (!benchmark) {
this.sequelize.log(`Executing ${fmt}`, options);
}
return () => {
const afterMsg = `Executed ${fmt}`;
debugContext(afterMsg);
if (benchmark) {
this.sequelize.log(afterMsg, Date.now() - startTime, options);
}
};
}
/**
* The function takes the result of the query execution and groups * The function takes the result of the query execution and groups
* the associated data by the callee. * the associated data by the callee.
* *
......
...@@ -3,10 +3,10 @@ ...@@ -3,10 +3,10 @@
const AbstractConnectionManager = require('../abstract/connection-manager'); const AbstractConnectionManager = require('../abstract/connection-manager');
const SequelizeErrors = require('../../errors'); const SequelizeErrors = require('../../errors');
const Promise = require('../../promise'); const Promise = require('../../promise');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const DataTypes = require('../../data-types').mariadb; const DataTypes = require('../../data-types').mariadb;
const momentTz = require('moment-timezone'); const momentTz = require('moment-timezone');
const debug = logger.getLogger().debugContext('connection:mariadb'); const debug = logger.debugContext('connection:mariadb');
const parserStore = require('../parserStore')('mariadb'); const parserStore = require('../parserStore')('mariadb');
/** /**
......
'use strict'; 'use strict';
const Utils = require('../../utils');
const logger = require('../../utils/logger');
const debug = logger.getLogger().debugContext('sql:mariadb');
const AbstractQuery = require('../abstract/query'); const AbstractQuery = require('../abstract/query');
const uuidv4 = require('uuid/v4'); const uuidv4 = require('uuid/v4');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const _ = require('lodash'); const _ = require('lodash');
const DataTypes = require('../../data-types'); const DataTypes = require('../../data-types');
const Promise = require('../../promise');
const { logger } = require('../../utils/logger');
const ER_DUP_ENTRY = 1062; const ER_DUP_ENTRY = 1062;
const ER_ROW_IS_REFERENCED = 1451; const ER_ROW_IS_REFERENCED = 1451;
const ER_NO_REFERENCED_ROW = 1452; const ER_NO_REFERENCED_ROW = 1452;
const debug = logger.debugContext('sql:mariadb');
class Query extends AbstractQuery { class Query extends AbstractQuery {
constructor(connection, sequelize, options) { constructor(connection, sequelize, options) {
super(connection, sequelize, Object.assign({ showWarnings: false }, options)); super(connection, sequelize, Object.assign({ showWarnings: false }, options));
...@@ -35,60 +36,34 @@ class Query extends AbstractQuery { ...@@ -35,60 +36,34 @@ class Query extends AbstractQuery {
run(sql, parameters) { run(sql, parameters) {
this.sql = sql; this.sql = sql;
const { connection } = this;
//do we need benchmark for this query execution
const benchmark = this.sequelize.options.benchmark
|| this.options.benchmark;
const showWarnings = this.sequelize.options.showWarnings const showWarnings = this.sequelize.options.showWarnings
|| this.options.showWarnings; || this.options.showWarnings;
let queryBegin; const complete = this._logQuery(sql, debug);
if (benchmark) {
queryBegin = Date.now();
} else {
this.sequelize.log(
`Executing (${this.connection.uuid || 'default'}): ${this.sql}`,
this.options);
}
debug(`executing(${this.connection.uuid || 'default'}) : ${this.sql}`);
if (parameters) { if (parameters) {
debug('parameters(%j)', parameters); debug('parameters(%j)', parameters);
} }
return new Utils.Promise((resolve, reject) => { return Promise.resolve(
this.connection.query(this.sql, parameters) connection.query(this.sql, parameters)
.then(results => { .then(results => {
debug( complete();
`executed(${this.connection.uuid || 'default'}) : ${this.sql}`);
if (benchmark) {
this.sequelize.log(
`Executed (${this.connection.uuid || 'default'}): ${this.sql}`,
Date.now() - queryBegin, this.options);
}
// Log warnings if we've got them. // Log warnings if we've got them.
if (showWarnings && results && results.warningStatus > 0) { if (showWarnings && results && results.warningStatus > 0) {
resolve(this.logWarnings(results)); return this.logWarnings(results);
return;
} }
resolve(results); return results;
}) })
.catch(err => { .catch(err => {
debug( complete();
`executed(${this.connection.uuid || 'default'}) : ${this.sql}`);
if (benchmark) {
this.sequelize.log(
`Executed (${this.connection.uuid || 'default'}): ${this.sql}`,
Date.now() - queryBegin, this.options);
}
err.sql = sql; err.sql = sql;
reject(this.formatError(err)); throw this.formatError(err);
}); })
}) )
// Log warnings if we've got them. // Log warnings if we've got them.
.then(results => { .then(results => {
if (showWarnings && results && results.warningStatus > 0) { if (showWarnings && results && results.warningStatus > 0) {
......
...@@ -3,12 +3,12 @@ ...@@ -3,12 +3,12 @@
const AbstractConnectionManager = require('../abstract/connection-manager'); const AbstractConnectionManager = require('../abstract/connection-manager');
const ResourceLock = require('./resource-lock'); const ResourceLock = require('./resource-lock');
const Promise = require('../../promise'); const Promise = require('../../promise');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const DataTypes = require('../../data-types').mssql; const DataTypes = require('../../data-types').mssql;
const parserStore = require('../parserStore')('mssql'); const parserStore = require('../parserStore')('mssql');
const debug = logger.getLogger().debugContext('connection:mssql'); const debug = logger.debugContext('connection:mssql');
const debugTedious = logger.getLogger().debugContext('connection:mssql:tedious'); const debugTedious = logger.debugContext('connection:mssql:tedious');
class ConnectionManager extends AbstractConnectionManager { class ConnectionManager extends AbstractConnectionManager {
constructor(dialect, sequelize) { constructor(dialect, sequelize) {
...@@ -91,7 +91,7 @@ class ConnectionManager extends AbstractConnectionManager { ...@@ -91,7 +91,7 @@ class ConnectionManager extends AbstractConnectionManager {
connection.once('connect', connectHandler); connection.once('connect', connectHandler);
if (config.dialectOptions && config.dialectOptions.debug) { if (config.dialectOptions && config.dialectOptions.debug) {
connection.on('debug', debugTedious); connection.on('debug', debugTedious.log.bind(debugTedious));
} }
}).tap(resourceLock => { }).tap(resourceLock => {
const connection = resourceLock.unwrap(); const connection = resourceLock.unwrap();
......
'use strict'; 'use strict';
const logger = require('../../utils/logger');
const Promise = require('../../promise'); const Promise = require('../../promise');
const AbstractQuery = require('../abstract/query'); const AbstractQuery = require('../abstract/query');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const parserStore = require('../parserStore')('mssql'); const parserStore = require('../parserStore')('mssql');
const _ = require('lodash'); const _ = require('lodash');
const debug = logger.getLogger().debugContext('sql:mssql'); const { logger } = require('../../utils/logger');
const debug = logger.debugContext('sql:mssql');
class Query extends AbstractQuery { class Query extends AbstractQuery {
getInsertIdField() { getInsertIdField() {
...@@ -33,63 +34,35 @@ class Query extends AbstractQuery { ...@@ -33,63 +34,35 @@ class Query extends AbstractQuery {
_run(connection, sql, parameters) { _run(connection, sql, parameters) {
this.sql = sql; this.sql = sql;
const { options } = this;
//do we need benchmark for this query execution const complete = this._logQuery(sql, debug);
const benchmark = this.sequelize.options.benchmark || this.options.benchmark;
let queryBegin;
if (benchmark) {
queryBegin = Date.now();
} else {
this.sequelize.log(`Executing (${this.connection.uuid || 'default'}): ${this.sql}`, this.options);
}
debug(`executing(${this.connection.uuid || 'default'}) : ${this.sql}`);
return new Promise((resolve, reject) => { return new Promise((resolve, reject) => {
const handleTransaction = err => {
if (err) {
reject(this.formatError(err));
return;
}
resolve(this.formatResults());
};
// TRANSACTION SUPPORT // TRANSACTION SUPPORT
if (this.sql.startsWith('BEGIN TRANSACTION')) { if (sql.startsWith('BEGIN TRANSACTION')) {
return connection.beginTransaction(err => { return connection.beginTransaction(handleTransaction, options.transaction.name, connection.lib.ISOLATION_LEVEL[options.isolationLevel]);
if (err) {
reject(this.formatError(err));
return;
}
resolve(this.formatResults());
}, this.options.transaction.name, connection.lib.ISOLATION_LEVEL[this.options.isolationLevel]);
} }
if (this.sql.startsWith('COMMIT TRANSACTION')) { if (sql.startsWith('COMMIT TRANSACTION')) {
return connection.commitTransaction(err => { return connection.commitTransaction(handleTransaction);
if (err) {
reject(this.formatError(err));
return;
}
resolve(this.formatResults());
});
} }
if (this.sql.startsWith('ROLLBACK TRANSACTION')) { if (sql.startsWith('ROLLBACK TRANSACTION')) {
return connection.rollbackTransaction(err => { return connection.rollbackTransaction(handleTransaction, options.transaction.name);
if (err) {
reject(this.formatError(err));
}
resolve(this.formatResults());
}, this.options.transaction.name);
} }
if (this.sql.startsWith('SAVE TRANSACTION')) { if (sql.startsWith('SAVE TRANSACTION')) {
return connection.saveTransaction(err => { return connection.saveTransaction(handleTransaction, options.transaction.name);
if (err) {
reject(this.formatError(err));
return;
}
resolve(this.formatResults());
}, this.options.transaction.name);
} }
const results = []; const results = [];
const request = new connection.lib.Request(this.sql, (err, rowCount) => { const request = new connection.lib.Request(sql, (err, rowCount) => {
debug(`executed(${this.connection.uuid || 'default'}) : ${this.sql}`);
if (benchmark) { complete();
this.sequelize.log(`Executed (${this.connection.uuid || 'default'}): ${this.sql}`, Date.now() - queryBegin, this.options);
}
if (err) { if (err) {
err.sql = sql; err.sql = sql;
......
...@@ -3,10 +3,10 @@ ...@@ -3,10 +3,10 @@
const AbstractConnectionManager = require('../abstract/connection-manager'); const AbstractConnectionManager = require('../abstract/connection-manager');
const SequelizeErrors = require('../../errors'); const SequelizeErrors = require('../../errors');
const Promise = require('../../promise'); const Promise = require('../../promise');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const DataTypes = require('../../data-types').mysql; const DataTypes = require('../../data-types').mysql;
const momentTz = require('moment-timezone'); const momentTz = require('moment-timezone');
const debug = logger.getLogger().debugContext('connection:mysql'); const debug = logger.debugContext('connection:mysql');
const parserStore = require('../parserStore')('mysql'); const parserStore = require('../parserStore')('mysql');
/** /**
......
'use strict'; 'use strict';
const Utils = require('../../utils'); const Utils = require('../../utils');
const logger = require('../../utils/logger');
const debug = logger.getLogger().debugContext('sql:mysql');
const AbstractQuery = require('../abstract/query'); const AbstractQuery = require('../abstract/query');
const uuidv4 = require('uuid/v4'); const uuidv4 = require('uuid/v4');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const _ = require('lodash'); const _ = require('lodash');
const { logger } = require('../../utils/logger');
const debug = logger.debugContext('sql:mysql');
class Query extends AbstractQuery { class Query extends AbstractQuery {
constructor(connection, sequelize, options) { constructor(connection, sequelize, options) {
...@@ -29,27 +31,16 @@ class Query extends AbstractQuery { ...@@ -29,27 +31,16 @@ class Query extends AbstractQuery {
run(sql, parameters) { run(sql, parameters) {
this.sql = sql; this.sql = sql;
const { connection } = this;
//do we need benchmark for this query execution //do we need benchmark for this query execution
const benchmark = this.sequelize.options.benchmark || this.options.benchmark;
const showWarnings = this.sequelize.options.showWarnings || this.options.showWarnings; const showWarnings = this.sequelize.options.showWarnings || this.options.showWarnings;
let queryBegin; const complete = this._logQuery(sql, debug);
if (benchmark) {
queryBegin = Date.now();
} else {
this.sequelize.log(`Executing (${this.connection.uuid || 'default'}): ${this.sql}`, this.options);
}
debug(`executing(${this.connection.uuid || 'default'}) : ${this.sql}`);
return new Utils.Promise((resolve, reject) => { return new Utils.Promise((resolve, reject) => {
const handler = (err, results) => { const handler = (err, results) => {
debug(`executed(${this.connection.uuid || 'default'}) : ${this.sql}`); complete();
if (benchmark) {
this.sequelize.log(`Executed (${this.connection.uuid || 'default'}): ${this.sql}`, Date.now() - queryBegin, this.options);
}
if (err) { if (err) {
err.sql = sql; err.sql = sql;
...@@ -61,9 +52,9 @@ class Query extends AbstractQuery { ...@@ -61,9 +52,9 @@ class Query extends AbstractQuery {
}; };
if (parameters) { if (parameters) {
debug('parameters(%j)', parameters); debug('parameters(%j)', parameters);
this.connection.execute(sql, parameters, handler).setMaxListeners(100); connection.execute(sql, parameters, handler).setMaxListeners(100);
} else { } else {
this.connection.query({ sql: this.sql }, handler).setMaxListeners(100); connection.query({ sql }, handler).setMaxListeners(100);
} }
}) })
// Log warnings if we've got them. // Log warnings if we've got them.
......
...@@ -2,8 +2,8 @@ ...@@ -2,8 +2,8 @@
const _ = require('lodash'); const _ = require('lodash');
const AbstractConnectionManager = require('../abstract/connection-manager'); const AbstractConnectionManager = require('../abstract/connection-manager');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const debug = logger.getLogger().debugContext('connection:pg'); const debug = logger.debugContext('connection:pg');
const Promise = require('../../promise'); const Promise = require('../../promise');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const semver = require('semver'); const semver = require('semver');
......
'use strict'; 'use strict';
const logger = require('../../utils/logger');
const debug = logger.getLogger().debugContext('sql:pg');
const AbstractQuery = require('../abstract/query'); const AbstractQuery = require('../abstract/query');
const QueryTypes = require('../../query-types'); const QueryTypes = require('../../query-types');
const Promise = require('../../promise'); const Promise = require('../../promise');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const _ = require('lodash'); const _ = require('lodash');
const { logger } = require('../../utils/logger');
const debug = logger.debugContext('sql:mysql');
class Query extends AbstractQuery { class Query extends AbstractQuery {
/** /**
...@@ -43,28 +45,18 @@ class Query extends AbstractQuery { ...@@ -43,28 +45,18 @@ class Query extends AbstractQuery {
} }
run(sql, parameters) { run(sql, parameters) {
const connection = this.connection; const { connection } = this;
this.sql = sql;
if (!_.isEmpty(this.options.searchPath)) { if (!_.isEmpty(this.options.searchPath)) {
this.sql = this.sequelize.getQueryInterface().QueryGenerator.setSearchPath(this.options.searchPath) + sql; sql = this.sequelize.getQueryInterface().QueryGenerator.setSearchPath(this.options.searchPath) + sql;
} }
this.sql = sql;
const query = parameters && parameters.length const query = parameters && parameters.length
? new Promise((resolve, reject) => connection.query(this.sql, parameters, (error, result) => error ? reject(error) : resolve(result))) ? new Promise((resolve, reject) => connection.query(sql, parameters, (error, result) => error ? reject(error) : resolve(result)))
: new Promise((resolve, reject) => connection.query(this.sql, (error, result) => error ? reject(error) : resolve(result))); : new Promise((resolve, reject) => connection.query(sql, (error, result) => error ? reject(error) : resolve(result)));
//do we need benchmark for this query execution const complete = this._logQuery(sql, debug);
const benchmark = this.sequelize.options.benchmark || this.options.benchmark;
let queryBegin;
if (benchmark) {
queryBegin = Date.now();
} else {
this.sequelize.log(`Executing (${connection.uuid || 'default'}): ${this.sql}`, this.options);
}
debug(`executing(${connection.uuid || 'default'}) : ${this.sql}`);
return query.catch(err => { return query.catch(err => {
// set the client so that it will be reaped if the connection resets while executing // set the client so that it will be reaped if the connection resets while executing
...@@ -76,15 +68,8 @@ class Query extends AbstractQuery { ...@@ -76,15 +68,8 @@ class Query extends AbstractQuery {
throw this.formatError(err); throw this.formatError(err);
}) })
.then(queryResult => { .then(queryResult => {
debug(`executed(${connection.uuid || 'default'}) : ${this.sql}`); complete();
if (benchmark) {
this.sequelize.log(`Executed (${connection.uuid || 'default'}): ${this.sql}`, Date.now() - queryBegin, this.options);
}
return queryResult;
})
.then(queryResult => {
const rows = Array.isArray(queryResult) const rows = Array.isArray(queryResult)
? queryResult.reduce((allRows, r) => allRows.concat(r.rows || []), []) ? queryResult.reduce((allRows, r) => allRows.concat(r.rows || []), [])
: queryResult.rows; : queryResult.rows;
......
...@@ -2,8 +2,8 @@ ...@@ -2,8 +2,8 @@
const AbstractConnectionManager = require('../abstract/connection-manager'); const AbstractConnectionManager = require('../abstract/connection-manager');
const Promise = require('../../promise'); const Promise = require('../../promise');
const logger = require('../../utils/logger'); const { logger } = require('../../utils/logger');
const debug = logger.getLogger().debugContext('connection:sqlite'); const debug = logger.debugContext('connection:sqlite');
const dataTypes = require('../../data-types').sqlite; const dataTypes = require('../../data-types').sqlite;
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const parserStore = require('../parserStore')('sqlite'); const parserStore = require('../parserStore')('sqlite');
......
...@@ -2,13 +2,15 @@ ...@@ -2,13 +2,15 @@
const _ = require('lodash'); const _ = require('lodash');
const Utils = require('../../utils'); const Utils = require('../../utils');
const logger = require('../../utils/logger');
const debug = logger.getLogger().debugContext('sql:sqlite');
const Promise = require('../../promise'); const Promise = require('../../promise');
const AbstractQuery = require('../abstract/query'); const AbstractQuery = require('../abstract/query');
const QueryTypes = require('../../query-types'); const QueryTypes = require('../../query-types');
const sequelizeErrors = require('../../errors'); const sequelizeErrors = require('../../errors');
const parserStore = require('../parserStore')('sqlite'); const parserStore = require('../parserStore')('sqlite');
const { logger } = require('../../utils/logger');
const debug = logger.debugContext('sql:sqlite');
class Query extends AbstractQuery { class Query extends AbstractQuery {
getInsertIdField() { getInsertIdField() {
...@@ -65,13 +67,7 @@ class Query extends AbstractQuery { ...@@ -65,13 +67,7 @@ class Query extends AbstractQuery {
return ret; return ret;
} }
_handleQueryResponse(metaData, columnTypes, benchmark, queryBegin, err, results) { _handleQueryResponse(metaData, columnTypes, err, results) {
debug(`executed(${this.connection.uuid || 'default'}) : ${this.sql}`);
if (benchmark) {
this.sequelize.log(`Executed (${this.connection.uuid || 'default'}): ${this.sql}`, Date.now() - queryBegin, this.options);
}
if (err) { if (err) {
err.sql = this.sql; err.sql = this.sql;
throw this.formatError(err); throw this.formatError(err);
...@@ -231,23 +227,13 @@ class Query extends AbstractQuery { ...@@ -231,23 +227,13 @@ class Query extends AbstractQuery {
this.sql = sql; this.sql = sql;
} }
//do we need benchmark for this query execution const complete = this._logQuery(sql, debug);
const benchmark = this.sequelize.options.benchmark || this.options.benchmark;
let queryBegin;
if (benchmark) {
queryBegin = Date.now();
} else {
this.sequelize.log(`Executing (${conn.uuid || 'default'}): ${this.sql}`, this.options);
}
debug(`executing(${conn.uuid || 'default'}) : ${this.sql}`);
return new Promise(resolve => { return new Promise(resolve => {
const columnTypes = {}; const columnTypes = {};
conn.serialize(() => { conn.serialize(() => {
const executeSql = () => { const executeSql = () => {
if (this.sql.startsWith('-- ')) { if (sql.startsWith('-- ')) {
return resolve(); return resolve();
} }
resolve(new Promise((resolve, reject) => { resolve(new Promise((resolve, reject) => {
...@@ -255,9 +241,10 @@ class Query extends AbstractQuery { ...@@ -255,9 +241,10 @@ class Query extends AbstractQuery {
// cannot use arrow function here because the function is bound to the statement // cannot use arrow function here because the function is bound to the statement
function afterExecute(executionError, results) { function afterExecute(executionError, results) {
try { try {
complete();
// `this` is passed from sqlite, we have no control over this. // `this` is passed from sqlite, we have no control over this.
// eslint-disable-next-line no-invalid-this // eslint-disable-next-line no-invalid-this
resolve(query._handleQueryResponse(this, columnTypes, benchmark, queryBegin, executionError, results)); resolve(query._handleQueryResponse(this, columnTypes, executionError, results));
return; return;
} catch (error) { } catch (error) {
reject(error); reject(error);
...@@ -266,10 +253,10 @@ class Query extends AbstractQuery { ...@@ -266,10 +253,10 @@ class Query extends AbstractQuery {
if (method === 'exec') { if (method === 'exec') {
// exec does not support bind parameter // exec does not support bind parameter
conn[method](this.sql, afterExecute); conn[method](sql, afterExecute);
} else { } else {
if (!parameters) parameters = []; if (!parameters) parameters = [];
conn[method](this.sql, parameters, afterExecute); conn[method](sql, parameters, afterExecute);
} }
})); }));
return null; return null;
......
'use strict'; 'use strict';
const _ = require('lodash'); const _ = require('lodash');
const logger = require('./utils/logger'); const { logger } = require('./utils/logger');
const Promise = require('./promise'); const Promise = require('./promise');
const debug = logger.getLogger().debugContext('hooks'); const debug = logger.debugContext('hooks');
const hookTypes = { const hookTypes = {
beforeValidate: { params: 2 }, beforeValidate: { params: 2 },
......
...@@ -5,7 +5,7 @@ const _ = require('lodash'); ...@@ -5,7 +5,7 @@ const _ = require('lodash');
const Dottie = require('dottie'); const Dottie = require('dottie');
const Utils = require('./utils'); const Utils = require('./utils');
const logger = require('./utils/logger'); const { logger } = require('./utils/logger');
const BelongsTo = require('./associations/belongs-to'); const BelongsTo = require('./associations/belongs-to');
const BelongsToMany = require('./associations/belongs-to-many'); const BelongsToMany = require('./associations/belongs-to-many');
const InstanceValidator = require('./instance-validator'); const InstanceValidator = require('./instance-validator');
...@@ -19,6 +19,7 @@ const Hooks = require('./hooks'); ...@@ -19,6 +19,7 @@ const Hooks = require('./hooks');
const associationsMixin = require('./associations/mixin'); const associationsMixin = require('./associations/mixin');
const Op = require('./operators'); const Op = require('./operators');
// This list will quickly become dated, but failing to maintain this list just means // This list will quickly become dated, but failing to maintain this list just means
// we won't throw a warning when we should. At least most common cases will forever be covered // we won't throw a warning when we should. At least most common cases will forever be covered
// so we stop throwing erroneous warnings when we shouldn't. // so we stop throwing erroneous warnings when we shouldn't.
......
...@@ -17,14 +17,6 @@ class Logger { ...@@ -17,14 +17,6 @@ class Logger {
context: 'sequelize', context: 'sequelize',
debug: true debug: true
}, config); }, config);
this.debug = debug(this.config.context);
}
debug(message) {
if (this.config.debug) {
this.debug(message);
}
} }
warn(message) { warn(message) {
...@@ -32,17 +24,11 @@ class Logger { ...@@ -32,17 +24,11 @@ class Logger {
console.warn(`(${this.config.context}) Warning: ${message}`); console.warn(`(${this.config.context}) Warning: ${message}`);
} }
debugContext(childContext) { debugContext(name) {
if (!childContext) { return debug(`${this.config.context}:${name}`);
throw new Error('No context supplied to debug');
}
return debug([this.config.context, childContext].join(':'));
} }
} }
exports.Logger = Logger; exports.logger = new Logger();
const logger = new Logger();
exports.warn = logger.warn.bind(logger); exports.Logger = Logger;
exports.getLogger = () => logger ;
...@@ -295,7 +295,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => { ...@@ -295,7 +295,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => {
describe('logging', () => { describe('logging', () => {
it('executes a query with global benchmarking option and default logger', () => { it('executes a query with global benchmarking option and default logger', () => {
const logger = sinon.spy(console, 'log'); const logger = sinon.stub(console, 'log');
const sequelize = Support.createSequelizeInstance({ const sequelize = Support.createSequelizeInstance({
logging: logger, logging: logger,
benchmark: true benchmark: true
...@@ -322,7 +322,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => { ...@@ -322,7 +322,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => {
}); });
it('executes a query with benchmarking option and default logger', function() { it('executes a query with benchmarking option and default logger', function() {
const logger = sinon.spy(console, 'log'); const logger = sinon.stub(console, 'log');
return this.sequelize.query('select 1;', { return this.sequelize.query('select 1;', {
logging: logger, logging: logger,
benchmark: true benchmark: true
......
'use strict'; 'use strict';
const chai = require('chai'), const { expect } = require('chai');
sinon = require('sinon'), const { stub, spy } = require('sinon');
expect = chai.expect, const Support = require('../support');
Support = require('../support'), const dialect = Support.getTestDialect();
dialect = Support.getTestDialect();
describe(Support.getTestDialectTeaser('Sequelize'), () => { describe(Support.getTestDialectTeaser('Sequelize'), () => {
describe('log', () => { describe('log', () => {
beforeEach(function() { beforeEach(function() {
this.spy = sinon.spy(console, 'log'); this.stub = stub(console, 'log');
}); });
afterEach(() => { afterEach(() => {
...@@ -23,7 +22,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => { ...@@ -23,7 +22,7 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => {
it('does not call the log method of the logger', function() { it('does not call the log method of the logger', function() {
this.sequelize.log(); this.sequelize.log();
expect(this.spy.calledOnce).to.be.false; expect(this.stub.calledOnce).to.be.false;
}); });
}); });
...@@ -35,33 +34,33 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => { ...@@ -35,33 +34,33 @@ describe(Support.getTestDialectTeaser('Sequelize'), () => {
describe('called with no arguments', () => { describe('called with no arguments', () => {
it('calls the log method', function() { it('calls the log method', function() {
this.sequelize.log(); this.sequelize.log();
expect(this.spy.calledOnce).to.be.true; expect(this.stub.calledOnce).to.be.true;
}); });
it('logs an empty string as info event', function() { it('logs an empty string as info event', function() {
this.sequelize.log(''); this.sequelize.log('');
expect(this.spy.calledOnce).to.be.true; expect(this.stub.calledOnce).to.be.true;
}); });
}); });
describe('called with one argument', () => { describe('called with one argument', () => {
it('logs the passed string as info event', function() { it('logs the passed string as info event', function() {
this.sequelize.log('my message'); this.sequelize.log('my message');
expect(this.spy.withArgs('my message').calledOnce).to.be.true; expect(this.stub.withArgs('my message').calledOnce).to.be.true;
}); });
}); });
describe('called with more than two arguments', () => { describe('called with more than two arguments', () => {
it('passes the arguments to the logger', function() { it('passes the arguments to the logger', function() {
this.sequelize.log('error', 'my message', 1, { a: 1 }); this.sequelize.log('error', 'my message', 1, { a: 1 });
expect(this.spy.withArgs('error', 'my message', 1, { a: 1 }).calledOnce).to.be.true; expect(this.stub.withArgs('error', 'my message', 1, { a: 1 }).calledOnce).to.be.true;
}); });
}); });
}); });
describe('with a custom function for logging', () => { describe('with a custom function for logging', () => {
beforeEach(function() { beforeEach(function() {
this.spy = sinon.spy(); this.spy = spy();
this.sequelize = new Support.Sequelize('db', 'user', 'pw', { dialect, logging: this.spy }); this.sequelize = new Support.Sequelize('db', 'user', 'pw', { dialect, logging: this.spy });
}); });
......
...@@ -4,7 +4,7 @@ const path = require('path'); ...@@ -4,7 +4,7 @@ const path = require('path');
const Query = require(path.resolve('./lib/dialects/abstract/query.js')); const Query = require(path.resolve('./lib/dialects/abstract/query.js'));
const Support = require(path.join(__dirname, './../../support')); const Support = require(path.join(__dirname, './../../support'));
const chai = require('chai'); const chai = require('chai');
const { stub, match } = require('sinon');
const current = Support.sequelize; const current = Support.sequelize;
const expect = chai.expect; const expect = chai.expect;
...@@ -472,4 +472,41 @@ describe('[ABSTRACT]', () => { ...@@ -472,4 +472,41 @@ describe('[ABSTRACT]', () => {
]); ]);
}); });
}); });
describe('_logQuery', () => {
beforeEach(function() {
this.cls = class MyQuery extends Query { };
this.sequelizeStub = {
log: stub(),
options: {}
};
this.connectionStub = {
uuid: 'test'
};
});
it('logs before and after', function() {
const debugStub = stub();
const qry = new this.cls(this.connectionStub, this.sequelizeStub, {});
const complete = qry._logQuery('SELECT 1', debugStub);
complete();
expect(this.sequelizeStub.log).to.have.been.calledOnce;
expect(this.sequelizeStub.log).to.have.been.calledWithMatch('Executing (test): SELECT 1');
expect(debugStub).to.have.been.calledWith('Executing (test): SELECT 1');
expect(debugStub).to.have.been.calledWith('Executed (test): SELECT 1');
});
it('logs before and after with benchmark', function() {
const debugStub = stub();
const qry = new this.cls(this.connectionStub, this.sequelizeStub, { benchmark: true });
const complete = qry._logQuery('SELECT 1', debugStub);
complete();
expect(this.sequelizeStub.log).to.have.been.calledOnce;
expect(this.sequelizeStub.log).to.have.been.calledWithMatch('Executed (test): SELECT 1', match.number, { benchmark: true });
expect(debugStub).to.have.been.calledWith('Executing (test): SELECT 1');
expect(debugStub).to.have.been.calledWith('Executed (test): SELECT 1');
});
});
}); });
...@@ -6,13 +6,13 @@ const Support = require('../support'); ...@@ -6,13 +6,13 @@ const Support = require('../support');
const current = Support.sequelize; const current = Support.sequelize;
const sinon = require('sinon'); const sinon = require('sinon');
const DataTypes = require('../../../lib/data-types'); const DataTypes = require('../../../lib/data-types');
const logger = require('../../../lib/utils/logger'); const { Logger } = require('../../../lib/utils/logger');
const sequelizeErrors = require('../../../lib/errors'); const sequelizeErrors = require('../../../lib/errors');
describe(Support.getTestDialectTeaser('Model'), () => { describe(Support.getTestDialectTeaser('Model'), () => {
describe('warnOnInvalidOptions', () => { describe('warnOnInvalidOptions', () => {
beforeEach(function() { beforeEach(function() {
this.loggerSpy = sinon.spy(logger, 'warn'); this.loggerSpy = sinon.spy(Logger.prototype, 'warn');
}); });
afterEach(function() { afterEach(function() {
......
...@@ -5,7 +5,7 @@ const expect = chai.expect; ...@@ -5,7 +5,7 @@ const expect = chai.expect;
const Support = require('./support'); const Support = require('./support');
const DataTypes = require('../../lib/data-types'); const DataTypes = require('../../lib/data-types');
const Utils = require('../../lib/utils'); const Utils = require('../../lib/utils');
const logger = require('../../lib/utils/logger').getLogger(); const { logger } = require('../../lib/utils/logger');
const Op = Support.Sequelize.Op; const Op = Support.Sequelize.Op;
describe(Support.getTestDialectTeaser('Utils'), () => { describe(Support.getTestDialectTeaser('Utils'), () => {
...@@ -271,8 +271,8 @@ describe(Support.getTestDialectTeaser('Utils'), () => { ...@@ -271,8 +271,8 @@ describe(Support.getTestDialectTeaser('Utils'), () => {
describe('Logger', () => { describe('Logger', () => {
it('debug', () => { it('debug', () => {
expect(logger.debug).to.be.a('function'); expect(logger.debugContext).to.be.a('function');
logger.debug('test debug'); logger.debugContext('test debug');
}); });
it('warn', () => { it('warn', () => {
...@@ -285,7 +285,6 @@ describe(Support.getTestDialectTeaser('Utils'), () => { ...@@ -285,7 +285,6 @@ describe(Support.getTestDialectTeaser('Utils'), () => {
const testLogger = logger.debugContext('test'); const testLogger = logger.debugContext('test');
expect(testLogger).to.be.a('function'); expect(testLogger).to.be.a('function');
expect(testLogger.namespace).to.be.eql('sequelize:test');
}); });
}); });
}); });
...@@ -13,8 +13,6 @@ export class Logger { ...@@ -13,8 +13,6 @@ export class Logger {
constructor(config: LoggerConfig) constructor(config: LoggerConfig)
public debug(message: string): void; public debug(message: string): void;
public warn(message: string): void; public warn(message: string): void;
public debugContext(message: string): (message: string) => void;
} }
export function warn(message: string): void; export const logger: Logger;
export function getLogger(): Logger;
Markdown is supported
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!