Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Passing multiple parameters to logging functions doesn't behave as expected #1427

Open
1 of 2 tasks
bdsomer opened this issue Aug 6, 2018 · 53 comments
Open
1 of 2 tasks

Comments

@bdsomer
Copy link

bdsomer commented Aug 6, 2018

Please tell us about your environment:

  • winston version?
    • winston@2
    • winston@3
  • node -v outputs: v8.11.3
  • Operating System? macOS
  • Language? Flow ES6/7

What is the problem?

With 3.x.x:

const winston = require('winston')

const logger = winston.createLogger({
	transports: [new winston.transports.Console()]
})

logger.info('test log', 'with a second parameter')

Outputs:

{"level":"info","message":"test log"}

With 2.x.x:

const winston = require('winston')

const logger = new winston.Logger({
	transports: [new winston.transports.Console()]
})

logger.info('test log', 'with a second parameter')

Outputs:

info: test log with a second parameter

What do you expect to happen instead?

It should output:

{"level":"info","message":"test log with a second parameter"}
@raszi
Copy link

raszi commented Aug 10, 2018

I ran into the same issue today. I believe it is a bug since the upgrade documentation also has an example like that here:

logger.info('transaction ok', { creditCard: 123456789012345 });

@mullim
Copy link

mullim commented Aug 10, 2018

Currently to get around this you can create a function that parses the arguments before it's passed into winston

@bdsomer
Copy link
Author

bdsomer commented Aug 11, 2018

@mulligan121 Okay, but I don't want to replace every log statement in my codebase...

@luislobo
Copy link

@indexzero Is this under your radar? I think this is a major breaking change. It actually prevents from moving from 2.x to 3.x as it requires us to change every log entry

@ArcticTee
Copy link

Temporary workaround:

const wrapper = ( original ) => {
    return (...args) => original(args.join(" "));
};

winstonLogger.error = wrapper(winstonLogger.error);
winstonLogger.warn = wrapper(winstonLogger.warn);
winstonLogger.info = wrapper(winstonLogger.info);
winstonLogger.verbose = wrapper(winstonLogger.verbose);
winstonLogger.debug = wrapper(winstonLogger.debug);
winstonLogger.silly = wrapper(winstonLogger.silly);

@rjmunro
Copy link

rjmunro commented Oct 4, 2018

This is a HUGE breaking change for us. If it is intentional, it should be detailed in https://github.com/winstonjs/winston/blob/master/UPGRADE-3.0.md

@rjmunro
Copy link

rjmunro commented Oct 4, 2018

So after some more investigation, I found that you need the splat formatter in order for multiple arguments to be printed. I thought that was just for argument interpolation (i.e. stuff with %s etc. in it), but it seems you need it just to do logger.info("something", value).

But this is still being a bit weird for me - I'm getting something that looks like JSON in the output with a key "meta", even though I am not using a JSON format:

logger.info('Test: %s', 1, 2, 3, 4);

Produces:

info: Test: 1 {"meta":[2,3,4]}

Even the example in examples doesn't produce what it says it will:

https://github.com/winstonjs/winston/blob/master/examples/interpolation.js#L20-L21

info: test message first, second {"meta":{"number":123}}

@luislobo
Copy link

luislobo commented Oct 4, 2018

I've solved it using something along these lines:

const { version } = require('../package');

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, colorize, label, printf, align } = format;
const { SPLAT } = require('triple-beam');
const { isObject } = require('lodash');

function formatObject(param) {
  if (isObject(param)) {
    return JSON.stringify(param);
  }
  return param;
}

// Ignore log messages if they have { private: true }
const all = format((info) => {
  const splat = info[SPLAT] || [];
  const message = formatObject(info.message);
  const rest = splat.map(formatObject).join(' ');
  info.message = `${message} ${rest}`;
  return info;
});

const customLogger = createLogger({
  format: combine(
    all(),
    label({ label: version }),
    timestamp(),
    colorize(),
    align(),
    printf(info => `${info.timestamp} [${info.label}] ${info.level}: ${formatObject(info.message)}`)
  ),
  transports: [new transports.Console()]
});

@mullim
Copy link

mullim commented Oct 4, 2018

Here is a common workaround to allow for multiple parameters:
https://github.com/rooseveltframework/roosevelt/blob/master/lib/tools/logger.js#L29

@alexilyaev
Copy link

Related to:
#1377

There's just too many things that don't work the same.

@piyushkantm
Copy link

Hi, Any updates here? Thanks.

@kirillgroshkov
Copy link

Also waiting for proper way to emulate console.log(...args) in winston...

@indexzero
Copy link
Member

We fixed a number of the edge / corner cases around splat and meta in 3.2.0, but it appears this is still an issue (see: #1576 for the CHANGELOG.md).

Will make sure this gets handled in 3.3.0. Thanks for your patience folks.

@lukasruczkowski
Copy link

This was a workaround for me:

'use strict';

const { createLogger, format, transports } = require('winston');
const { SPLAT } = require('triple-beam');

const { combine, timestamp, label, printf, colorize } = format;

const formatObject = (param) => {
  if (typeof param === 'string') {
    return param;
  }

  if (param instanceof Error) {
    return param.stack ? param.stack : JSON.stringify(param, null, 2);
  }

  return JSON.stringify(param, null, 2);
};

const logFormat = printf((info) => {
  const { timestamp: ts, level, message } = info;
  const rest = info[SPLAT] || [];
  const msg = info.stack ? formatObject(info.stack) : formatObject(message);
  let result = `${ts} ${level}: ${msg}`;

  if (rest.length) {
    result += `\n${rest.map(formatObject).join('\n')}`;
  }

  return result;
});

const logger = createLogger({
  format: combine(
    label({ label: 'app' }),
    timestamp(),
    logFormat,
  ),
  transports: [
    new transports.Console({
      format: combine(colorize()),
      handleExceptions: true,
    }),
  ],
  exceptionHandlers: [
    new transports.File({ filename: 'exceptions.log' }),
  ],
});

@sanjeevsiva17
Copy link

When I try to log with arguments I get a weird output
var s = "Hello" log.info("asdasda", s)

Getting the output

{"0":"H","1":"e","2":"l","3":"l","4":"o","service":"XXXX","level":"info","message":"asdasda","timestamp":"2019-04-15 13:58:51"}

I used the normal quick start code

@p-bakker
Copy link

p-bakker commented Apr 18, 2019

One thing I noticed is this:

  • got a logger with 2 transports (Console and Rotating file)
  • Both use the splat format
  • The call to the transform function of splat for the first transport clears out the array stored on info under the SPLAT Symbol
  • On the call to the transform function of splat for the second transport, the SPLAT array is empty and thus the extra arguments don't get logged anymore

Hope this can/will be fixed

Note: tested this with the latest released version of Winston, quick look at the code seems to suggest that it's still like this in master (which has other fixes it seems)

@matang-dave
Copy link

matang-dave commented May 2, 2019

Some improvements over @luislobo's solution 👏

const { version } = require('../package');

const { createLogger, format, transports } = require('winston');
const { combine, timestamp, colorize, label, printf, align } = format;
const { SPLAT } = require('triple-beam');
const { isObject,trimEnd } = require('lodash');

function formatObject(param) {
  if (isObject(param)) {
    return JSON.stringify(param);
  }
  return param;
}

const all = format((info) => {
  const splat = info[SPLAT] || []

    const isSplatTypeMessage =
        typeof info.message === 'string' &&
        (info.message.includes('%s') || info.message.includes('%d') || info.message.includes('%j'))
    if (isSplatTypeMessage) {
        return info
    }
    const message = formatObject(info.message)
    const rest = splat
        .map(formatObject)
        .join(' ')
    info.message = trimEnd(`${message} ${rest}`)
    return info
});

const customLogger = createLogger({
  format: combine(
    colorize(),
    all(),
    label({ label: version }),
    timestamp(),
    align(),
    printf(info => `${info.timestamp} [${info.label}] ${info.level}: ${info.message}`)
  ),
  transports: [new transports.Console()]
});

@asanger
Copy link

asanger commented Jun 21, 2019

Any further update to this that I may be missing? It seems like there's pretty strong support for this feature to be re-added, but the last commitment to this was nearly 6 months ago.

@anymos
Copy link

anymos commented Jun 27, 2019

Hi there, huge Bumper and show stopper, trying to migrate to the 3.X, probably will keep the 2.x for a while.

A bit disappointed :(

@pgorecki
Copy link

pgorecki commented Jul 4, 2019

This is what worked for me:

const { format, createLogger, transports } = require('winston');
const jsonStringify = require('fast-safe-stringify');

const logLikeFormat = {
  transform(info) {
    const { timestamp, label, message } = info;
    const level = info[Symbol.for('level')];
    const args = info[Symbol.for('splat')];
    const strArgs = args.map(jsonStringify).join(' ');
    info[Symbol.for('message')] = `${timestamp} [${label}] ${level}: ${message} ${strArgs}`;
    return info;
  }
};

const debugFormat = {
  transform(info) {
    console.log(info);
    return info;
  }
};

const logger = createLogger({
  format: format.combine(
    // debugFormat, // uncomment to see the internal log structure
    format.timestamp(),
    format.label({ label: 'myLabel' }),
    logLikeFormat,
    // debugFormat, // uncomment to see the internal log structure
  ),
  transports: [
    new transports.Console()
  ]
});


logger.info('foo', 'bar', 1, [2, 3], true, { name: 'John' });

which results in: 2019-07-04T21:30:08.455Z [myLabel] info: foo "bar" 1 [2,3] true {"name":"John"}

Basically format.combine sets a pipeline for an info object. For each format function, transform is called and the final log message should be written to info[Symbol.for('message')]
hope this helps

@henhal
Copy link

henhal commented Jul 5, 2019

I wanted a solution that supports %d, %o etc, but still defaults to including any rest arguments, so that logger.info('hello %d %j', 42, {a:3}, 'some', 'more', 'arguments') is rendered like this:

hello 42 {"a": 3} some more arguments

My solution for this ended up using the splat symbol but manually invoking util.format() directly from printf, which by default includes any rest arguments:

const {format} = require('util');
const winston = require('winston');
const {combine, timestamp, printf} = winston.format;
const SPLAT = Symbol.for('splat');

const transport = new winston.transports.Console({
    format: combine(
        timestamp(),
        printf(({timestamp, level, message, [SPLAT]: args = []}) =>
            `${timestamp} - ${level}: ${format(message, ...args)}`)
    )
})

If you don't want printf you could of course instead add a transform that simply expands the args into info.message, and then format the end result the way you like:

format: combine(
  {
    transform(info) {
      const {[SPLAT]: args = [], message} = info;

      info.message = format(message, ...args);

      return info;
    }
  },
  simple()
)  

The problem with using format.splat() is that it consumes the matching arguments but seems to throw away the rest. By invoking util.format() myself I can override that behaviour.

@fr1sk
Copy link

fr1sk commented Sep 1, 2019

Same issue, any update regarding this one? I love Winston, but it drives me crazy when I cannot print all arguments passed to the logger, which I can do with console.log().

@henhal
Copy link

henhal commented Sep 2, 2019

@fr1sk Did you try my formatting above? It gives console.log() like behaviour (node's console.log() implementation internally uses util.format() afaik).

@alexilyaev
Copy link

alexilyaev commented Sep 26, 2019

It's disappointing that this issue still has not been resolved, and that my related issue has been locked.
I'm working with many different teams and they all share the frustration of losing previous DX when migrating to v3.

I've spent a whole day trying things out.
The above solutions were close but I was missing the colorization and line breaking of extra arguments.

IMO, logging to the Console should be delightful.
Here's my attempt to make it happen...

v2 setup for comparison

const winston = require('winston');
const chalk = require('chalk');

const logger = new winston.Logger({
  transports: [
    new winston.transports.Console({
      level: 'info',
      colorize: true,
      prettyPrint: true,
      timestamp: true
    })
  ]
});

logger.info({ one: 1, two: 2, three: 3 });
logger.info(chalk.blue('[TEST]:'), { one: 1, two: 2, three: 3 }, [4, 5, 6]);
logger.info(chalk.blue('[TEST]:'), null, undefined, 'one', 2, { 3: 3, 4: '4' });
logger.info(chalk.blue('[TEST]:'), chalk.yellow('Bombastic'), () => {}, /foo/);
logger.error(chalk.blue('[ERR]:'), new Error('Error number 1'));
logger.error(new Error('Error number 2'));

Winston2

v3 setup

const { createLogger, format, transports } = require('winston');
const { inspect } = require('util');
const chalk = require('chalk');
const hasAnsi = require('has-ansi');

function isPrimitive(val) {
  return val === null || (typeof val !== 'object' && typeof val !== 'function');
}
function formatWithInspect(val) {
  const prefix = isPrimitive(val) ? '' : '\n';
  const shouldFormat = typeof val !== 'string' || !hasAnsi(val);

  return prefix + (shouldFormat ? inspect(val, { depth: null, colors: true }) : val);
}

const logger = createLogger({
  level: 'info',
  format: format.combine(
    format.timestamp(),
    format.errors({ stack: true }),
    format.colorize(),
    format.printf(info => {
      const msg = formatWithInspect(info.message);
      const splatArgs = info[Symbol.for('splat')] || [];
      const rest = splatArgs.map(data => formatWithInspect(data)).join(' ');

      return `${info.timestamp} - ${info.level}: ${msg} ${rest}`;
    })
  ),
  transports: [new transports.Console()]
});

logger.info({ one: 1, two: 2, three: 3 });
logger.info(chalk.blue('[TEST]:'), { one: 1, two: 2, three: 3 }, [4, 5, 6]);
logger.info(chalk.blue('[TEST]:'), null, undefined, 'one', 2, { 3: 3, 4: '4' });
logger.info(chalk.blue('[TEST]:'), chalk.yellow('Bombastic'), () => {}, /foo/);
logger.error(chalk.blue('[ERR]:'), new Error('Error number 1'));
logger.error(new Error('Error number 2'));

Winston3

There are many things to handle, some of which

  • An Object-like value as the first argument
  • Several arguments of mixed values
  • Strings with ANSI escape codes, e.g. using chalk
  • Esoteric values like Function and RegEx
  • An Error as a first argument or anywhere after that
  • Should still work fine alongside other formatters

Current bugs with this solution

  • Passing an Error as the 1st argument does not print the Stack Trace
    • This is because info.message is just a string and the stack tract is in the stack property
  • Passing an Object with a message property as the 1st argument only printsmessage, discarding any other properties
    • Same reason as the one above
  • Passing an Error as the 2nd argument somehow concatenates the error message on top of info.message (which is usually the value of the 1st argument), resulting in seeing the error message twice
    • Tracked in Error.message being appended to info.message #1660
    • This is actually part of the README:

      NOTE: any { message } property in a meta object provided will automatically be concatenated to any msg already provided: For example the below will concatenate 'world' onto 'hello':

Playing around with the errors formatter didn't help.

Positive enhancements

  • Logging primitive values now gets prettified
  • Logging several Object-like values now adds a newline between them
  • Logging an Array is now prettified instead of looking like an Object with indices keys

Edit:

We can handle the errors formatting but it's hacky:

function formatWithInspect(val) {
+ if (val instanceof Error) {
+   return '';
+ }

  const prefix = isPrimitive(val) ? '' : '\n';
  const shouldFormat = typeof val !== 'string' || !hasAnsi(val);

  return prefix + (shouldFormat ? inspect(val, { depth: null, colors: true }) : val);
}

...
    format.printf((info) => {
      const msg = formatWithInspect(info.message);
      const splatArgs = info[Symbol.for('splat')] || [];
      const rest = splatArgs.map((data) => formatWithInspect(data)).join(' ');
+    const stackTrace = info.stack ? `\n${info.stack}` : '';

      return `${info.timestamp} - ${info.level}: ${msg} ${rest}${stackTrace}`;
    })
...

@yamadashy
Copy link

it works for me using info[Symbol.for('splat')]

const logger = winston.createLogger({
    level: 'debug',
    transports: [
        ...
    ],
    format: winston.format.combine(
        winston.format.timestamp(),
        winston.format.printf((info: any) => {
            const timestamp = info.timestamp.trim();
            const level = info.level;
            const message = (info.message || '').trim();
            const args = info[Symbol.for('splat')];
            const strArgs = (args || []).map((arg: any) => {
                return util.inspect(arg, {
                    colors: true
                });
            }).join(' ');
            return `[${timestamp}] ${level} ${message} ${strArgs}`;
        })
    )
});

@neillindberg
Copy link

I understand major versions introduce breaking changes, but my goodness...

@nikitamendelbaum
Copy link

nikitamendelbaum commented Nov 20, 2019

None of the solutions gave me same behavior as winston v2.
Solutions from @henhal and @yamadashy both have same issue: message value is showed as the string.
logger.debug(err) create log message:

debug:  Error: ETIMEDOUT

whereas logger.debug('anystringhere', err) creates:

debug:  anystringhereError: ETIMEDOUT { RequestError: Error: ETIMEDOUT
    at new RequestError (/path/to/node_modules/request-promise-core/lib/errors.js:14:15)
 <the rest of full error stack here>

Second issue is that the additional arguments are suppressed when using with info level - winston v3 seems to handle that the other way before formatting.

Third issue is the missing space between 2 messages (notice "anystringhereError").

My current v3 logger configuration:

const { format } = require('util');
const winston = require("winston");

const logger = winston.createLogger({
  transports: [
    new winston.transports.Console({
      level: 'debug'
      format: winston.format.combine(
          winston.format.colorize(),
          winston.format.align(),
          winston.format.printf(
              ({level, message, [Symbol.for('splat')]: args = []}) => `${level}: ${format(message, ...args)}`
          )
      )
    }),
  ]
});
module.exports = logger;

I had enough of that and gonna switch back to winston v2 with just this:

const Winston = require("winston");

const logger = new Winston.Logger({
  transports: [
    new Winston.transports.Console({
      level: 'debug',
      handleExceptions: true,
      json: false,
      colorize: true,
    })
  ],
});
module.exports = logger;

This v2 configuration does not have the above-mentioned issues.

@edy
Copy link

edy commented Nov 21, 2019

I want to share my winston setup:

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

const myFormat = printf(({ level, message, label, timestamp, ...rest }) => {
	const splat = rest[Symbol.for('splat')];
	const strArgs = splat ? splat.map((s) => util.formatWithOptions({ colors: true, depth: 10 }, s)).join(' ') : '';
	return `${timestamp}  ${level}  ${util.formatWithOptions({ colors: true, depth: 10}, message)} ${strArgs}`;
});

const logger = createLogger({
	level: process.env.NODE_ENV === 'production' ? 'info' : 'debug',
	format: combine(
		colorize(),
		timestamp({
			format: 'YYYY-M-DD HH:mm:ss',
		}),
		padLevels(),
		myFormat
	),
	transports: [new transports.Console()],
});

logger.info('test info');
logger.error('test error');
logger.debug('test debug');

image

@rmuradov
Copy link

Here is a common workaround to allow for multiple parameters:
https://github.com/rooseveltframework/roosevelt/blob/master/lib/tools/logger.js#L29

here is updated link to the proposed solution
https://github.com/rooseveltframework/roosevelt/blob/0.13.0/lib/tools/logger.js

@jooj123
Copy link

jooj123 commented Feb 7, 2020

Mine is a variation of @alexilyaev great suggestions:

const { omit } = require('lodash');
const hasAnsi = require('has-ansi');

function isPrimitive(val) {
  return val === null || (typeof val !== 'object' && typeof val !== 'function');
}
function formatWithInspect(val) {
  if (val instanceof Error) {
    return '';
  }

  const shouldFormat = typeof val !== 'string' && !hasAnsi(val);
  const formattedVal = shouldFormat
    ? inspect(val, { depth: null, colors: true })
    : val;

  return isPrimitive(val) ? formattedVal : `\n${formattedVal}`;
}

// Handles all the different log formats for console
function getDomainWinstonLoggerFormat(format) {
  return format.combine(
    format.timestamp(),
    format.errors({ stack: true }),
    format.colorize(),
    format.printf((info) => {
      const stackTrace = info.stack ? `\n${info.stack}` : '';

      // handle single object
      if (!info.message) {
        const obj = omit(info, ['level', 'timestamp', Symbol.for('level')]);
        return `${info.timestamp} - ${info.level}: ${formatWithInspect(obj)}${stackTrace}`;
      }

      const splatArgs = info[Symbol.for('splat')] || [];
      const rest = splatArgs.map(data => formatWithInspect(data)).join('');
      const msg = formatWithInspect(info.message);

      return `${info.timestamp} - ${info.level}: ${msg}${rest}${stackTrace}`;
    }),
  );
}

for logs like:

logger.info({
    joe: 'blow',
  });
  logger.info('Single String');
  logger.info('With Func ', () => {}, /foo/);
  logger.info('String One ', 'String Two');
  logger.info('String One ', 'String Two ', 'String Three');
  logger.info('Single Object ', {
    test: 123,
  });
  logger.info(
    'Multiple Objects ',
    {
      test: 123,
    },
    {
      martin: 5555,
    },
  );
  logger.error('Error: ', new Error('Boom!'));

It outputs like this - which is good for all my scenarios:

Screen Shot 2020-02-06 at 10 54 31 pm

@jacargentina
Copy link
Contributor

jacargentina commented Mar 11, 2020

Hey I'm starting with Winston, never used v2, so I'm on v3.2.1

I was trying to simply do:

import winston, { format } from 'winston';
winston.format(format.combine(format.splat(), format.simple()));

winston.info('buildFastify dataPath %s', opts.dataPath);

And hoping the string interpolation works; but nope.

{"level":"info","message":"buildFastify dataPath %s"}

When I was expecting

{"level":"info","message":"buildFastify dataPath /My/Data/Path"}

This issue is the same thing somehow? Or I'm forced to use the logger.log('info', .....) function instead?

Edit

Event trying this doesn't work.

  winston.log('info', 'buildFastify dataPath %s', opts.dataPath);

output:

{"level":"info","message":"buildFastify dataPath %s"}

@Fabryz
Copy link

Fabryz commented Jun 11, 2020

Thanks to who posted the suggestions above.
Damn I've thrown away one day just to integrate Winston 3 on my project :/

@switch120
Copy link

switch120 commented Jun 30, 2020

This one hit me today - I realized my fancy new logger was tossing all my ...rest arguments. This may not work for everyone or every use case, but in my case I found it acceptable to just wrap everything I wanted logged as an array. It's not the prettiest, but it's lighter than some of the [very clever] workarounds that require more code. Hope this helps someone else!

logger.info(["Something happened!", foo, bar]);

@1212gmartinez
Copy link

Really upsetting that they decided to make a breaking change this large and STILL have not mentioned it in the migration guide or the documentation.

Regardless I wanted to share my solution which I found quite compact and follows how node js implements console.log using util.format

const winstonLogger= createLogger(...);

const writeLogType = (logLevel) => {
    return function () {
        const args = Array.from(arguments);
        winstonLogger[logLevel](util.format(...args));
    };
};

const logger = {
    silly: writeLogType('silly'),
    debug: writeLogType('debug'),
    verbose: writeLogType('verbose'),
    info: writeLogType('info'),
    warn: writeLogType('warn'),
    error: writeLogType('error'),
};

@j-a-h-i-r
Copy link

I would like to chime in and request this feature to be added to the core Winston. Currently, I'm using the custom formatter with splat to achieve this functionality, which honestly feels very hacky. It would be nice to have functionality that matches console.log

@Silventino
Copy link

Any updates?

@YousefMMS
Copy link

YousefMMS commented Oct 22, 2020

Besides the above behaviors for v3, I want to add this as well:

logger.info('param 1', { propInJson1: 'propInJson 1', propInJson2: 'propInJson 2' });

will produce this

{"propInJson1":"propInJson 1","propInJson2":"propInJson 2","level":"info","message":"param 1"}

the version I'm using: (v3.2.1)
The configs:

winstonLogger.add(new winston.transports.Console());

@Cristy94
Copy link

I still don't understand how to output multiple values in Winston.

I just wanted to replace console.log('Hello', var1, '!') with logger.log('Hello', var1, '!').

To be honest, trying to use Winston always lead to a lot of time wasted and surprising problems with logging.

@delimmy
Copy link

delimmy commented Mar 29, 2021

Really upsetting that they decided to make a breaking change this large and STILL have not mentioned it in the migration guide or the documentation.

Regardless I wanted to share my solution which I found quite compact and follows how node js implements console.log using util.format

const winstonLogger= createLogger(...);

const writeLogType = (logLevel) => {
    return function () {
        const args = Array.from(arguments);
        winstonLogger[logLevel](util.format(...args));
    };
};

const logger = {
    silly: writeLogType('silly'),
    debug: writeLogType('debug'),
    verbose: writeLogType('verbose'),
    info: writeLogType('info'),
    warn: writeLogType('warn'),
    error: writeLogType('error'),
};

Also, use util.formatWithOptions({ colors: true }, ...args); to get colored print output like with regular console.log

@whoisstan
Copy link

whoisstan commented Mar 31, 2021

This works for me. combineMessageAndSplat that combines message and splat using util.format

const winston = require("winston");
const util    = require('util');

const combineMessageAndSplat = () => {
    return {transform: (info, opts) => {
      //combine message and args if any
      info.message =  util.format(info.message, ...info[Symbol.for('splat')]  ||  [] )
      return info;
    }
  }
}

const logger = winston.createLogger({
  format:
    winston.format.combine(
      combineMessageAndSplat(),
      winston.format.simple()
    )
});

logger.add(new winston.transports.Console({
    level: 'info'
  })
);

logger.info("string");          // info: string
logger.info({a:1,b:[{c:[1]}]}); // info: { a: 1, b: [ { c: [Array] } ] }
logger.info("1","2",{a:1});     // info: 1 2 { a: 1 }
logger.info([{},""]);           // info: [ {}, '' ]
logger.error(new Error());      // error: Error ...    at Object.<anonymous> 

@BananaAcid
Copy link

BananaAcid commented Apr 10, 2021

I had to conform to console.* methods, orientating on all above, and ...

  • default console methods (they colorize by default) for chrome-dev-tools
  • electrons terminal console output (also colored by default)
  • writing to a file

But: The file output should show object details.

So I ended up with:

// make File and FileList parseable // from: https://stackoverflow.com/a/51939522/1644202
File.prototype.toObject = function () {
    return Object({
        name: String(this.name),
        path: String(this.path),
        lastModified: parseInt(this.lastModified),
        lastModifiedDate: String(this.lastModifiedDate),
        size: parseInt(this.size),
        type: String(this.type)
    });
};

FileList.prototype.toArray = function () {
    return Array.from(this).map(function (file) {
        return file.toObject()
    });
};

// this fixes: winston console transport to use the original console functions and all the colorization/folding/etc that comes with it
const Transport = require('winston-transport');
class WebDeveloperConsole extends Transport {
    constructor(opts) {
        super(opts);
    }

    log(info, callback) {
        (window.console[info.level] || window.console.log).apply(window.console, [info.timestamp, ...info.message]);
        callback();
    }
};

// Electron app console output
class AppConsole extends Transport {
    constructor(opts) {
        super(opts);

        const { remote } = require('electron');
        this.electronConsole = remote.getGlobal('console');
    }

    log(info, callback) {
        (this.electronConsole[info.level] || this.electronConsole.log).apply(this.electronConsole, [info.timestamp, ...info.message]);
        callback();
    }
};

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

let logger = createLogger({
    level: 'trace',
    levels: {
        error: 0,
        warn: 1,
        info: 2,
        //http: 3,   no console.* methods
        //verbose: 4,
        debug: 3,
        trace: 4
    },

    format: format.combine(
        format.prettyPrint(),
        format.timestamp({
            format: 'DD-MM-YYYY hh:mm:ss A'
        }),

        {
            transform(info) {
                const { timestamp, message } = info;
                const level = info[Symbol.for('level')];
                const args = [message, ...(info[Symbol.for('splat')] || [])];  // join the args back into one arr
                info.message = args;  // for all custom transports (mainly the console ones)

                let msg = args.map(e => {
                    if (e.toString() == '[object FileList]')
                        return util.inspect(e.toArray(), true, 10);
                    else if (e.toString() == '[object File]')
                        return util.inspect(e.toObject(), true, 10);
                    else if (e.toString() == '[object Object]') {
                        return util.inspect(e, true, 5);
                    }
                    else if (e instanceof Error)
                        return e.stack
                    else
                        return e;
                }).join(' ');

                info[Symbol.for('message')] = `${timestamp} - ${level}: ${msg}`; // for inbuild transport / file-transport

                return info;
            }
        },
    ),
    transports: [
        //new transports.Console(),
        new WebDeveloperConsole(),
        new AppConsole(),
        ...
    ],
    ...
});

@TimUnderhay
Copy link

@indexzero Was wondering if you were still planning to address this at some point?

@vellala2000
Copy link

i am exploring winston to use in my project, now wondering is it worth taking the risk as this issue is open for more than 2 years. for me this seems like a basic function for any logging framework

@leegee
Copy link

leegee commented Jul 8, 2021

Is the only solution to use Pino or something other than Winston?

@jonathanstokes
Copy link

jonathanstokes commented Jul 14, 2021

Is the only solution to use Pino or something other than Winston?

Well, patching Winston yourself as described in this thread is a viable solution. It is disappointing that something so major has to be fixed this way, but the framework is extensible enough to fix this way without forking, so there's that.

@mattpr
Copy link

mattpr commented Jul 14, 2021

At this point there are 356 open issues and commit activity on the repo has tapered off since the beginning of 2020.

So I would guess that the maintainers feel the project is good enough and/or don't have enough time to process all the open issues.

Normally you would get some indication in the issue discussion if they are open to a change/PR before you start making a contribution.

So fork it and patch it, open a PR and if the PR is ignored use your fork.
Or use something else if this is a major issue for you.

@b4ti1c
Copy link

b4ti1c commented Jan 30, 2022

At this point I have lost faith in winston project. I cant believe this issue is not embraced at all. I have switched from winston to pino to bunyan and back to winston and to winston 2. Winston is able to provide very important functionalities the other two cannot, however the disability to log multiple parameters and error is downright unacceptable. With pino, you cannot define a stackdriver service context and transform. With bunyan, you cannot transform the logs as well. With winston you cannot log more than 1 parameter. I am having a hard time believing these are all our 'modern' logger options in 2022.

To leave my bits I have put together the following winston configuration to accommodate both errors and multiple parameters in the logs. Thanks to BananaAcid's reply above

const winston = require('winston');
const util = require('util');


const enumerateErrorFormat = winston.format(info => {
    if (info.message instanceof Error) {
      info.message = Object.assign({
        message: info.message.message,
        stack: info.message.stack
      }, info.message);
    }

    if (info instanceof Error) {
      return Object.assign({
        message: info.message,
        stack: info.stack
      }, info);
    }

    return info;
});

const logger = winston.createLogger({
    level: 'silly',
    format: winston.format.combine(
        enumerateErrorFormat(),
        {
            transform: (info) => {
                const args = [info.message, ...(info[Symbol.for('splat')] || [])];
                info.message = args;

                const msg = args.map(arg => {
                    if (typeof arg == 'object')
                        return util.inspect(arg, {compact: true, depth: Infinity});
                    return arg;
                }).join(' ');

                info[Symbol.for('message')] = `${info[Symbol.for('level')]}: ${msg}${info.stack ? ' ' + info.stack : ''}`;

                return info;
            }
        }
    )
});

logger.add(new winston.transports.Console())
logger.add(new winston.transports.File({filename: './logs.txt.'}));

logger.silly('hello silly', 1234, 'my condolence', {ahmet:1, meh:[{ahmet:1, meh:'alo'},{ahmet:1, meh:'alo'}]}, [{ahmet:1, meh:'alo'},{ahmet:1, meh:'alo'}]);
logger.debug('hello debug', () => console.log(1+2));
logger.info('hello info');
logger.warn('hello warn');
logger.error('hello error');
logger.error(new Error('error 1'), 123, new Error('error 2'));

@wbt
Copy link
Contributor

wbt commented Jan 31, 2022

At this point there are 356 open issues and commit activity on the repo has tapered off since the beginning of 2020.

So I would guess that the maintainers feel the project is good enough and/or don't have enough time to process all the open issues.

Normally you would get some indication in the issue discussion if they are open to a change/PR before you start making a contribution.

So fork it and patch it, open a PR and if the PR is ignored use your fork. Or use something else if this is a major issue for you.

This seems like a reasonable description in general; core maintainers have very little bandwidth even for reviewing issues/PRs and are largely reliant on community members for authoring PRs.

@maverick1872
Copy link
Member

I'm hoping to be able to take a look at this and verify it with a MWE prior to investigation. My time is limited in the next couple weeks but I'll keep this on my radar regardless. Alternatively if any one of the multiple people who have contributed to this issue thread believes they have a fix, please open a PR, link to this issue, and request a review from me!

@ejbp
Copy link

ejbp commented Jan 17, 2023

Meanwhile, I workaround this issue with the following code:
Please note that I didn't spend so much time on it so please test it carefully.

import { createLogger, format, transports } from "winston";
import { TransformableInfo } from "logform";

const prepareSplats = format((info: TransformableInfo): TransformableInfo => {
  const formatRegExp = /%[scdjifoO%]/g; // this line was copied from logform
  const splatSymbol = Symbol.for("splat") as unknown as string;

  const msg = info.message; // this line was copied from logform
  let splat = info[splatSymbol] || info.splat; // this line was copied from logform
  const tokens = msg && msg.match && msg.match(formatRegExp); // this line was copied from logform

  if (!tokens && (splat?.length)) {
    if (!(splat.length === 1 && typeof splat[0] === "object")) {
      splat = splat.map((v, index) => {
        return { [`arg_${index}`]: v };
      });
    }
  }

  return {
    ...info,
    [splatSymbol]: splat,
  };
});

export const log = createLogger({
  defaultMeta: { service: "your-service-name" },
  transports: [
    new transports.Console({
      level: "info",
      format: format.combine(
        format.timestamp({ format: "YYYY-MM-DD HH:mm:ss.SSS" }),
        format.ms(),
        format.errors({ stack: false }),
        prepareSplats(),
        format.splat(),
        format.json()
      ),
    }),
  ],
});

@GaryTowers
Copy link

Facing the same issue. I'm unable to simply do logger.info('Hello', { firstObject: true }, { secondObject: true}). As logger will throw away the second object or any other subsequent. Is this still being worked on? Thanks

@wbt
Copy link
Contributor

wbt commented Apr 10, 2023

Try a wrapper: logger.info('Hello', { objectsToLog: { firstObject: true }, { secondObject: true } }).

@danbenn
Copy link

danbenn commented Feb 22, 2024

To capture multiple parameters without any external dependencies, you can add a custom formatter, like this.

This is possible because Winston stores the extra parameters in a hidden "splat" field:

const customFormatter = format((info) => {
  if (info.label) {
    info.message = `[${info.label}]: ${info.message}`
  }

  // Winston stores the extra parameters here, 
  // in case they are needed for adding to a formatted string
  const splatProperties: any = Symbol.for('splat')
  const allArgsExceptMessage = (info[splatProperties] || [])
  const extraArgs = allArgsExceptMessage?.slice(1)

  if (extraArgs?.length) {
    const formattedExtraArgs = extraArgs.map((arg: any) => {
      if (arg instanceof Error) {
        return JSON.stringify(arg, Object.getOwnPropertyNames(arg))
      }
      return arg
    })

    // Sometimes, the initial info.metadata is just a string,
    // so we need to convert this into an object
    info.metadata = {
      metadata: info.metadata,
      extraArgs: formattedExtraArgs
    }
  }

  return info
});

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests