fix: log cause property from the error (#9944)

Fixes: FRMW-2762

This PR fixes the error reporting to include the original error message and the error cause when logging it using the JSON formatter of Winston.

> Side note: There is still a lot of room for improvements in our logging. But that require a overhaul cleanup in multiple places and will require dedicated loggers for commands and APP and special treatment for pretty printing errors.

## Error output in JSON format

**Before**
![CleanShot 2024-11-06 at 13 12 32@2x](https://github.com/user-attachments/assets/a986d33c-9c30-45bc-816d-e9aa142ea097)

**After**
![CleanShot 2024-11-06 at 13 11 28@2x](https://github.com/user-attachments/assets/15430e55-40b3-4d1c-b91d-3b3b4f9d0d39)
This commit is contained in:
Harminder Virk
2024-11-06 21:13:54 +05:30
committed by GitHub
parent b3cbc160eb
commit c9a2b42252
4 changed files with 129 additions and 30 deletions

View File

@@ -9,16 +9,10 @@ exports[`Reporter handles "Error" signature correctly 1`] = `
`;
exports[`Reporter handles "String" signature correctly 1`] = `
{
"level": "error",
"message": "Test log",
}
`;
exports[`Reporter handles "String, Error" signature correctly 1`] = `
{
"level": "error",
"message": "Test log",
"stack": Any<Array>,
}
[
{
"level": "error",
"message": "Test log",
},
]
`;

View File

@@ -1,4 +1,6 @@
import { Reporter } from "../"
import winston from "winston"
import Transport from "winston-transport"
describe(`Reporter`, () => {
const winstonMock = {
@@ -21,20 +23,19 @@ describe(`Reporter`, () => {
it(`handles "String" signature correctly`, () => {
reporter.error("Test log")
const generated = getErrorMessages(winstonMock.log)[0]
expect(generated).toMatchSnapshot()
expect(getErrorMessages(winstonMock.log)).toMatchSnapshot()
})
it(`handles "String, Error" signature correctly`, () => {
reporter.error("Test log", new Error("String Error"))
const generated = getErrorMessages(winstonMock.log)[0]
expect(generated).toMatchSnapshot({
stack: expect.any(Array),
})
expect(generated).toMatchInlineSnapshot(`
{
"level": "error",
"message": "Test log",
}
`)
})
it(`handles "Error" signature correctly`, () => {
@@ -46,4 +47,73 @@ describe(`Reporter`, () => {
stack: expect.any(Array),
})
})
it(`should display error cause when using json formatter`, () => {
class MemoryTransport extends Transport {
logs = []
log(info, callback) {
this.logs.push(info)
callback()
}
}
const transport = new MemoryTransport()
const jsonReporter = new Reporter({
logger: winston.createLogger({
level: "info",
levels: winston.config.npm.levels,
format: winston.format.combine(
winston.format.timestamp({
format: "YYYY-MM-DD HH:mm:ss",
}),
winston.format.errors({ stack: true }),
winston.format.splat(),
winston.format.json()
),
transports: [transport],
}),
})
jsonReporter.error(new Error("Error", { cause: new Error("Nested error") }))
expect(transport.logs).toHaveLength(1)
expect(transport.logs[0]).toHaveProperty("cause")
expect(transport.logs[0].cause).toMatch("Nested error")
})
it(`should display custom message and error cause when using json formatter`, () => {
class MemoryTransport extends Transport {
logs = []
log(info, callback) {
this.logs.push(info)
callback()
}
}
const transport = new MemoryTransport()
const jsonReporter = new Reporter({
logger: winston.createLogger({
level: "info",
levels: winston.config.npm.levels,
format: winston.format.combine(
winston.format.timestamp({
format: "YYYY-MM-DD HH:mm:ss",
}),
winston.format.errors({ stack: true }),
winston.format.splat(),
winston.format.json()
),
transports: [transport],
}),
})
jsonReporter.error(
"Something went wrong",
new Error("Error", { cause: new Error("Nested error") })
)
expect(transport.logs).toHaveLength(2)
expect(transport.logs[0].message).toEqual("Something went wrong")
expect(transport.logs[1].message).toEqual("Error")
expect(transport.logs[1]).toHaveProperty("cause")
expect(transport.logs[1].cause).toMatch("Nested error")
})
})

View File

@@ -1,8 +1,9 @@
import { track } from "@medusajs/telemetry"
import ora from "ora"
import stackTrace from "stack-trace"
import { ulid } from "ulid"
import winston from "winston"
import { inspect } from "util"
import stackTrace from "stack-trace"
import { track } from "@medusajs/telemetry"
import { panicHandler } from "./panic-handler"
const LOG_LEVEL = process.env.LOG_LEVEL || "http"
@@ -174,11 +175,17 @@ export class Reporter {
* Level 0
*/
error(messageOrError: string | Error, error?: Error) {
let message = messageOrError as string
let message: string
let errorAsObject: Error | undefined
if (typeof messageOrError === "object") {
if (messageOrError && typeof messageOrError === "object") {
errorAsObject = messageOrError
message = messageOrError.message
error = messageOrError
} else if (error) {
message = messageOrError
errorAsObject = error
} else {
message = messageOrError
}
const toLog = {
@@ -186,15 +193,38 @@ export class Reporter {
message,
}
if (error) {
toLog["stack"] = stackTrace.parse(error)
if (errorAsObject) {
toLog["message"] = errorAsObject.message
toLog["stack"] = stackTrace.parse(errorAsObject)
/**
* Winston only logs the error properties when they are
* string values. Hence we will have to self convert
* the error cause to a string
*/
if ("cause" in errorAsObject) {
toLog["cause"] = inspect(errorAsObject.cause)
}
}
/**
* If "errorAsObject" has a message property, then we will
* print the standalone message as one log item and then
* the actual error object as another log item.
*
* Otherwise, we always loose the message property from the
* actual error object
*/
if (errorAsObject?.message && errorAsObject?.message !== message) {
this.loggerInstance_.log({ level: "error", message })
}
this.loggerInstance_.log(toLog)
// Give stack traces and details in dev
if (error && IS_DEV) {
console.log(error)
/**
* In dev we print the error using `console.error`, because Winston
* CLI formatter does not print the error stack in that case
*/
if (errorAsObject && IS_DEV) {
console.error(errorAsObject)
}
}