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

always log errors with stack trace #3573

Merged
merged 1 commit into from
Mar 16, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 16 additions & 23 deletions packages/@uppy/companion/src/server/logger.js
Original file line number Diff line number Diff line change
@@ -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 = []
/**
Expand Down Expand Up @@ -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))
}

/**
Expand Down Expand Up @@ -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)
}

/**
Expand Down
2 changes: 1 addition & 1 deletion packages/@uppy/companion/src/server/middlewares.js
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Copy link
Member

Choose a reason for hiding this comment

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

why not send the whole err object like in the other instances?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

because it's a very common error and causes a lot of noise, and in the current version we only log the message (inside logger.error), so I thought we'd keep the noise low on this one

}
return res.sendStatus(401)
}
Expand Down
5 changes: 2 additions & 3 deletions packages/@uppy/companion/src/standalone/index.js
Original file line number Diff line number Diff line change
Expand Up @@ -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 })
}
})
Expand Down
5 changes: 2 additions & 3 deletions packages/@uppy/companion/test/__tests__/logger.js
Original file line number Diff line number Diff line change
Expand Up @@ -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 ******')
Expand Down