diff --git a/packages/backend-common/README.md b/packages/backend-common/README.md index 972dc41fff..32bdd3d2a8 100644 --- a/packages/backend-common/README.md +++ b/packages/backend-common/README.md @@ -15,18 +15,20 @@ then make use of the handlers and logger as necessary: ```typescript import { - logger, errorHandler, + getRootLogger, notFoundHandler, + requestLoggingHandler, } from '@backstage/backend-common'; const app = express(); +app.use(requestLoggingHandler()); app.use('/home', myHomeRouter); app.use(errorHandler()); app.use(notFoundHandler()); app.listen(PORT, () => { - logger.info(`Listening on port ${PORT}`); + getRootLogger().info(`Listening on port ${PORT}`); }); ``` diff --git a/packages/backend-common/package.json b/packages/backend-common/package.json index b2f1bb3735..eec21063ce 100644 --- a/packages/backend-common/package.json +++ b/packages/backend-common/package.json @@ -31,9 +31,11 @@ "devDependencies": { "@backstage/cli": "^0.1.1-alpha.4", "@types/express": "^4.17.6", + "@types/http-errors": "^1.6.3", "@types/morgan": "^1.9.0", "@types/supertest": "^2.0.8", "get-port": "^5.1.1", + "http-errors": "^1.7.3", "jest": "^25.1.0", "jest-fetch-mock": "^3.0.3", "supertest": "^4.0.2", diff --git a/packages/backend-common/src/index.ts b/packages/backend-common/src/index.ts index b2c38ab506..54b9f5c40f 100644 --- a/packages/backend-common/src/index.ts +++ b/packages/backend-common/src/index.ts @@ -14,6 +14,5 @@ * limitations under the License. */ -export * from './errors'; export * from './logging'; export * from './middleware'; diff --git a/packages/backend-common/src/logging/index.ts b/packages/backend-common/src/logging/index.ts index 6e186fe384..06ce76ac54 100644 --- a/packages/backend-common/src/logging/index.ts +++ b/packages/backend-common/src/logging/index.ts @@ -14,4 +14,4 @@ * limitations under the License. */ -export * from './logger'; +export * from './rootLogger'; diff --git a/packages/backend-common/src/errors.ts b/packages/backend-common/src/logging/rootLogger.test.ts similarity index 51% rename from packages/backend-common/src/errors.ts rename to packages/backend-common/src/logging/rootLogger.test.ts index e59cd984d8..cc7b174221 100644 --- a/packages/backend-common/src/errors.ts +++ b/packages/backend-common/src/logging/rootLogger.test.ts @@ -14,23 +14,24 @@ * limitations under the License. */ -export class StatusCodeError extends Error { - public statusCode: number; +import { PassThrough } from 'stream'; +import winston from 'winston'; +import { getRootLogger, setRootLogger } from './rootLogger'; - constructor(statusCode: number, message?: string) { - super(message); - this.statusCode = statusCode; - } -} +describe('rootLogger', () => { + it('can replace the default logger', () => { + const logger = winston.createLogger({ + transports: [ + new winston.transports.Stream({ stream: new PassThrough() }), + ], + }); + jest.spyOn(logger, 'info'); -export class InvalidRequestError extends StatusCodeError { - constructor(message?: string) { - super(400, message || 'Invalid Request'); - } -} + setRootLogger(logger); + getRootLogger().info('testing'); -export class NotFoundError extends StatusCodeError { - constructor(message?: string) { - super(404, message || 'Not Found'); - } -} + expect(logger.info).toHaveBeenCalledWith( + expect.stringContaining('testing'), + ); + }); +}); diff --git a/packages/backend-common/src/logging/logger.ts b/packages/backend-common/src/logging/rootLogger.ts similarity index 85% rename from packages/backend-common/src/logging/logger.ts rename to packages/backend-common/src/logging/rootLogger.ts index 7021422d52..8058e22947 100644 --- a/packages/backend-common/src/logging/logger.ts +++ b/packages/backend-common/src/logging/rootLogger.ts @@ -16,7 +16,7 @@ import winston, { Logger } from 'winston'; -export let logger: Logger = winston.createLogger({ +let rootLogger: Logger = winston.createLogger({ level: process.env.LOG_LEVEL || 'info', format: process.env.NODE_ENV === 'production' @@ -35,6 +35,10 @@ export let logger: Logger = winston.createLogger({ ], }); -export function setLogger(newLogger: Logger) { - logger = newLogger; +export function getRootLogger(): Logger { + return rootLogger; +} + +export function setRootLogger(newLogger: Logger) { + rootLogger = newLogger; } diff --git a/packages/backend-common/src/middleware/errorHandler.test.ts b/packages/backend-common/src/middleware/errorHandler.test.ts index a6ec2860a8..f90794b07b 100644 --- a/packages/backend-common/src/middleware/errorHandler.test.ts +++ b/packages/backend-common/src/middleware/errorHandler.test.ts @@ -15,9 +15,9 @@ */ import express from 'express'; +import createError from 'http-errors'; import request from 'supertest'; import { errorHandler } from './errorHandler'; -import { StatusCodeError } from '../errors'; describe('errorHandler', () => { it('gives default code and message', async () => { @@ -36,7 +36,7 @@ describe('errorHandler', () => { it('takes code from StatusCodeError', async () => { const app = express(); app.use('/breaks', () => { - throw new StatusCodeError(432, 'Some Message'); + throw createError(432, 'Some Message'); }); app.use(errorHandler()); diff --git a/packages/backend-common/src/middleware/errorHandler.ts b/packages/backend-common/src/middleware/errorHandler.ts index 4491be1283..655d93ad91 100644 --- a/packages/backend-common/src/middleware/errorHandler.ts +++ b/packages/backend-common/src/middleware/errorHandler.ts @@ -20,10 +20,15 @@ import { ErrorRequestHandler, NextFunction, Request, Response } from 'express'; * Express middleware to handle errors during request processing. * * This is commonly the second to last middleware in the chain (before the - * notFoundHandler). It special cases StatusCodeError errors to expose their - * embedded status codes. + * notFoundHandler). * + * Its primary purpose is not to do translation of business logic exceptions, + * but rather to be a gobal catch-all for uncaught "fatal" errors that are + * expected to result in a 500 error. However, it also does handle some common + * error types (such as http-error exceptions) and returns the enclosed status + * code accordingly. * + * @returns An Express error request handler */ export function errorHandler(): ErrorRequestHandler { /* eslint-disable @typescript-eslint/no-unused-vars */ @@ -34,19 +39,24 @@ export function errorHandler(): ErrorRequestHandler { _next: NextFunction, ) => { const status = getStatusCode(error); - const message = error.message || 'Internal Server Error'; + const message = error.message; response.status(status).send(message); }; } function getStatusCode(error: Error): number { - const errorStatusCode = (error as any).statusCode; - if ( - typeof errorStatusCode === 'number' && - errorStatusCode >= 100 && - errorStatusCode <= 599 - ) { - return errorStatusCode; + const knownStatusCodeFields = ['statusCode', 'status']; + + for (const field of knownStatusCodeFields) { + const statusCode = (error as any)[field]; + if ( + typeof statusCode === 'number' && + (statusCode | 0) === statusCode && // is whole integer + statusCode >= 100 && + statusCode <= 599 + ) { + return statusCode; + } } return 500; diff --git a/packages/backend-common/src/middleware/notFoundHandler.ts b/packages/backend-common/src/middleware/notFoundHandler.ts index 7d148ec355..19dd130c64 100644 --- a/packages/backend-common/src/middleware/notFoundHandler.ts +++ b/packages/backend-common/src/middleware/notFoundHandler.ts @@ -22,11 +22,11 @@ import { NextFunction, Request, RequestHandler, Response } from 'express'; * Should be used as the very last handler in the chain, as it unconditionally * returns a 404 status. * - * @returns An Apollo request handler + * @returns An Express request handler */ export function notFoundHandler(): RequestHandler { /* eslint-disable @typescript-eslint/no-unused-vars */ return (_request: Request, response: Response, _next: NextFunction) => { - response.status(404).send('Not Found'); + response.status(404).send(); }; } diff --git a/packages/backend-common/src/middleware/requestLoggingHandler.test.ts b/packages/backend-common/src/middleware/requestLoggingHandler.test.ts index 35f5c8b978..191949bebe 100644 --- a/packages/backend-common/src/middleware/requestLoggingHandler.test.ts +++ b/packages/backend-common/src/middleware/requestLoggingHandler.test.ts @@ -15,12 +15,19 @@ */ import express from 'express'; +import { PassThrough } from 'stream'; import request from 'supertest'; +import winston from 'winston'; import { requestLoggingHandler } from './requestLoggingHandler'; describe('requestLoggingHandler', () => { it('emits logs for each request', async () => { - const logger = jest.fn(); + const logger = winston.createLogger({ + transports: [ + new winston.transports.Stream({ stream: new PassThrough() }), + ], + }); + jest.spyOn(logger, 'info'); const app = express(); app.use(requestLoggingHandler(logger)); @@ -31,8 +38,14 @@ describe('requestLoggingHandler', () => { await r.get('/exists1'); await r.get('/exists2'); - expect(logger).toHaveBeenCalledTimes(2); - expect(logger).toHaveBeenNthCalledWith(1, expect.stringContaining('200')); - expect(logger).toHaveBeenNthCalledWith(2, expect.stringContaining('201')); + expect(logger.info).toHaveBeenCalledTimes(2); + expect(logger.info).toHaveBeenNthCalledWith( + 1, + expect.stringContaining('200'), + ); + expect(logger.info).toHaveBeenNthCalledWith( + 2, + expect.stringContaining('201'), + ); }); }); diff --git a/packages/backend-common/src/middleware/requestLoggingHandler.ts b/packages/backend-common/src/middleware/requestLoggingHandler.ts index 36d0cae769..6604ec245c 100644 --- a/packages/backend-common/src/middleware/requestLoggingHandler.ts +++ b/packages/backend-common/src/middleware/requestLoggingHandler.ts @@ -15,23 +15,25 @@ */ import { RequestHandler } from 'express'; +import { Logger } from 'winston'; import morgan from 'morgan'; -import { logger as commonLogger } from '../logging'; +import { getRootLogger } from '../logging'; /** * Logs incoming requests. * - * @param logger An optional logger to use. If not specified, the default logger is used. - * @returns An Apollo request handler + * @param logger An optional logger to use. If not specified, the root logger will be used. + * @returns An Express request handler */ -export function requestLoggingHandler( - logger?: (message: String) => void, -): RequestHandler { - const actualLogger = logger || commonLogger.info; +export function requestLoggingHandler(logger?: Logger): RequestHandler { + const actualLogger = (logger || getRootLogger()).child({ + type: 'incomingRequest', + }); + return morgan('combined', { stream: { write(message: String) { - actualLogger(message); + actualLogger.info(message); }, }, }); diff --git a/packages/backend/src/index.ts b/packages/backend/src/index.ts index c55efd79d2..e0fd44430d 100644 --- a/packages/backend/src/index.ts +++ b/packages/backend/src/index.ts @@ -24,8 +24,9 @@ import { errorHandler, - logger, + getRootLogger, notFoundHandler, + requestLoggingHandler, } from '@backstage/backend-common'; import { router as inventoryRouter } from '@backstage/plugin-inventory-backend'; import compression from 'compression'; @@ -43,11 +44,12 @@ app.use(helmet()); app.use(cors()); app.use(compression()); app.use(express.json()); +app.use(requestLoggingHandler()); app.use('/test', testRouter); app.use('/inventory', inventoryRouter); app.use(errorHandler()); app.use(notFoundHandler()); app.listen(PORT, () => { - logger.info(`Listening on port ${PORT}`); + getRootLogger().info(`Listening on port ${PORT}`); }); diff --git a/yarn.lock b/yarn.lock index cd412c1780..0cf9fa778f 100644 --- a/yarn.lock +++ b/yarn.lock @@ -3999,6 +3999,11 @@ "@types/tapable" "*" "@types/webpack" "*" +"@types/http-errors@^1.6.3": + version "1.6.3" + resolved "https://registry.npmjs.org/@types/http-errors/-/http-errors-1.6.3.tgz#619a55768eab98299e8f76747339f3373f134e69" + integrity sha512-4KCE/agIcoQ9bIfa4sBxbZdnORzRjIw8JNQPLfqoNv7wQl/8f8mRbW68Q8wBsQFoJkPUHGlQYZ9sqi5WpfGSEQ== + "@types/http-proxy-middleware@*": version "0.19.3" resolved "https://registry.npmjs.org/@types/http-proxy-middleware/-/http-proxy-middleware-0.19.3.tgz#b2eb96fbc0f9ac7250b5d9c4c53aade049497d03" @@ -10795,17 +10800,7 @@ http-errors@1.7.2: statuses ">= 1.5.0 < 2" toidentifier "1.0.0" -http-errors@~1.6.2: - version "1.6.3" - resolved "https://registry.npmjs.org/http-errors/-/http-errors-1.6.3.tgz#8b55680bb4be283a0b5bf4ea2e38580be1d9320d" - integrity sha1-i1VoC7S+KDoLW/TqLjhYC+HZMg0= - dependencies: - depd "~1.1.2" - inherits "2.0.3" - setprototypeof "1.1.0" - statuses ">= 1.4.0 < 2" - -http-errors@~1.7.2: +http-errors@^1.7.3, http-errors@~1.7.2: version "1.7.3" resolved "https://registry.npmjs.org/http-errors/-/http-errors-1.7.3.tgz#6c619e4f9c60308c38519498c14fbb10aacebb06" integrity sha512-ZTTX0MWrsQ2ZAhA1cejAwDLycFsd7I7nVtnkT3Ol0aqodaKW+0CTZDQ1uBv5whptCnc8e8HeRRJxRs0kmm/Qfw== @@ -10816,6 +10811,16 @@ http-errors@~1.7.2: statuses ">= 1.5.0 < 2" toidentifier "1.0.0" +http-errors@~1.6.2: + version "1.6.3" + resolved "https://registry.npmjs.org/http-errors/-/http-errors-1.6.3.tgz#8b55680bb4be283a0b5bf4ea2e38580be1d9320d" + integrity sha1-i1VoC7S+KDoLW/TqLjhYC+HZMg0= + dependencies: + depd "~1.1.2" + inherits "2.0.3" + setprototypeof "1.1.0" + statuses ">= 1.4.0 < 2" + "http-parser-js@>=0.4.0 <0.4.11": version "0.4.10" resolved "https://registry.npmjs.org/http-parser-js/-/http-parser-js-0.4.10.tgz#92c9c1374c35085f75db359ec56cc257cbb93fa4"