Winston: [3.0.0-rc5]: Cannot colorize JSON logs

[denisw]

Please tell us about your environment:

• _winston version?_
  
  
  
  • winston@3
  
  
• _node -v outputs:_ v8.10.0
• _Operating System?_ macOS
• _Language?_ all

What is the problem?

I am trying to write colorized JSON logs using Winston 3.x. Following the documentation, I initialized the logger like this:

module.exports = winston.createLogger({
  format: winston.format.combine(
    winston.format.colorize(),
    winston.format.json()
  ),
  transports: [new winston.transports.Console()]
})

However, when using this logger, I get encoded color codes instead of colors:

{
  "message": "An example message",
  "level": "\u001b[32minfo\u001b[39m"
}

What do you expect to happen instead?

I would have expected the log output to actually be colored.

[chriswiggins]

@denisw try this:

module.exports = winston.createLogger({
  format: winston.format.combine(
    winston.format.colorize(),
    winston.format.printf(info => `${info.timestamp} ${info.level}: ${info.message}`)
  ),
  transports: [new winston.transports.Console()]
})

JSON objects don't have colour in them ;-)

[indexzero]

winston is working as expected, but perhaps the documentation could be more clear in this regard (related: https://github.com/winstonjs/logform/issues/9). For colorize all it does is add ANSI color codes to the MESSAGE. In your JSON you can see these color codes have been added (\u001b[32 and \u001b[39m)

{
  "message": "An example message",
  "level": "\u001b[32minfo\u001b[39m"
}

[denisw]

I understand what is happening - the color code characters get JSON-string-escaped - I just can‘t imagine that this is what anyone _wants_ or _expects_, at least not when logging to the console.

I just want my log levels to appear in red/yellow/green _and_ appear as JSON payloads during development. Am I correct that the very loosely coupled design of logform / winston currently makes that impossible?

[indexzero]

@denisw I can see how this might be confusing, but it's quite logical when one examines how the different formats & specifications are fighting against each other.

1. The behavior of JSON.stringify is well documented – strings must be enclosed in quotes and are escaped. Even using a custom replacer parameter I was unable to work around the string escaping for \\u chars.
2. ANSI color codes when escaped look weird – but we don't see it because the escaping is unwrapped when written to the console – e.g. \u001b[32m instead of \\\u001b[32m.

There may be a way to get this working with a custom replacer passed to JSON.stringify, but I couldn't get it wired up.

Instead, if we think about the desired output as what I believe it is – _simply not JSON._ It is _JSON-like_, but it's not JSON since the strings are unescaped to allow colors to pass through. There are a lot of ways to shave the JSON-like yak, but I quickly hacked this one together to illustrate it's possible:

const { createLogger, format, transports } = require('winston');
const util = require('util');

const logger = createLogger({
  level: 'silly',
  format: format.combine(
    format.colorize(),
    format.printf(info => {
      return Object.keys(info).reverse().reduce((acc, key, i) => {
        if (typeof key === 'string') {
          if (i > 0) acc += ", "
          acc += `"${key}": "${info[key]}"`
        }

        return acc;
      }, '{ ') + ' }';
    })
  ),
  transports: [new transports.Console()]
});

logger.info('hey colors!');
logger.error('oh and this one is red');
logger.silly('magenta maybe?');

Which when executed outputs:

[denisw]

I understand your point, although I personally don't see the importance of development-stage console output to actually be valid JSON byte-by-byte. For instance, the jq tool also colors JSON when outputting to the console, but omits color codes when e.g. piping to a file.

Given that this is intended behavior and not a bug, feel free to close this issue.

[pdiniz13]

Something should probably be added to the docs explaining that this is the intended behavior, given that the example given in the readme is:

winston.format.combine(
  winston.format.colorize(),
  winston.format.json()
);

[eponymz]

There is an easier way of doing this. I spent my day searching and then found this.
https://github.com/winstonjs/winston#formats
This is now my logger file.

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, label, colorize, printf, splat } = format;

const myFormat = printf(info => {
  return `${info.timestamp} ${info.label} ${info.level}: ${info.message}`;
});

const logger = createLogger({
  format: combine(
    colorize(),
    label({ label: '[app-server]' }),
    timestamp(),
    splat(),
    myFormat
  ),
  transports: [new transports.Console()]
});

module.exports = logger;

which outputs (everywhere) like this

[0] [nodemon] restarting due to changes...
[0] [nodemon] starting `node index.js`
[0] 2018-08-16T22:12:26.955Z [app-server] info: Server running on port: 5000
[0] 2018-08-16T22:12:27.448Z [app-server] info: DB connected successfully

P.S. it logs all colors correctly

[pdiniz13]

@eponymz that's kinda funny. I just spend the past couple of hours working on this and came up with pretty much the same solution. Only difference for me was that I had my format function set to:

info => {
    return `${info.timestamp} ${info.level}: ${JSON.stringify(info.message)}`
})

otherwise it wasn't expanding my objects

[eponymz]

@pdiniz13 that's actually a good idea too. I was trying to get opts to work with %O but for the life of me couldn't. Been a long day..

[shanurrahman-gcsns]

import { format, transports, LoggerOptions, createLogger } from "winston";

const consoleOpts = {
    handleExceptions: true,
    level: process.env.NODE_ENV === "production" ? "error" : "debug",
    format: format.combine(
        format.json(),
        format.colorize({ all: true }),
        format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }),
    )
}

const options: LoggerOptions = {
    transports: [
        new transports.Console(consoleOpts),
        new transports.File({ filename: "debug.log", level: "debug" })
    ],
    format: format.combine(
        format.json(),
        format.timestamp()
    )
};

const logger = createLogger(options);

if (process.env.NODE_ENV !== "production") {
    logger.debug("Logging initialized at debug level");
}

export default logger;

[RaphiStein]

How do you guys handle splats ?
For example, if in addition to the message, you want to pass other info, like arrays/objects/variables ?