winston-cloudwatch icon indicating copy to clipboard operation
winston-cloudwatch copied to clipboard

messageFormatter doesn't seem to work (since Winston 3.0.0?)

Open navFooh opened this issue 7 years ago • 20 comments

Hello,

Recently I upgraded to Winston 3.0.0 and decided to add some message formatting as well. I my old setup I never used the messageFormatter property of winston-cloudwatch, but now I felt a need to.

However it seems like the messageFormatter function is never executed. No matter what I change on the logObject or what I return from the function. Even when I do a console.log in the formatter, it never shows up.

I did notice that the whole formatting system of Winston changed quite a bit since 2.x. Maybe this had an impact on this formatter as well? Do you have a working example somewhere?

Best, Thijs

navFooh avatar Jul 24 '18 08:07 navFooh

There are a few examples, none about messageFormatter though... but it might also be that I screwed up somewhere during the upgrade to the newer APIs.

I will add an example for this case, check the result, if that's the case provide a fix, and come back to you; thanks for the issue!

lazywithclass avatar Jul 26 '18 15:07 lazywithclass

I've just tested this after reading the source code and this example works for me:

var winston = require('winston'),
    WinstonCloudWatch = require('../index');

winston.add(new WinstonCloudWatch({
  messageFormatter: function() {
    return 'will always log this text'
  },
  logGroupName: 'testing',
  logStreamName: 'first',
  awsRegion: 'us-east-1'
}));

winston.error('this will be always overwritten');

Could you please check if that's the case also for you?

lazywithclass avatar Aug 06 '18 21:08 lazywithclass

Sorry, I didn't have much time to get back to you recently.

I tried your example and that works fine for me too! So I got curious and tried to find why it didn't work in my original case.

Finally I discovered that when specifying the option jsonMessage: true, it never hits the messageFormatter. Maybe this is desired behaviour, since it's already being formatted as JSON. However, Winston 3 does support combining multiple formatters. Anyway, I'll leave it up to you what to do with it from here :) I don't necessarily need the messageFormatter anymore.

Cheers!

navFooh avatar Sep 07 '18 10:09 navFooh

I ran into the same issue, expecting the format option to be used if messageFormatter is not provided. This is not the case, so I ended up implementing messageFormatter to use the formatted message from the info object:

const winston = require('winston');
const WinstonCloudWatch = require('winston-cloudwatch');
const { MESSAGE } = require('triple-beam');

winston.createLogger({
  format: winston.format.json(), // default since winston 3.0.0
  transports: [
    new WinstonCloudWatch({
      jsonMessage: false,
      messageFormatter(info) {
        return info[MESSAGE];
      },
      // ... other options
    })
  ]
);

I think this should be the default behavior from winston 3.0.0.

tiborbaksa avatar Sep 09 '19 15:09 tiborbaksa

Also I'd like to mention a couple more things:

  • the LogObject (now called info object) changed: the msg property has been replaced with message property (as stated here)
  • all transports should derive from winston-transport for unified interface: now the format transport option is missing for WinstonCloudwatch

I'd like to say that using the bult-in Winston formats could be done by setting messageFormatter = winston.format.[...]([...]).transform, but it expects an object with the message property and not msg.

Align this interface WinstonJS' would lead to better usage IMO.

Thank you.

EDIT: typo

Carlovan avatar Jan 20 '20 13:01 Carlovan

@Carlovan @tiborbaksa hello and sorry for the delay, I've been quite busy on both work and non-work related issues.

Is this still relevant? From what I remember by using messageFormatter one could address all formatting needs.

Anyway, I have more free time now and could tackle the issues you're experiencing. I'm not quite sure I understood the issue, would you please sum up the changes you need so I can come up with a PR tho show a possible implementation?

lazywithclass avatar Apr 05 '20 23:04 lazywithclass

@lazywithclass what @Carlovan reported is still valid. I just came across it as well.

Winston Format

{
  format: winston.format.printf(({level, message}) => {
    return `${level} - ${message}`;
  })
}

Winston-CloudWatch MessageFormatter

{
  messageFormatter: ({level, msg}) => {
    return `${level} - ${msg}`;
  }
}

fewieden avatar Apr 09 '20 09:04 fewieden

@lazywithclass I also have the same expectations as @tiborbaksa.

If I create my logger with something like:

winston.createLogger({
    exitOnError: false,
    transports: [],
    format: winston.format.printf(customFormatter)
  });

I would expect if I don't specify a custom messageFormatter while adding a cloudwatch transport, that it would print in the format of the logger described above.

Currently, I need to add transport like this in order to achieve the same format as the console transport for example which is making use of the format option inside createLogger.

logger.add(new WinstonCloudWatch({
      awsRegion: 'eu-central-1',
      logGroupName:  'logger',
      logStreamName: process.env.NODE_ENV || 'development',
      messageFormatter: customFormatter
}));

fewieden avatar Apr 09 '20 10:04 fewieden

So you want to be able to do

winston.createLogger({
  exitOnError: false,
  transports: [],
  format: winston.format.printf(customFormatter)
});

and rely on Winston's default, is that correct?

lazywithclass avatar Apr 09 '20 10:04 lazywithclass

@lazywithclass yes that is correct, so I can use the same format in all my transports.

fewieden avatar Apr 09 '20 13:04 fewieden

@fewieden I am trying to put myself in your scenario, I wrote the following example script

var winston = require('winston'),
    WinstonCloudWatch = require('../index');


var transport = winston.createLogger({
  exitOnError: false,
  transports: [
    new WinstonCloudWatch({
      logGroupName: 'testing',
      logStreamName: 'first',
      awsRegion: 'us-east-1'
    })],
  format: winston.format.printf(function({level, message}) {
    return `${level} - ${message}`;
  })
});

transport.error('error error!');

and saw "error - error error!" in AWS CloudWatch. I'm afraid I am missing the point you guys are trying to kindly explain me, could you please post a complete snippet that I can try to verify what needs to be done?

Thanks a lot!

lazywithclass avatar Apr 09 '20 23:04 lazywithclass

Hey @lazywithclass, based on your example, it looks like that's what the ask from OP was - to be able to define a format once and use it for any transport (a Winston one or a WinstonCloudWatch one).

I'm curious to try your example, as I've done something similar in the past with no success. I'll give it another shot soon, and if I get it working, I can come back and post some code :)

petracles avatar Apr 10 '20 02:04 petracles

@lazywithclass in principle that's what I would like to do, but I think the problem with your example here is, that the format you specified is the same as you use for cloudwatch as default, if messageFormatter is not specified. That's why they are matching.

https://github.com/lazywithclass/winston-cloudwatch/blob/276dcdf0ae8edf5d236b2d097b02c72231a32514/index.js#L25-L27

Our custom format looks like this:

import { format } from 'util';

// workaround for https://github.com/winstonjs/winston/issues/1427
export function customFormatter({level, message = '', msg = '', [Symbol.for('splat')]: args = []}) {
  return `${level} - ${format(message || msg, ...args)}`;
}

Simple example

transport.info('some text');

Console Transport Screenshot from 2020-04-11 18-04-21

Cloudwatch Screenshot from 2020-04-11 18-10-16

Advanced example

transport.info('some text', {foo: 'bar'}, new Error('wtf'));

Console Transport Screenshot from 2020-04-11 18-07-20

Cloudwatch Screenshot from 2020-04-11 18-05-39

Cloudwatch with specifying messageFormatter Screenshot from 2020-04-11 18-08-41

fewieden avatar Apr 11 '20 16:04 fewieden

About msg: we don't have that anymore in the codebase, we use message the docs were obsolete, but now I've fixed them.

I've changed my proposed example to sum up your problem as follows

var winston = require('winston'),
    WinstonCloudWatch = require('../index');

function format(message, ...rest) {
  // I am inventing a custom formatter
  return `
    ${message}
    ${rest.map(r => ` * ${r}`).join('\n')}
  `
}

function customFormatter({level, message, [Symbol.for('splat')]: args = []}) {
  return `${level} - ${format(message, ...args)}`;
}

var transport = winston.createLogger({
  exitOnError: false,
  transports: [
    new WinstonCloudWatch({
      logGroupName: 'testing',
      logStreamName: 'first',
      awsRegion: 'us-east-1'
    })],
  format: winston.format.printf(customFormatter)
});

transport.info('some text', {foo: 'bar'}, new Error('wtf'));

In AWS CloudWatch it just logs info - some text, regardless of the output of customFormatter, which would've printed something like

some text
 * [object Object]
 * Error: wtf

Do you confirm that you would like the second output to appear in AWS CloudWatch? If so great!, otherwise please update the code I've pasted and add the expected output, so I have something that looks like a test to work on and check my work.

Thank you!

P.S.: This is one of those issues that would've been solved in 5 minutes if we were sitting at the same desk :D, but hopefully I'm getting closer to understanding.

lazywithclass avatar Apr 13 '20 23:04 lazywithclass

@lazywithclass

  1. The example looks good to me.
  2. Yes, I would have expected the second output in Cloudwatch.
  3. The problem with msg for me was, that typescript complained about the interface for messageFormatter. Both packages come with their own types in the package. My dependencies in this regard look like:
"dependencies": {
    "winston": "3.2.1",
    "winston-cloudwatch": "2.3.0"
},
"devDependencies": {
    "typescript": "3.8.3"
}

If you like we could also do a pair programming session.

fewieden avatar Apr 14 '20 16:04 fewieden

I'll start working towards a solution. In case I'll have problems I'll come back to you.

Thanks for the offer :)

lazywithclass avatar Apr 14 '20 18:04 lazywithclass

To have a clean implementation I think we have to move away from the obsolete inheritance model I coded ages ago and introduce the much cleaner class model. This will also allow to get rid of old practices like utils.inherit and winston.Transport.call(this, options), and finally allow us to follow the preferred way of creating a new Transport.

One of my wildest dreams would be also to remove the horrific setInterval (what was I even thinking?!?), and introduce a better approach like @timdp did for his fork https://github.com/timdp/winston-aws-cloudwatch. But I'll see about that.

This won't be immediate though and will be surely marked as winston-cloudwatch v3.0.0. I am going though the changes required to make this a reality. If you have a better idea I'm listening ^^

lazywithclass avatar Apr 20 '20 16:04 lazywithclass

Update: as you can see from https://github.com/lazywithclass/winston-cloudwatch/pull/130 I moved to the cleaner class syntax, and I've used Winston's default formatter.

I'll then put myself back into the green-red-green refactoring cycle, so I can hopefully remove setInterval as required for #127.

lazywithclass avatar May 03 '20 13:05 lazywithclass

Besides work and university issues I'm progressing slower than usual because I've got some issue with mockery, I can't get it to mock a required module (AWS)

lazywithclass avatar Jun 10 '20 20:06 lazywithclass

Try like this guys

const messageFormatter = (data) => {
  const { level, message, timestamp, ...meta } = data;
  const metatdata = `:\n${JSON.stringify(meta, null, 2)}`;
  return `${timestamp} [${level}] ${message}${metatdata}`;
};

function cloudwatch() {
  const options = { messageFormatter };
  return new winstonCloudwatch(options);
}

const logger = winston.createLogger({
  format: format.combine(format.timestamp()), // Just to allow timestamp
  transports: [cloudwatch()],
});

renjithspace avatar Jun 19 '23 16:06 renjithspace