Overwriting sails logger does not work as expected #2695
Comments
|
Messed around with this a little bit more and it seems that if I set the Winston logger to "config.log.custom" by doing it in the file "config/log.js" as opposed to passing it to "sails.lift" it works (almost) as expected. The only issue is that now the log message type gets printed twice (presumably once from Winston and once from Captain's Log):
It would then appear that the issue with the custom Winston logger not working might be with the config object passed to "sails.lift" and not with the whole logging component. EDIT: Looked into Captain's Log and I think the duplicate log labels issue stems from there, so I created a separate issue on that project: https://github.com/balderdashy/captains-log/issues/14 |
|
So I dug into the code and narrowed it down to the line of code causing the issue. When I call Captain's Log looks for a I don't understand the need to clone the |
|
Found a temporary solution by explicitly defining the log property on the logger and setting it to to the var logger = myLib.logger;
logger.log = logger.log;
sails.lift({
log: {
custom: logger
}
}, function(err, sails) {
if (err) console.error(err);
sails.log('testing');
}); |
|
@felixmc Thanks for all the work on this. Custom logging is a bit of a neglected feature. If you have a PR that would fix this, we'd love to see it. |
|
@sgress454 do you know by any chance why Directly assigning |
|
@felixmc Have you tried any of this w/ the I've basically been wrestling almost the same issue, but trying to resolve it through the Here's the equivalent of what I have in var winston = require('winston');
var wLogger = new (winston.Logger)({
exitOnError: false,
transports: [
new winston.transports.File({
filename: '/home/gotmikhail/sails.log',
json: true,
level: 'silly'
})
],
timestamp: true
});
wLogger.log = wLogger.log;
module.exports.log = {
level: 'silly',
colors: false,
custom: wLogger,
wLogger: wLogger
};Note that I added the change you mentioned, Here's a test: sails.log.verbose('test1', { headers: req.headers });
sails.log('verbose', 'test2', { headers: req.headers });
sails.config.log.wLogger.log('verbose', 'test3', { headers: req.headers });If everything was working as I expected, all 3 would be equivalent except for the {
"level": "verbose",
"message": "test1 { headers: \n { host: '192.168.1.123:1337',\n connection: 'keep-alive',\n 'content-length': '419',\n csp: 'active',\n 'cache-control': 'no-cache',\n origin: 'chrome-extension://fhbjgbiflinjbdggehcddcbncdddomop',\n 'content-type': 'application/json',\n 'user-agent': 'Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2368.0 Safari/537.36',\n 'postman-token': '7ae1969a-f3fa-5ada-e8cb-a238441bd23b',\n accept: '*/*',\n dnt: '1',\n 'accept-encoding': 'gzip, deflate',\n 'accept-language': 'en-US,en;q=0.8' } }",
"timestamp": "2015-04-14T21:23:09.537Z"
}
{
"level": "debug",
"message": "verbose test2 { headers: \n { host: '192.168.1.123:1337',\n connection: 'keep-alive',\n 'content-length': '419',\n csp: 'active',\n 'cache-control': 'no-cache',\n origin: 'chrome-extension://fhbjgbiflinjbdggehcddcbncdddomop',\n 'content-type': 'application/json',\n 'user-agent': 'Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2368.0 Safari/537.36',\n 'postman-token': '7ae1969a-f3fa-5ada-e8cb-a238441bd23b',\n accept: '*/*',\n dnt: '1',\n 'accept-encoding': 'gzip, deflate',\n 'accept-language': 'en-US,en;q=0.8' } }",
"timestamp": "2015-04-14T21:23:09.538Z"
}
{
"headers": {
"host": "192.168.1.123:1337",
"connection": "keep-alive",
"content-length": "419",
"csp": "active",
"cache-control": "no-cache",
"origin": "chrome-extension://fhbjgbiflinjbdggehcddcbncdddomop",
"content-type": "application/json",
"user-agent": "Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2368.0 Safari/537.36",
"postman-token": "7ae1969a-f3fa-5ada-e8cb-a238441bd23b",
"accept": "*/*",
"dnt": "1",
"accept-encoding": "gzip, deflate",
"accept-language": "en-US,en;q=0.8"
},
"level": "verbose",
"message": "test3",
"timestamp": "2015-04-14T21:23:09.538Z"
}So, looks like Any suggestions? |
|
@gotmikhail @felixmc // sails/config/local.js
var Winston = require('winston');
module.exports = {
// ...
log: {
custom: new Winston.Logger({
levels: {
silly: 0,
verbose: 1,
debug: 2,
info: 3,
warn: 4,
error: 5
},
transports: [
new Winston.transports.Console({
level: 'silly',
showLevel: false
})
]
}),
// the following line doesnt make sense, but if you dont
// have it, the "verbose" and "silly" levels will not appear
level: ''
},
// ...
}I haven't looked into why this works, but it does. The reason I defined my own custom log levels is because I disliked how sails goes against convention by having debug > info, and also because I disliked how Winston has verbose > debug. The latter was especially annoying because all the sails verbose messages would be displayed when I had the log level to debug.... Anyway, not a permanent fix, but it works for now. |
|
@bberry6 Does your fix take care of the issue w/ |
|
Just tested it, and it looks like, no, they are not formatted the same... Here's my local.js file, which has the Winston logger for The tests... sails.log.info('test', {foo: 'bar'});
sails.config.log.custom.log('info', 'test4', {foo: 'bar'});output... {
"level": "info",
"message": "\u001b[32minfo: \u001b[39mtest { foo: 'bar' }"
}
{
"foo": "bar",
"level": "info",
"message": "test4"
}Honestly, this is probably because sails is doing some behind the scenes serialization when setting up the sails.log to use the Winston logger, but I haven't done the research so I honestly don't know.... Which could imply that the 2nd test is the expected output of the Winston logger with that setup? |
|
@gotmikhail @bberry6 |
|
you need to use formatter option inside transports in order to remove "level" var logger = new (winston.Logger)({
transports: [
new (winston.transports.Console)({
timestamp: function() {
return Date.now();
},
formatter: function(options) {
// Return string will be passed to logger.
return options.timestamp() +' '+ options.level.toUpperCase() +' '+ (undefined !== options.message ? options.message : '') +
(options.meta && Object.keys(options.meta).length ? '\n\t'+ JSON.stringify(options.meta) : '' );
}
})
]
});just remove |
|
I would add a slightly simpler way is to simply do this.
|
|
Thanks for posting, @felixmc. I'm a repo bot-- nice to meet you! It has been 60 days since there have been any updates or new comments on this page. If this issue has been resolved, feel free to disregard the rest of this message. On the other hand, if you are still waiting on a patch, please:
Thanks so much for your help! |
|
@gotmikhail @stensrud @joshuamarquez @rh0dium thanks for the help guys! @bberry6 @felixmc as @gotmikhail pointed out above, there's some additional points covered in https://github.com/balderdashy/captains-log/issues/16 that might be helpful. Specifically, https://github.com/balderdashy/captains-log/issues/16#issuecomment-169890710 is a pretty thorough example of another way to completely override the default logging with your own custom handling. |
This is for Sails v0.10.5
I wanted to overwrite the default Captain's Log logger in my Sails application to an instance of Winston from an internal library my company uses in our node.js apps.
I was unable to find anything specifically about overwriting the logger in the official Sails docs pertaining to logging (let me know if I missed something):
http://sailsjs.org/#!/documentation/concepts/Logging
http://sailsjs.org/#!/documentation/reference/sails.config/sails.config.log.html
http://sailsjs.org/#!/documentation/anatomy/myApp/config/log.js.html
However, the following Stack Overflow answer claims that I can use the "log.custom" config property with an instance of Winston to overwrite the default logger:
http://stackoverflow.com/questions/25211183/sails-js-0-10-x-log-to-file
This correlates with the official Captain's Log documentation which states that a "custom" property with an instance of Winston or another logger can be passed to the Captain's Log constructor.
Reference: https://github.com/balderdashy/captains-log/blob/master/README.md#configuring-a-custom-logger
And so I tried the following in my
app.js:But got the following error:
The error seems to suggest that Sails tried to load a logger from the "custom" property, but the instance I passed did not have "info()" and "debug()" methods, so it's not a valid logger, even though I had called those methods on the logger right before passing it to the Sails config.
What's strange is that if I passed a custom logger with just those methods, Sails had no problem with it and worked as expected:
This might mean the problem isn't with the "config.log.custom" property, but rather with my specific instance of Winston or the fact that I passed in an instance of Winston.
On a hunch, I decided set my Winston logger to "config.log", and this appears to be working great (respects the logging options and transports on my Winston logger).
However I am confused about whether this is a supported feature or just a hack I stumbled upon that might get removed in future versions of Sails.
Since overwriting the logger isn't really covered in Sail's documentation, though it is mentioned in the docs of Captain's Log, which is a Sails sub-project, I would have expected that setting the "custom" property of "config.log" would be the proper way of overwriting the logger.
If "config.log.custom" is supposed to be a proper way of setting a custom Winston logger, then there might be a bug in v0.10.5 that prevents that from working, at least in some instances (since it gave me the above error when I passed a valid instance of Winston to it).
Also if setting "config.log" is not a hack and is supposed to be supported, it should probably be mentioned in the docs along with "config.log.custom".
The text was updated successfully, but these errors were encountered: