always log errors with stack trace (#3573)

but don't do it for common error types that we ourselves produce

fixes #3495
This commit is contained in:
Mikael Finstad 2022-03-16 13:47:03 +08:00 committed by GitHub
parent ca15897cac
commit fc6f8f3fe5
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
4 changed files with 21 additions and 30 deletions

View file

@ -1,6 +1,7 @@
const chalk = require('chalk')
const escapeStringRegexp = require('escape-string-regexp')
const util = require('util')
const { ProviderApiError, ProviderAuthError } = require('./provider/error')
const valuesToMask = []
/**
@ -35,37 +36,30 @@ function maskMessage (msg) {
/**
* message log
*
* @param {string | Error} msg the message to log
* @param {string | Error} arg the message or error to log
* @param {string} tag a unique tag to easily search for this message
* @param {string} level error | info | debug
* @param {string=} id a unique id to easily trace logs tied to a request
* @param {Function=} color function to display the log in appropriate color
* @param {boolean=} shouldLogStackTrace when set to true, errors will be logged with their stack trace
*/
const log = (msg, tag = '', level, id = '', color = (message) => message, shouldLogStackTrace) => {
const log = (arg, tag = '', level, id = '', color = (message) => message) => {
const time = new Date().toISOString()
const whitespace = tag && id ? ' ' : ''
function logMsg (msg2) {
let msgString = typeof msg2 === 'string' ? msg2 : util.inspect(msg2)
msgString = maskMessage(msgString)
// eslint-disable-next-line no-console
console.log(color(`companion: ${time} [${level}] ${id}${whitespace}${tag}`), color(msgString))
}
if (msg instanceof Error) {
// Not sure why it only logs the stack without the message, but this is how the code was originally
if (shouldLogStackTrace && typeof msg.stack === 'string') {
logMsg(msg.stack)
return
function msgToString () {
// We don't need to log stack trace on special errors that we ourselves have produced
// (to reduce log noise)
if ((arg instanceof ProviderApiError || arg instanceof ProviderAuthError) && typeof arg.message === 'string') {
return arg.message
}
// We don't want to log stack trace (this is how the code was originally)
logMsg(String(msg))
return
if (typeof arg === 'string') return arg
return util.inspect(arg)
}
logMsg(msg)
const msgString = msgToString()
const masked = maskMessage(msgString)
// eslint-disable-next-line no-console
console.log(color(`companion: ${time} [${level}] ${id}${whitespace}${tag}`), color(masked))
}
/**
@ -97,11 +91,10 @@ exports.warn = (msg, tag, traceId) => {
* @param {string | Error} msg the message to log
* @param {string=} tag a unique tag to easily search for this message
* @param {string=} traceId a unique id to easily trace logs tied to a request
* @param {boolean=} shouldLogStackTrace when set to true, errors will be logged with their stack trace
*/
exports.error = (msg, tag, traceId, shouldLogStackTrace) => {
exports.error = (msg, tag, traceId) => {
// @ts-ignore
log(msg, tag, 'error', traceId, chalk.bold.red, shouldLogStackTrace)
log(msg, tag, 'error', traceId, chalk.bold.red)
}
/**

View file

@ -42,7 +42,7 @@ exports.verifyToken = (req, res, next) => {
const { err, payload } = tokenService.verifyEncryptedToken(token, req.companion.options.secret)
if (err || !payload[providerName]) {
if (err) {
logger.error(err, 'token.verify.error', req.id)
logger.error(err.message, 'token.verify.error', req.id)
}
return res.sendStatus(401)
}

View file

@ -197,18 +197,17 @@ module.exports = function server (inputCompanionOptions = {}) {
// @ts-ignore
app.use((err, req, res, next) => { // eslint-disable-line no-unused-vars
const logStackTrace = true
if (app.get('env') === 'production') {
// if the error is a URIError from the requested URL we only log the error message
// to avoid uneccessary error alerts
if (err.status === 400 && err instanceof URIError) {
logger.error(err.message, 'root.error', req.id)
} else {
logger.error(err, 'root.error', req.id, logStackTrace)
logger.error(err, 'root.error', req.id)
}
res.status(err.status || 500).json({ message: 'Something went wrong', requestId: req.id })
} else {
logger.error(err, 'root.error', req.id, logStackTrace)
logger.error(err, 'root.error', req.id)
res.status(err.status || 500).json({ message: err.message, error: err, requestId: req.id })
}
})

View file

@ -57,14 +57,13 @@ describe('Test Logger secret mask', () => {
const exptectedMsg = chalk.bold.red('Error: this error has ****** and ****** and case-insensitive ******')
expect(loggedMessage).toBeTruthy()
expect(loggedMessage).toBe(exptectedMsg)
expect(loggedMessage.startsWith(exptectedMsg)).toBeTruthy()
})
test('masks secret values present in log.error stack trace', () => {
const loggedMessage = captureConsoleLog(() => {
const err = new Error('this error has ToBeMasked1 and toBeMasked2 and case-insensitive TOBEMasKED2')
logger.error(err, '', '', true)
logger.error(err, '', '')
})
const exptectedMsg = chalk.bold.red('Error: this error has ****** and ****** and case-insensitive ******')