From 3b0bd362c9abf1ba6d0b6d7013e623c675fd6fb1 Mon Sep 17 00:00:00 2001 From: Tuan Dang Date: Wed, 1 Nov 2023 10:10:39 +0200 Subject: [PATCH] Refactor requestErrorHandler, adjust request errors to appropriate pino log level --- backend/package-lock.json | 118 ++++++++++++++---- backend/package.json | 2 +- backend/src/middleware/requestErrorHandler.ts | 58 ++++----- backend/src/utils/errors.ts | 2 +- backend/src/utils/logging/logger.ts | 11 +- backend/src/utils/requestError.ts | 47 +++---- backend/src/utils/setup/backfillData.ts | 26 ++-- docs/self-hosting/configuration/envars.mdx | 29 ++--- 8 files changed, 175 insertions(+), 118 deletions(-) diff --git a/backend/package-lock.json b/backend/package-lock.json index 2000548c9..ccd86213d 100644 --- a/backend/package-lock.json +++ b/backend/package-lock.json @@ -15,7 +15,7 @@ "@godaddy/terminus": "^4.12.0", "@node-saml/passport-saml": "^4.0.4", "@octokit/rest": "^19.0.5", - "@sentry/node": "^7.49.0", + "@sentry/node": "^7.77.0", "@sentry/tracing": "^7.48.0", "@types/crypto-js": "^4.1.1", "@types/libsodium-wrappers": "^0.7.10", @@ -5028,18 +5028,59 @@ "integrity": "sha512-Xni35NKzjgMrwevysHTCArtLDpPvye8zV/0E4EyYn43P7/7qvQwPh9BGkHewbMulVntbigmcT7rdX3BNo9wRJg==" }, "node_modules/@sentry/node": { - "version": "7.59.3", - "resolved": "https://registry.npmjs.org/@sentry/node/-/node-7.59.3.tgz", - "integrity": "sha512-5dG90YzmKjuy5TK04qDuc9LBxnGfqsZw8Oh9giwOBfQVCaFp7R14AXyQ1F8k3iUF+4sGeTvoqi9I/GKAItVmlA==", + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/node/-/node-7.77.0.tgz", + "integrity": "sha512-Ob5tgaJOj0OYMwnocc6G/CDLWC7hXfVvKX/ofkF98+BbN/tQa5poL+OwgFn9BA8ud8xKzyGPxGU6LdZ8Oh3z/g==", "dependencies": { - "@sentry-internal/tracing": "7.59.3", - "@sentry/core": "7.59.3", - "@sentry/types": "7.59.3", - "@sentry/utils": "7.59.3", - "cookie": "^0.4.1", - "https-proxy-agent": "^5.0.0", - "lru_map": "^0.3.3", - "tslib": "^2.4.1 || ^1.9.3" + "@sentry-internal/tracing": "7.77.0", + "@sentry/core": "7.77.0", + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0", + "https-proxy-agent": "^5.0.0" + }, + "engines": { + "node": ">=8" + } + }, + "node_modules/@sentry/node/node_modules/@sentry-internal/tracing": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry-internal/tracing/-/tracing-7.77.0.tgz", + "integrity": "sha512-8HRF1rdqWwtINqGEdx8Iqs9UOP/n8E0vXUu3Nmbqj4p5sQPA7vvCfq+4Y4rTqZFc7sNdFpDsRION5iQEh8zfZw==", + "dependencies": { + "@sentry/core": "7.77.0", + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0" + }, + "engines": { + "node": ">=8" + } + }, + "node_modules/@sentry/node/node_modules/@sentry/core": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/core/-/core-7.77.0.tgz", + "integrity": "sha512-Tj8oTYFZ/ZD+xW8IGIsU6gcFXD/gfE+FUxUaeSosd9KHwBQNOLhZSsYo/tTVf/rnQI/dQnsd4onPZLiL+27aTg==", + "dependencies": { + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0" + }, + "engines": { + "node": ">=8" + } + }, + "node_modules/@sentry/node/node_modules/@sentry/types": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/types/-/types-7.77.0.tgz", + "integrity": "sha512-nfb00XRJVi0QpDHg+JkqrmEBHsqBnxJu191Ded+Cs1OJ5oPXEW6F59LVcBScGvMqe+WEk1a73eH8XezwfgrTsA==", + "engines": { + "node": ">=8" + } + }, + "node_modules/@sentry/node/node_modules/@sentry/utils": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/utils/-/utils-7.77.0.tgz", + "integrity": "sha512-NmM2kDOqVchrey3N5WSzdQoCsyDkQkiRxExPaNI2oKQ/jMWHs9yt0tSy7otPBcXs0AP59ihl75Bvm1tDRcsp5g==", + "dependencies": { + "@sentry/types": "7.77.0" }, "engines": { "node": ">=8" @@ -20523,18 +20564,49 @@ } }, "@sentry/node": { - "version": "7.59.3", - "resolved": "https://registry.npmjs.org/@sentry/node/-/node-7.59.3.tgz", - "integrity": "sha512-5dG90YzmKjuy5TK04qDuc9LBxnGfqsZw8Oh9giwOBfQVCaFp7R14AXyQ1F8k3iUF+4sGeTvoqi9I/GKAItVmlA==", + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/node/-/node-7.77.0.tgz", + "integrity": "sha512-Ob5tgaJOj0OYMwnocc6G/CDLWC7hXfVvKX/ofkF98+BbN/tQa5poL+OwgFn9BA8ud8xKzyGPxGU6LdZ8Oh3z/g==", "requires": { - "@sentry-internal/tracing": "7.59.3", - "@sentry/core": "7.59.3", - "@sentry/types": "7.59.3", - "@sentry/utils": "7.59.3", - "cookie": "^0.4.1", - "https-proxy-agent": "^5.0.0", - "lru_map": "^0.3.3", - "tslib": "^2.4.1 || ^1.9.3" + "@sentry-internal/tracing": "7.77.0", + "@sentry/core": "7.77.0", + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0", + "https-proxy-agent": "^5.0.0" + }, + "dependencies": { + "@sentry-internal/tracing": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry-internal/tracing/-/tracing-7.77.0.tgz", + "integrity": "sha512-8HRF1rdqWwtINqGEdx8Iqs9UOP/n8E0vXUu3Nmbqj4p5sQPA7vvCfq+4Y4rTqZFc7sNdFpDsRION5iQEh8zfZw==", + "requires": { + "@sentry/core": "7.77.0", + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0" + } + }, + "@sentry/core": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/core/-/core-7.77.0.tgz", + "integrity": "sha512-Tj8oTYFZ/ZD+xW8IGIsU6gcFXD/gfE+FUxUaeSosd9KHwBQNOLhZSsYo/tTVf/rnQI/dQnsd4onPZLiL+27aTg==", + "requires": { + "@sentry/types": "7.77.0", + "@sentry/utils": "7.77.0" + } + }, + "@sentry/types": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/types/-/types-7.77.0.tgz", + "integrity": "sha512-nfb00XRJVi0QpDHg+JkqrmEBHsqBnxJu191Ded+Cs1OJ5oPXEW6F59LVcBScGvMqe+WEk1a73eH8XezwfgrTsA==" + }, + "@sentry/utils": { + "version": "7.77.0", + "resolved": "https://registry.npmjs.org/@sentry/utils/-/utils-7.77.0.tgz", + "integrity": "sha512-NmM2kDOqVchrey3N5WSzdQoCsyDkQkiRxExPaNI2oKQ/jMWHs9yt0tSy7otPBcXs0AP59ihl75Bvm1tDRcsp5g==", + "requires": { + "@sentry/types": "7.77.0" + } + } } }, "@sentry/tracing": { diff --git a/backend/package.json b/backend/package.json index 77a90f87d..f950b1d9c 100644 --- a/backend/package.json +++ b/backend/package.json @@ -6,7 +6,7 @@ "@godaddy/terminus": "^4.12.0", "@node-saml/passport-saml": "^4.0.4", "@octokit/rest": "^19.0.5", - "@sentry/node": "^7.49.0", + "@sentry/node": "^7.77.0", "@sentry/tracing": "^7.48.0", "@types/crypto-js": "^4.1.1", "@types/libsodium-wrappers": "^0.7.10", diff --git a/backend/src/middleware/requestErrorHandler.ts b/backend/src/middleware/requestErrorHandler.ts index f7e964630..3bcea0d98 100644 --- a/backend/src/middleware/requestErrorHandler.ts +++ b/backend/src/middleware/requestErrorHandler.ts @@ -3,52 +3,44 @@ import { ErrorRequestHandler } from "express"; import { TokenExpiredError } from "jsonwebtoken"; import { InternalServerError, UnauthorizedRequestError } from "../utils/errors"; import { logger } from "../utils/logging"; -import RequestError from "../utils/requestError"; +import RequestError, { mapToPinoLogLevel } from "../utils/requestError"; import { ForbiddenError } from "@casl/ability"; export const requestErrorHandler: ErrorRequestHandler = async ( - error: RequestError | Error, + err: RequestError | Error, req, res, next ) => { if (res.headersSent) return next(); - const logAndCaptureException = async (error: RequestError) => { - // TODO: tie pino error-handling to error types/levels + let error: RequestError; - // (await getLogger("backend-main")).log( - // (error).levelName.toLowerCase(), - // `${error.stack}\n${error.message}` - // ); - - logger.error(error.stack, error.message); - - //* Set Sentry user identification if req.user is populated - if (req.user !== undefined && req.user !== null) { - Sentry.setUser({ email: (req.user as any).email }); - } - - Sentry.captureException(error); - }; - - if (error instanceof RequestError) { - if (error instanceof TokenExpiredError) { - error = UnauthorizedRequestError({ stack: error.stack, message: "Token expired" }); - } - await logAndCaptureException((error)); - } else { - if (error instanceof ForbiddenError) { - error = UnauthorizedRequestError({ context: { exception: error.message }, stack: error.stack }) - } else { - error = InternalServerError({ context: { exception: error.message }, stack: error.stack }); - } - - await logAndCaptureException((error)); + switch (true) { + case err instanceof TokenExpiredError: + error = UnauthorizedRequestError({ stack: err.stack, message: "Token expired" }); + break; + case err instanceof ForbiddenError: + error = UnauthorizedRequestError({ context: { exception: err.message }, stack: err.stack }) + break; + case err instanceof RequestError: + error = err as RequestError; + break; + default: + error = InternalServerError({ context: { exception: err.message }, stack: err.stack }); + break; } + logger[mapToPinoLogLevel(error.level)](error); + + if (req.user) { + Sentry.setUser({ email: (req.user as any).email }); + } + + Sentry.captureException(error); + delete (error).stacktrace // remove stack trace from being sent to client - res.status((error).statusCode).json(error); + res.status((error).statusCode).json(error); // revise json part here next(); }; diff --git a/backend/src/utils/errors.ts b/backend/src/utils/errors.ts index 42cc20509..1751dcd92 100644 --- a/backend/src/utils/errors.ts +++ b/backend/src/utils/errors.ts @@ -29,7 +29,7 @@ export const UnauthorizedRequestError = (error?: Partial) = }); export const ForbiddenRequestError = (error?: Partial) => new RequestError({ - logLevel: error?.logLevel ?? LogLevel.INFO, + logLevel: error?.logLevel ?? LogLevel.WARN, statusCode: error?.statusCode ?? 403, type: error?.type ?? "forbidden", message: error?.message ?? "You are not allowed to access this resource", diff --git a/backend/src/utils/logging/logger.ts b/backend/src/utils/logging/logger.ts index 2cef739ed..37f2c0ecd 100644 --- a/backend/src/utils/logging/logger.ts +++ b/backend/src/utils/logging/logger.ts @@ -13,9 +13,12 @@ export const logger = pino({ }, }, transport: { - target: "pino-pretty", - options: { - colorize: true - } + targets: [ + { + target: "pino-pretty", + level: process.env.PINO_LOG_LEVEL || "trace", + options: { colorize: true } + } + ] } }); \ No newline at end of file diff --git a/backend/src/utils/requestError.ts b/backend/src/utils/requestError.ts index 73d29dbb8..f5f320b8d 100644 --- a/backend/src/utils/requestError.ts +++ b/backend/src/utils/requestError.ts @@ -2,34 +2,30 @@ import { Request } from "express" import { getVerboseErrorOutput } from "../config"; export enum LogLevel { - DEBUG = 100, - INFO = 200, - NOTICE = 250, - WARNING = 300, - ERROR = 400, - CRITICAL = 500, - ALERT = 550, - EMERGENCY = 600, + TRACE = 10, + DEBUG = 20, + INFO = 30, + WARN = 40, + ERROR = 50, + FATAL = 60 } -export const mapToWinstonLogLevel = (customLogLevel: LogLevel): string => { +type PinoLogLevel = "trace" | "debug" | "info" | "warn" | "error" | "fatal"; + +export const mapToPinoLogLevel = (customLogLevel: LogLevel): PinoLogLevel => { switch (customLogLevel) { + case LogLevel.TRACE: + return "trace"; case LogLevel.DEBUG: return "debug"; case LogLevel.INFO: return "info"; - case LogLevel.NOTICE: - return "notice"; - case LogLevel.WARNING: + case LogLevel.WARN: return "warn"; case LogLevel.ERROR: return "error"; - case LogLevel.CRITICAL: - return "crit"; - case LogLevel.ALERT: - return "alert"; - case LogLevel.EMERGENCY: - return "emerg"; + case LogLevel.FATAL: + return "fatal"; } } @@ -42,10 +38,10 @@ export type RequestErrorContext = { stack?: string|undefined } -export default class RequestError extends Error{ +export default class RequestError extends Error { private _logLevel: LogLevel - private _logName: string + private _logName: string; statusCode: number type: string context: Record @@ -55,9 +51,10 @@ export default class RequestError extends Error{ constructor( {logLevel, statusCode, type, message, context, stack} : RequestErrorContext ){ + super(message) this._logLevel = logLevel || LogLevel.INFO - this._logName = LogLevel[this._logLevel] + this._logName = LogLevel[this._logLevel]; this.statusCode = statusCode this.type = type this.context = context || {} @@ -83,8 +80,12 @@ export default class RequestError extends Error{ }) } - get level(){ return this._logLevel } - get levelName(){ return this._logName } + get level(){ + return this._logLevel + } + get levelName(){ + return this._logName + } withTags(...tags: string[]|number[]){ this.context["tags"] = Object.assign(tags, this.context["tags"]) diff --git a/backend/src/utils/setup/backfillData.ts b/backend/src/utils/setup/backfillData.ts index 3339d8927..319c2605b 100644 --- a/backend/src/utils/setup/backfillData.ts +++ b/backend/src/utils/setup/backfillData.ts @@ -1,4 +1,3 @@ -/* eslint-disable no-console */ import crypto from "crypto"; import { Types } from "mongoose"; import { encryptSymmetric128BitHexKeyUTF8 } from "../crypto"; @@ -47,6 +46,7 @@ import { ProjectPermissionSub, memberProjectPermissions } from "../../ee/services/ProjectRoleService"; +import { logger } from "../logging"; /** * Backfill secrets to ensure that they're all versioned and have @@ -88,7 +88,7 @@ export const backfillSecretVersions = async () => { ) }); } - console.log("Migration: Secret version migration v1 complete"); + logger.info("Migration: Secret version migration v1 complete"); }; /** @@ -518,7 +518,7 @@ export const backfillSecretFolders = async () => { .limit(50); } - console.log("Migration: Folder migration v1 complete"); + logger.info("Migration: Folder migration v1 complete"); }; export const backfillServiceToken = async () => { @@ -534,7 +534,7 @@ export const backfillServiceToken = async () => { } } ); - console.log("Migration: Service token migration v1 complete"); + logger.info("Migration: Service token migration v1 complete"); }; export const backfillIntegration = async () => { @@ -550,7 +550,7 @@ export const backfillIntegration = async () => { } } ); - console.log("Migration: Integration migration v1 complete"); + logger.info("Migration: Integration migration v1 complete"); }; export const backfillServiceTokenMultiScope = async () => { @@ -575,7 +575,7 @@ export const backfillServiceTokenMultiScope = async () => { } } - console.log("Migration: Service token migration v2 complete"); + logger.info("Migration: Service token migration v2 complete"); }; /** @@ -650,7 +650,7 @@ export const backfillTrustedIps = async () => { }); await TrustedIP.bulkWrite(operations); - console.log("Backfill: Trusted IPs complete"); + logger.info("Backfill: Trusted IPs complete"); } }; @@ -698,7 +698,7 @@ export const backfillPermission = async () => { if (lock) { try { - console.info("Lock acquired for script [backfillPermission]"); + logger.info("Lock acquired for script [backfillPermission]"); const memberships = await Membership.find({ deniedPermissions: { @@ -801,7 +801,7 @@ export const backfillPermission = async () => { } } - console.info("Backfill: Finished converting old denied permission in workspace to viewers"); + logger.info("Backfill: Finished converting old denied permission in workspace to viewers"); await MembershipOrg.updateMany( { @@ -814,14 +814,14 @@ export const backfillPermission = async () => { } ); - console.info("Backfill: Finished converting owner role to member"); + logger.info("Backfill: Finished converting owner role to member"); } catch (error) { - console.error("An error occurred when running script [backfillPermission]:", error); + logger.error(error, "An error occurred when running script [backfillPermission]"); } } else { - console.info("Could not acquire lock for script [backfillPermission], skipping"); + logger.info("Could not acquire lock for script [backfillPermission], skipping"); } }; @@ -837,5 +837,5 @@ export const migrateRoleFromOwnerToAdmin = async () => { } ); - console.info("Backfill: Finished converting owner role to member"); + logger.info("Backfill: Finished converting owner role to member"); } \ No newline at end of file diff --git a/docs/self-hosting/configuration/envars.mdx b/docs/self-hosting/configuration/envars.mdx index 9b054e376..c05647627 100644 --- a/docs/self-hosting/configuration/envars.mdx +++ b/docs/self-hosting/configuration/envars.mdx @@ -153,29 +153,18 @@ Other environment variables are listed below to increase the functionality of yo JWT token lifetime expressed in seconds or a string describing a time span -{" "} - - - -{" "} - - - -#### Error logging +#### Logging Infisical uses Sentry to report error logs -{" "} + + The minimum log level for application logging; can be one of `trace`, `debug`, `info`, `warn`, `error`, or `fatal`. +