From 382a42d4393a1b457620eb5fb50fc7805e007624 Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Wed, 27 Apr 2022 15:30:55 +0200 Subject: [PATCH 1/7] Add basic error handling + Add express-async-errors package to handle async errors + Add ForwaradableError class (Base class for all project-specific errors) + Add defaultErrorHandler middleware which handles errors and sends info to the client --- package.json | 1 + src/Middleware/error/ForwardableError.ts | 16 +++++++++++ src/Middleware/error/handler.ts | 36 ++++++++++++++++++++++++ src/app.ts | 7 +++++ 4 files changed, 60 insertions(+) create mode 100644 src/Middleware/error/ForwardableError.ts create mode 100644 src/Middleware/error/handler.ts diff --git a/package.json b/package.json index 4166d94..9bbdaf3 100644 --- a/package.json +++ b/package.json @@ -27,6 +27,7 @@ "argon2": "^0.28.2", "dotenv": "^10.0.0", "express": "^4.17.1", + "express-async-errors": "^3.1.1", "jsonwebtoken": "^8.5.1", "nodemailer": "^6.7.0", "redis": "^3.1.2" diff --git a/src/Middleware/error/ForwardableError.ts b/src/Middleware/error/ForwardableError.ts new file mode 100644 index 0000000..04bc5e1 --- /dev/null +++ b/src/Middleware/error/ForwardableError.ts @@ -0,0 +1,16 @@ +export default class ForwardableError extends Error { + // If in different context + private readonly __id = "CUSTOM_ERROR"; + + public readonly status: number; + + constructor(status: number, message: string) { + super(message); + + this.status = status; + } + + static isForwardableError(error: any): error is ForwardableError { + return error.__id === "CUSTOM_ERROR"; + } +} diff --git a/src/Middleware/error/handler.ts b/src/Middleware/error/handler.ts new file mode 100644 index 0000000..d182f19 --- /dev/null +++ b/src/Middleware/error/handler.ts @@ -0,0 +1,36 @@ +import { PrismaClientUnknownRequestError } from "@prisma/client/runtime"; +import { NextFunction, Request, Response } from "express"; +import ForwardableError from "./ForwardableError"; + +const env = process.env.NODE_ENV || "production"; + +export default function defaultErrorHandler(err: any, req: Request, res: Response, next: NextFunction) { + if (ForwardableError.isForwardableError(err)) { + return res.status(err.status).json({ + type: "error", + payload: { + message: err.message, + ...(env === "development" + ? { + stack: err.stack, + } + : {}), + }, + }); + } + + if (err instanceof PrismaClientUnknownRequestError) { + return res.status(404).json({ + type: "error", + payload: { + message: "An unknown error occured. This could be due to malformed IDs", + ...(env === "development" + ? { + prisma: err.message, + stack: err.stack, + } + : {}), + }, + }); + } +} diff --git a/src/app.ts b/src/app.ts index bb3b56b..83e28d1 100644 --- a/src/app.ts +++ b/src/app.ts @@ -6,6 +6,10 @@ import argon2 from "argon2"; import adminRouter from "./Routes/admin.routes"; import organisationRouter from "./Routes/organisation.routes"; import groupRouter from "./Routes/group.routes"; +import defaultErrorHandler from "./Middleware/error/handler"; + +// Set up async error handling +require("express-async-errors"); require("dotenv").config(); // Load dotenv config @@ -52,6 +56,9 @@ async function main() { app.use("/api/groups", groupRouter); + // Error handling + app.use(defaultErrorHandler); + app.listen(process.env.PORT, () => { console.log(`Listening on Port: ${process.env.PORT}`); }); From 9516b60d93e45b4985b79229de186f8324374f3d Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Wed, 27 Apr 2022 17:00:36 +0200 Subject: [PATCH 2/7] Add logger using winston + Add formats + Add debug and error log files --- src/Middleware/error/handler.ts | 3 +++ src/Middleware/error/logger.ts | 39 +++++++++++++++++++++++++++++++++ 2 files changed, 42 insertions(+) create mode 100644 src/Middleware/error/logger.ts diff --git a/src/Middleware/error/handler.ts b/src/Middleware/error/handler.ts index d182f19..33f3448 100644 --- a/src/Middleware/error/handler.ts +++ b/src/Middleware/error/handler.ts @@ -1,6 +1,7 @@ import { PrismaClientUnknownRequestError } from "@prisma/client/runtime"; import { NextFunction, Request, Response } from "express"; import ForwardableError from "./ForwardableError"; +import logger from "./logger"; const env = process.env.NODE_ENV || "production"; @@ -20,6 +21,8 @@ export default function defaultErrorHandler(err: any, req: Request, res: Respons } if (err instanceof PrismaClientUnknownRequestError) { + logger.warning(err); + return res.status(404).json({ type: "error", payload: { diff --git a/src/Middleware/error/logger.ts b/src/Middleware/error/logger.ts new file mode 100644 index 0000000..184f5f7 --- /dev/null +++ b/src/Middleware/error/logger.ts @@ -0,0 +1,39 @@ +import winston, { createLogger } from "winston"; + +const { + format: { printf, colorize, combine, timestamp, json, errors, prettyPrint }, +} = winston; + +const defaultJsonFormat = combine(errors({ stack: true }), timestamp(), json({ space: 2 })); + +const customCLIFormat = printf(({ level, message, label, timestamp, stack }) => { + let output = `${level}${stack ? `(1/2:message)` : ""} at ${timestamp}${label ? ` (#${label})` : ""}: ${message}\n`; + + if (stack) { + output += `\n${level}(2/2:stack)${label ? ` (#${label})` : ""}: ${stack}\n\n`; + } + + return output; +}); + +export default createLogger({ + levels: winston.config.syslog.levels, + format: combine(errors({ stack: true }), timestamp()), + transports: [ + new winston.transports.Console({ + level: "debug", + format: combine(timestamp(), colorize(), customCLIFormat), + }), + new winston.transports.File({ + filename: "/app/error.log", + level: "error", + format: defaultJsonFormat, + }), + new winston.transports.File({ + level: "debug", + filename: "/app/debug.log", + format: defaultJsonFormat, + silent: !(process.env.NODE_ENV === "development"), // Silent when not in development + }), + ], +}); From 9ac4fb8efdaf8c299e5520998fe8dd894893d8a9 Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Wed, 27 Apr 2022 17:14:16 +0200 Subject: [PATCH 3/7] Add logger to main + Remove whitespace --- src/Middleware/error/logger.ts | 4 +++- src/app.ts | 5 ++++- 2 files changed, 7 insertions(+), 2 deletions(-) diff --git a/src/Middleware/error/logger.ts b/src/Middleware/error/logger.ts index 184f5f7..9674d1f 100644 --- a/src/Middleware/error/logger.ts +++ b/src/Middleware/error/logger.ts @@ -7,7 +7,9 @@ const { const defaultJsonFormat = combine(errors({ stack: true }), timestamp(), json({ space: 2 })); const customCLIFormat = printf(({ level, message, label, timestamp, stack }) => { - let output = `${level}${stack ? `(1/2:message)` : ""} at ${timestamp}${label ? ` (#${label})` : ""}: ${message}\n`; + let output = `${level}${stack ? `(1/2:message)` : ""} at ${timestamp}${label ? ` (#${label})` : ""}: ${message}${ + stack ? "\n" : "" + }`; if (stack) { output += `\n${level}(2/2:stack)${label ? ` (#${label})` : ""}: ${stack}\n\n`; diff --git a/src/app.ts b/src/app.ts index 83e28d1..d821084 100644 --- a/src/app.ts +++ b/src/app.ts @@ -7,6 +7,7 @@ import adminRouter from "./Routes/admin.routes"; import organisationRouter from "./Routes/organisation.routes"; import groupRouter from "./Routes/group.routes"; import defaultErrorHandler from "./Middleware/error/handler"; +import logger from "./Middleware/error/logger"; // Set up async error handling require("express-async-errors"); @@ -60,8 +61,10 @@ async function main() { app.use(defaultErrorHandler); app.listen(process.env.PORT, () => { - console.log(`Listening on Port: ${process.env.PORT}`); + logger.info(`Listening on port ${process.env.PORT}`); }); + + logger.info("Server started"); } main() From 8bf18267d1d203f78f972331a50c0c3deaa0f9e8 Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Thu, 28 Apr 2022 12:04:36 +0200 Subject: [PATCH 4/7] Fix: Add winston; And: Add custom error handlers + addCustomHandler() + removeCustomHandler() --- package.json | 3 ++- src/Middleware/error/handler.ts | 43 +++++++++++++++++++++++++++++++++ 2 files changed, 45 insertions(+), 1 deletion(-) diff --git a/package.json b/package.json index 9bbdaf3..e51d789 100644 --- a/package.json +++ b/package.json @@ -30,7 +30,8 @@ "express-async-errors": "^3.1.1", "jsonwebtoken": "^8.5.1", "nodemailer": "^6.7.0", - "redis": "^3.1.2" + "redis": "^3.1.2", + "winston": "^3.7.2" }, "devDependencies": { "@types/chai": "^4.2.22", diff --git a/src/Middleware/error/handler.ts b/src/Middleware/error/handler.ts index 33f3448..fbfe846 100644 --- a/src/Middleware/error/handler.ts +++ b/src/Middleware/error/handler.ts @@ -5,7 +5,34 @@ import logger from "./logger"; const env = process.env.NODE_ENV || "production"; +type ErrorHandler = (err: any, req: Request, res: Response) => boolean; + +const customHandlers: ErrorHandler[] = []; + +export function addCustomHandler(handler: ErrorHandler) { + customHandlers.push(handler); +} + +export function removeCustomHandler(handler: ErrorHandler): Boolean { + const index = customHandlers.findIndex((h) => h === handler); + + if (index < 0) { + return false; + } + + customHandlers.splice(index); + + return true; +} + export default function defaultErrorHandler(err: any, req: Request, res: Response, next: NextFunction) { + for (const handler of customHandlers) { + // Run custom handler + if (handler(err, req, res)) { + return; + } + } + if (ForwardableError.isForwardableError(err)) { return res.status(err.status).json({ type: "error", @@ -36,4 +63,20 @@ export default function defaultErrorHandler(err: any, req: Request, res: Respons }, }); } + + logger.error("--- Unhandled error ---"); + logger.error(err); + + return res.status(err.status).json({ + type: "error", + payload: { + message: err.message, + ...(env === "development" + ? { + notice: "This error was not caught by any handler, please add handling!", + stack: err.stack, + } + : {}), + }, + }); } From 09931c78da5f2412188839da8d17a697073fb224 Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Thu, 28 Apr 2022 13:51:10 +0200 Subject: [PATCH 5/7] Add logger and remove unused code --- src/app.ts | 16 +++++----------- 1 file changed, 5 insertions(+), 11 deletions(-) diff --git a/src/app.ts b/src/app.ts index d821084..bda5053 100644 --- a/src/app.ts +++ b/src/app.ts @@ -34,17 +34,6 @@ async function main() { app.use(express.urlencoded({ extended: true })); app.use(express.json()); - app.use((err: any, req: Request, res: Response, next: NextFunction) => { - if (err) { - res.status(400).send({ - type: "error", - payload: "The body of your request did not contain valid data", - }); - } else { - next(); - } - }); - // Admin authentication endpoints app.use("/api/authentication", adminAuthRouter); @@ -65,10 +54,15 @@ async function main() { }); logger.info("Server started"); + + process.on("exit", () => { + logger.info("Server stopping..."); + }); } main() .catch((e) => { + logger.crit(e); throw e; }) .finally(async () => { From 51c744de26a6604a970f1770dad39a7adfa03d49 Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Thu, 28 Apr 2022 14:35:15 +0200 Subject: [PATCH 6/7] Add debugging code + Small fix in the event controller + Add development flag to the dev container --- dev.sh | 1 + src/Controllers/event.controller.ts | 14 +++++++------- src/Middleware/debug/logger.ts | 10 ++++++++++ src/app.ts | 7 +++++++ 4 files changed, 25 insertions(+), 7 deletions(-) create mode 100644 src/Middleware/debug/logger.ts diff --git a/dev.sh b/dev.sh index b669776..258ad38 100755 --- a/dev.sh +++ b/dev.sh @@ -52,6 +52,7 @@ if [ "$RECREATE" = true ]; then -p $D_PORT:$D_PORT -e PORT=$D_PORT \ -e DATABASE_PASSWORD=server \ -e DATABASE_URL="postgresql://server:server@postgres:5432/management?schema=public" \ + -e NODE_ENV="development" \ --entrypoint "/app/scripts/docker-entrypoint.dev.sh" \ node fi diff --git a/src/Controllers/event.controller.ts b/src/Controllers/event.controller.ts index 4789a1f..6667aa6 100644 --- a/src/Controllers/event.controller.ts +++ b/src/Controllers/event.controller.ts @@ -14,13 +14,13 @@ export const getAllEvents = async (req: Request, res: Response) => { id: false, }, }); - if (events.length > 0) - res.status(200).json({ - type: "success", - payload: { - events, - }, - }); + + res.status(200).json({ + type: "success", + payload: { + events, + }, + }); }; export const getEvent = async (req: Request, res: Response) => { diff --git a/src/Middleware/debug/logger.ts b/src/Middleware/debug/logger.ts new file mode 100644 index 0000000..11711a2 --- /dev/null +++ b/src/Middleware/debug/logger.ts @@ -0,0 +1,10 @@ +import { NextFunction, Request, Response } from "express"; +import logger from "../error/logger"; + +export default function debugLogger(req: Request, res: Response, next: NextFunction) { + // Only log when in development mode + if (process.env.NODE_ENV === "development") { + logger.debug(`Request to: ${req.url}`); + next(); + } +} diff --git a/src/app.ts b/src/app.ts index bda5053..da3df2c 100644 --- a/src/app.ts +++ b/src/app.ts @@ -8,6 +8,7 @@ import organisationRouter from "./Routes/organisation.routes"; import groupRouter from "./Routes/group.routes"; import defaultErrorHandler from "./Middleware/error/handler"; import logger from "./Middleware/error/logger"; +import debugLogger from "./Middleware/debug/logger"; // Set up async error handling require("express-async-errors"); @@ -16,6 +17,10 @@ require("dotenv").config(); // Load dotenv config const app = express(); +if (process.env.NODE_ENV === "development") { + logger.info("Using development mode"); +} + async function main() { // Dev await prisma.admin.upsert({ @@ -34,6 +39,8 @@ async function main() { app.use(express.urlencoded({ extended: true })); app.use(express.json()); + app.use(debugLogger); + // Admin authentication endpoints app.use("/api/authentication", adminAuthRouter); From 6fb09b9f3198ff9b4e850cf8833f13fbf88e1e6c Mon Sep 17 00:00:00 2001 From: Stephan <57194608+stephan418@users.noreply.github.com> Date: Fri, 29 Apr 2022 10:25:13 +0200 Subject: [PATCH 7/7] HOTFIX: next() only called when in development mode + Push fix, now the server should be working again --- src/Middleware/debug/logger.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/Middleware/debug/logger.ts b/src/Middleware/debug/logger.ts index 11711a2..64310c1 100644 --- a/src/Middleware/debug/logger.ts +++ b/src/Middleware/debug/logger.ts @@ -5,6 +5,7 @@ export default function debugLogger(req: Request, res: Response, next: NextFunct // Only log when in development mode if (process.env.NODE_ENV === "development") { logger.debug(`Request to: ${req.url}`); - next(); } + + next(); }