I am using winston for logging and most of the time it works well, but when there is an exception, it just does not print any details.
Here is my code for configuring winston:
// Create logger
const logger = winston.createLogger()
// Create timestamp format
const tsFormat = () => (new Date()).toLocaleTimeString()
// Attach transports based on app mode
if (process.env.APP_MODE === 'production') {
// Log to file
logger.add(new (winston.transports.DailyRotateFile)({
filename: path.join(__dirname, '../logs/errors-%DATE%.log'),
datePattern: 'YYYY-MM-DD-HH',
zippedArchive: true,
format: winston.format.json(),
handleExceptions: true
}))
} else {
// Log to the console
logger.add(new (winston.transports.Console)({
timestamp: tsFormat,
colorize: true,
handleExceptions: true
}))
}
module.exports = logger
I am also using Express and in my error handling middleware, I have this code:
const logger = require('../config/winston')
function (err, req, res, next) {
console.log(err)
logger.error(err)
res.status(500).send({ error: 'Please try again later.' })
}
The problem is that when an error occurs all winston logs is:
{"level":"error"}
While the good old console.log() displays:
TypeError: Cannot read property 'filename' of undefined
at router.post (/Users/balazsvincze/Desktop/testapi/app/routes/upload.js:16:33)
at Layer.handle [as handle_request] (/Users/de/Desktop/testapi/node_modules/express/lib/router/layer.js:95:5)
at next (/Users/balazsvincze/Desktop/testapi/node_modules/express/lib/router/route.js:137:13)
at Immediate.<anonymous> (/Users/balazsvincze/Desktop/testapi/node_modules/multer/lib/make-middleware.js:53:37)
at runCallback (timers.js:814:20)
at tryOnImmediate (timers.js:768:5)
at processImmediate [as _immediateCallback] (timers.js:745:5)
How do I get winston to log something like this including the stack trace?
Many thanks!
EDIT: If I change the line logger.error(err) to logger.error(err.message), at least I get this:
{"message":"Cannot read property 'filename' of undefined","level":"error"}
Still very far off from what I am after.
I think what you're missing is format.errors({ stack: true }) in winston.createLogger.
const logger = winston.createLogger({
level: 'debug',
format: format.combine(
format.errors({ stack: true }),
print,
),
transports: [new transports.Console()],
});
See this GitHub thread for more information.
The reason this is happening is because the interesting Error object properties, like .stack, are non-enumerable. Some functions check if the their parameters are Error instances, like console.error, and other functions ignore all non-enumerable properties, like winston.<log-level> and JSON.stringify.
> console.error(new Error('foo'))
Error: foo
at repl:1:15
at Script.runInThisContext (vm.js:124:20)
...(abbr)
> JSON.stringify(new Error('foo'))
'{}'
All that said, it's horrible usability to have an error logger essentially ignore errors... I just lost too much time to this.
A quick and dirty way would be to log err.stack:
logger.error(err.stack);
A more elaborate method would be to implement a custom format specifically for Error instances. There's some example code on how to implement that in this Github issue.
Using format.
const { combine, timestamp, label, printf } = winston.format;
const myFormat = printf(info => {
if(info instanceof Error) {
return `${info.timestamp} [${info.label}] ${info.level}: ${info.message} ${info.stack}`;
}
return `${info.timestamp} [${info.label}] ${info.level}: ${info.message}`;
});
winston.createLogger({
level: "info",
format: combine(
winston.format.splat(),
label({ label: filename}),
timestamp(),
myFormat,
),
transports: [
//
// - Write to all logs with level `info` and below to `combined.log`
// - Write all logs error (and below) to `error.log`.
//
new winston.transports.File({ filename: path.join(os.tmpdir(), "test", "test.log"), level: "info" }),
],
});