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

Fix bug in overriding default metadata in child loggers. #1598

Conversation

maverick1872
Copy link
Member

When creating a child logger with overrides for defaultMeta properties they do not actually override. Is due to the fact that the child logger is overriding the write function which is inappropriate. It should actually be overriding how the default metadata is being added to the log statement. I will have test cases incoming to prove functionality. All existing test cases are passing.

This should address issue #1596

@maverick1872
Copy link
Member Author

Some reviews on this would be much appreciated! I also have an in-progress branch to implement accessing loggers created via the child function by an ID. Between these two things I could clean up my use of winston by a respectable amount.

@kbirger
Copy link

kbirger commented Feb 28, 2019

This is much better, but still has some issues. I'm including a code sample and sample output using both Stable winston 3.2.0 and the PR code. This code includes usage examples from the root logger and from child loggers because I have realized that there are issues with both functionality and they are deeply related.

The Code

const winston = require('winston');

const rootLogger = winston.createLogger({
  level: 'debug',
  levels: winston.config.npm.levels,
  defaultMeta: {
    component: 'ROOT'
  },
  transports: [
    new winston.transports.Console({
      format: winston.format.printf((info) => `[${info.level}] [${info.component}] ${info.message}`)
    })
  ]
});

const child = rootLogger.child({
  component: 'CHILD'
});

console.log('#ROOT\n\n##This group should say [ROOT]')
rootLogger.info('1. root info string');
rootLogger.log({
  level: 'info',
  message: '2. root info obj'
});
rootLogger.log('info', '3. root info string (level, message)'); // broken

console.log('\n##Next line should say [ROOT2]');
rootLogger.log({
  level: 'debug',
  message: '4. root log override component',
  component: 'ROOT2'
}); // broken

console.log('\n#CHILD\n\n#Everything below here should say [CHILD]');
child.info('5. root info string');
child.log({
  level: 'info',
  message: '6. root info obj'
});
child.log('info', '7. root info string (level, message)'); // broken

console.log('\n##Next line should say [CHILD2]');
child.log({
  level: 'debug',
  message: '8. root log override component',
  component: 'CHILD2'
}); // broken

Winston 3.2.0

#ROOT

##This group should say [ROOT]
[info] [ROOT] 1. root info string
[info] [ROOT] 2. root info obj
[info] [undefined] 3. root info string (level, message)

##Next line should say [ROOT2]
[debug] [ROOT] 4. root log override component

#CHILD

#Everything below here should say [CHILD]
[info] [ROOT] 5. root info string
[info] [ROOT] 6. root info obj
[info] [CHILD] 7. root info string (level, message)

##Next line should say [ROOT2]
[debug] [ROOT] 8. root log override component

PR 1598

#ROOT

##This group should say [ROOT]
[info] [ROOT] 1. root info string
[info] [ROOT] 2. root info obj
[info] [undefined] 3. root info string (level, message)

##Next line should say [ROOT2]
[debug] [ROOT] 4. root log override component

#CHILD

#Everything below here should say [CHILD]
[info] [CHILD] 5. root info string
[info] [CHILD] 6. root info obj
[info] [undefined] 7. root info string (level, message)

##Next line should say [CHILD2]
[debug] [CHILD] 8. root log override component

Issues, as I observe them

There are two issues, and they show up on both root and child loggers as of this PR.

  1. root.log(level, message)
    child.log(level, message)

    logger.js:209 only logs level and message, ignoring default metadata
  2. root.log({level, message, metadataOverrideProperty})
    child.log({level, message, metadataOverrideProperty})

    logger.js:621 - _addDefaultMeta assigns in reverse order
    Object.assign(msg, this.defaultMeta);

For the first issue, I think the code needs to call _addDefaultMetadata on the object passed to this.write
For the second issue, I think the code needs to read Object.assign({}, this.defaultMeta, msg)

Please let me know if you need more info

@maverick1872
Copy link
Member Author

maverick1872 commented Feb 28, 2019

This is SUPER helpful. I'll pull this test locally, find the discrepancies and see what I can come up with. I'll add a few new tests as well as I don't believe I added any for the .log method.

@maverick1872
Copy link
Member Author

maverick1872 commented Feb 28, 2019

@kbirger So digging into the remaining issues, it's specifically an issue with the log method. I'm hesitant to modify it as it is written as is to be backwards compatible with previous versions. I'll see what I can come up with. It's primarily centered around them modifying objects in place, instead of returning the modified objects.

Edit: Would you be interested in tag-teaming it with me? I've got it 90% there but changes cause regressions across the board which I was worried about.

@kbirger
Copy link

kbirger commented Mar 1, 2019

@maverick1872 sure thing. I'd be happy to. let me know how we can best do that.

edit: also, one of the main maintainers should probably look at this before it gets accepted anyway, and they'd be in the best place to say whether we violate any backwards compatibility. I would think this would be fine, since it doesn't seem like it would be desired behavior and we aren't changing any call signatures.

Copy link
Contributor

@DABH DABH left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm supportive of this PR! Seems like child loggers are indeed a bit inconsistent as they stand so would definitely be a win to get everything working consistently.

Dropped a few questions/comments, lmk how I can help, happy to re-review when this is ready to go. @maverick1872 @kbirger feel free to hop on the winston gitter channel if you'd like to have any real-time-ish discussions about this PR. Thanks!

lib/winston/logger.js Outdated Show resolved Hide resolved
lib/winston/logger.js Outdated Show resolved Hide resolved
lib/winston/logger.js Show resolved Hide resolved
test/logger.test.js Show resolved Hide resolved
@maverick1872
Copy link
Member Author

@DABH Thanks for the review and comments. I believe I have answered all of them as of yet. I hope to dig back into this later this week when I'm on vacation.

@mjurincic
Copy link

Any news on this PR

@maverick1872
Copy link
Member Author

Any news on this PR

@mjurincic I apologize. Life/work caught up to me very quickly (even while on vacation) and I haven't had many free cycles to sit down and revisit this. I will see if I can't address @DABH's comments this weekend and hopefully get it pushed through sooner rather than later.

@ryanrolds
Copy link

Just hit this while trying to use child loggers. Anything I can do to help this along?

@maverick1872 maverick1872 force-pushed the bugfix/child-logger-metadata-override-fix branch from 768994b to 9d0e5e9 Compare May 21, 2020 20:03
@maverick1872 maverick1872 requested a review from DABH May 23, 2020 19:14
@maverick1872
Copy link
Member Author

@DABH Is there anyway I can get you to re-review this?

@ryanlewis
Copy link

Any reason why this hasn't been merged? This still just awaiting a review from @DABH ?

@maverick1872
Copy link
Member Author

@ryanlewis Yes that is correct. One of the Project Maintainers needs to give it approval.

@indexzero could you maybe look this over and give it approval?

@maverick1872
Copy link
Member Author

At this point I'm considering Winston a dead package as it appears that the current maintainers are no longer actively supporting any aspect of it. I've seen a couple issues raised, trying to determine the status of the package, only to be shutdown without any indication of the future of the project. I'm happy to assist (in some capacity) in maintaining a fork if there is a desire for it. Otherwise I'll likely start looking for alternatives personally.

@mpetrunic
Copy link

At this point I'm considering Winston a dead package as it appears that the current maintainers are no longer actively supporting any aspect of it. I've seen a couple issues raised, trying to determine the status of the package, only to be shutdown without any indication of the future of the project. I'm happy to assist (in some capacity) in maintaining a fork if there is a desire for it. Otherwise I'll likely start looking for alternatives personally.

I suggest https://github.com/pinojs/pino

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

Successfully merging this pull request may close these issues.

None yet

7 participants