Winston: Log / info methods don't respect metadata overrides

[kbirger]

Please tell us about your environment:

• _winston version?_
  
  
  
  • [ ] winston@2
  
  
  • [x] winston@3
  
  
• _node -v outputs:_ v10.14.2
• _Operating System?_ (Windows, macOS, or Linux) Windows and Linux
• _Language?_ all

What is the problem?

If I create a root logger with some default metadata property and a format string containing metadata, then create a child logger, calling child.info('test') ignores the metadata set on the child.
If I call child.log({ level: 'info, message: 'test' }) the metadata is honored.

I also noticed that this behavior is broken even on the root logger. If you use defaultMeta, it will overwrite data in your info object.

What do you expect to happen instead?

I expect the child behave consistently when calling .log and .info

Other information

There seem to be a few problems here.

First Problem:
When you create a logger with default metadata, it is stored as defaultMeta. When you call log(info), the default metaData is applied onto info, effectively overwriting whatever you passed.

logger.log({ level: 'debug', message: 'root log', component: 'ROOT2' });
// => [debug][ROOT]: root log

_addDefaultMeta(msg) {
    if (this.defaultMeta) {
      Object.assign(msg, this.defaultMeta); // msg gets overwritten with defaultMeta
    }
  }
}

this function should probably assign in reverse order to a blank object and return the value..

Second Problem:
When calling .info(), the same happens:

  logger.info({ message: 'root info', component: 'ROOT2' });
 // => [info][ROOT]: root info

Third Problem:
When creating a child logger which overrides component, if you call .info on the child, the metadata from the root is used instead. This is because the child() method only overrides write()

Please let me know if you need a full reproduction. I can try to provide one.

[Maverick1872]

I have created a PR that I believe will address your issue, as well as mine @kbirger. Please test it and let me know if it does not function as expected.

[kbirger]

I'm currently out of the country and my laptop has bit the dust. I'll have a look early next week, after I settle back into real life 🤣. Had a (really) brief look and the concept looks correct to me though

[Maverick1872]

@kbirger any updates? No worries if you haven't had a chance as of yet.

[kbirger]

@Maverick1872 thanks for the reminder. Just had a look and commented on your PR. I recommended two small changes, but other than that looks good, thanks!

[pciazynski]

This bug is affecting me as well. The problem is, that I cannot overwrite defaultMeta.

[Maverick1872]

Hey all, finally working through this again. Reviewed the comments on the PR and have decided I'll likely do this in phases. Updated branches my master branch, going back checking test coverage for logger.js first. Will be updating coverage where applicable before picking up the resolution for this issue to ensure I don't break anything that @DABH was worried about in regards to breaking functionality.

@mpetrunic I will be referencing your PR as well.

[Maverick1872]

@mpetrunic @kbirger Feel free to try out my PR branch if y'all want. Think I've addressed everything although there is a couple things I want to talk through with the maintainer to ensure backwards compatibility. Something to be aware of is that the .log(level, message) function signature does not apply any metadata as of right now so don't expect to see any logger configured metadata be appended to those log statements for the time being.

[mpetrunic]

@Maverick1872 Missed this comment, PR works for me

[Maverick1872]

@mpetrunic Awesome! Thanks so much for checking that! I'm basically just waiting to hear feedback about it from @DABH. In the interim i should likely add more tests to ensure the SPLAT functionality is still functioning as expected. I'm just not super familiar with it myself.