Address comments

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}`);
 });
 ```
 

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",

packages/backend-common/src/index.ts

@@ -14,6 +14,5 @@
  * limitations under the License.
  */
 
-export * from './errors';
 export * from './logging';
 export * from './middleware';

packages/backend-common/src/logging/index.ts

@@ -14,4 +14,4 @@
  * limitations under the License.
  */
 
-export * from './logger';
+export * from './rootLogger';

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'),
+    );
+  });
+});

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;
 }

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());
 

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;

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();
   };
 }

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'),
+    );
   });
 });

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);
       },
     },
   });

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}`);
 });

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"