sequelize: Logging problem with Winston

When using Winston.info() function as main Sequelize logging function, logs contain Sequelize logging function code.

Simple example :

const
    config  = require("./config"),
    winston = require("winston"),
    Sequelize = require("sequelize");

const sequelize = new Sequelize(config.db.name, config.db.username, config.db.password, {
    host: config.db.host,
    dialect: "mysql",
    logging: winston.info
});

sequelize.authenticate()
    .then(() => winston.info("Connection has been established successfully."))
    .catch(err => winston.error("Unable to connect to the database: ", err));

This example outputs the following log :

info: Executing (default): SELECT 1+1 AS result logging=function (msg) {
      // build argument list (level, msg, ... [string interpolate], [{metadata}], [callback])
      var args = [level].concat(Array.prototype.slice.call(arguments));
      target.log.apply(target, args);
    }, plain=true, raw=true, showWarnings=false, type=SELECT
info: Connection has been established successfully.

Dialect: mysql Database version: 5.7.12 Sequelize version: 4.2.0

About this issue

Original URL
State: closed
Created 7 years ago
Reactions: 2
Comments: 36 (24 by maintainers)

Most upvoted comments

@benjhoo: how about a simple work-around for now:

logging: (msg) => winston.info(msg),

This prints out the following in my test:

info: Executing (default): SELECT 1+1 AS result
info: Connection has been established successfully.

+41

ox on Jun 28, 2017

@benjhoo how are you configuring your winston logger? I created a logger that logs to console and file and it wrote to both:

const Sequelize = require('sequelize');
const winston = require('winston');
const logger = new winston.Logger({
  level: 'info',
  transports: [
    new (winston.transports.Console)(),
    new (winston.transports.File)({filename: 'somefile.log'}),
  ],
});

const {POSTGRES_DB, POSTGRES_USER, POSTGRES_HOST, POSTGRES_PORT, POSTGRES_PASSWORD, = process.env;

const opts = {
  host: POSTGRES_HOST,
  port: POSTGRES_PORT,
  dialect: 'postgres',
  logging: (msg) => logger.info(msg),
};

const sequelize = new Sequelize(POSTGRES_DB, POSTGRES_USER, POSTGRES_PASSWORD, opts);

sequelize.authenticate()
    .then(() => logger.info('Connection has been established successfully.'))
    .catch((err) => logger.error('Unable to connect to the database: ', err))
    .finally(() => sequelize.close());

After running it and seeing the console output, I checked somefile.log:

$ cat somefile.log
{"level":"info","message":"Executing (default): SELECT 1+1 AS result","timestamp":"2017-06-28T15:37:09.576Z"}
{"level":"info","message":"Executing (default): SELECT 1+1 AS result","timestamp":"2017-06-28T15:37:21.876Z"}
{"level":"info","message":"Connection has been established successfully.","timestamp":"2017-06-28T15:37:21.885Z"}

ox on Jun 28, 2017

removing the options object from custom loggers is a breaking change and therefore would need to be delayed until 5.0

I disagree. Log messages, just like error messages, don’t fall under any contract. You should never assert on the content of error messages or log messages, therefor no application breaks if any of these change (otherwise fixing a typo in a log or error message would be breaking change too).

Regarding the proposal, I would just add a logOptions flag.

felixfbecker on Jun 22, 2017

@contactakagrawal why should console.log be treated any different from other loggers, or a bound console.log?

felixfbecker on Jun 22, 2017

This is the PR that changed this: https://github.com/sequelize/sequelize/pull/7555

I don’t understand at all why console.log should be treated any different than other loggers. @janmeier @contactakagrawal could you explain?

felixfbecker on Jun 22, 2017