Repository: octokit/webhooks.js
Pull request #457 (2021-02-10 21:53:05)

feat(logging): add log option
I'd like to be able to redirect the log messages, so I added a `{ log }` option, consistent with the other `@octokit/*` packages, based on this feedback https://github.com/octokit/webhooks.js/pull/201#pullrequestreview-463894384

@oscard0m is already working on this in #201 (where there's existing discussion/feedback) and I'm happy to set the base branch of this PR to https://github.com/octokit/webhooks.js/tree/use-conole-log-level-package-instead-of-debug-package, however I think that branch has been removed.

If you resurrect that branch I'm happy to request pulling this PR into it. Whichever you prefer! I want to contribute to, not supersede, #201 :heart:


Patch:
diff --git a/jest.config.ts b/jest.config.ts
index 20f53a6..e1072d2 100644
--- a/jest.config.ts
+++ b/jest.config.ts
@@ -18,6 +18,7 @@ const config: Config.InitialOptions = {
     },
   },
   preset: "ts-jest",
+  restoreMocks: true,
   testEnvironment: "node",
   testRegex: /test\/.*\/.*.test.ts/u.source,
 };
diff --git a/src/event-handler/README.md b/src/event-handler/README.md
index 902ccf9..79255d8 100644
--- a/src/event-handler/README.md
+++ b/src/event-handler/README.md
@@ -37,6 +37,6 @@ if (!verify(secret, request.payload, request.headers['x-hub-signature'])) {
 
 ## API
 
-The `event-handler` API implements [`.receive()`](../#webhooksreceive), [`.on()`](../#webhookson) and [`.removeListener()`](../#webhooksremovelistener).
+The `event-handler` API implements [`.receive()`](../../README.md#webhooksreceive), [`.on()`](../../README.md#webhookson) and [`.removeListener()`](../../README.md#webhooksremovelistener).
 
-Back to [@octokit/webhooks README](..).
+Back to [@octokit/webhooks README](../../README.md).
diff --git a/src/event-handler/index.ts b/src/event-handler/index.ts
index 0150f9e..415e7ca 100644
--- a/src/event-handler/index.ts
+++ b/src/event-handler/index.ts
@@ -2,6 +2,7 @@ import type {
   EmitterWebhookEvent,
   EmitterWebhookEventName,
   HandlerFunction,
+  Logger,
   Options,
   State,
   WebhookEventHandlerError,
@@ -14,7 +15,7 @@ import {
 import { receiverHandle as receive } from "./receive";
 import { removeListener } from "./remove-listener";
 
-interface EventHandler<TTransformed = unknown> {
+interface EventHandler<TTransformed> {
   on<E extends EmitterWebhookEventName>(
     event: E | E[],
     callback: HandlerFunction<E, TTransformed>
@@ -28,9 +29,12 @@ interface EventHandler<TTransformed = unknown> {
   receive(event: EmitterWebhookEvent): Promise<void>;
 }
 
-export function createEventHandler(options: Options<any>): EventHandler {
+export function createEventHandler<TTransformed>(
+  options: Options<any, TTransformed>
+): EventHandler<TTransformed> {
   const state: State = {
     hooks: {},
+    log: createLogger(options.log),
   };
 
   if (options && options.transform) {
@@ -45,3 +49,13 @@ export function createEventHandler(options: Options<any>): EventHandler {
     receive: receive.bind(null, state),
   };
 }
+
+export function createLogger(logger?: Partial<Logger>) {
+  return {
+    debug: () => {},
+    info: /* istanbul ignore next: unused */ () => {},
+    warn: console.warn.bind(console),
+    error: console.error.bind(console),
+    ...logger,
+  };
+}
diff --git a/src/event-handler/on.ts b/src/event-handler/on.ts
index cf71049..36f4c0b 100644
--- a/src/event-handler/on.ts
+++ b/src/event-handler/on.ts
@@ -41,7 +41,7 @@ export function receiverOn(
   }
 
   if (emitterEventNames.indexOf(webhookNameOrNames) === -1) {
-    console.warn(
+    state.log.warn(
       `"${webhookNameOrNames}" is not a known webhook name (https://developer.github.com/v3/activity/events/types/)`
     );
   }
diff --git a/src/index.ts b/src/index.ts
index 8c645f5..68a29fe 100644
--- a/src/index.ts
+++ b/src/index.ts
@@ -1,5 +1,5 @@
 import { IncomingMessage, ServerResponse } from "http";
-import { createEventHandler } from "./event-handler/index";
+import { createEventHandler, createLogger } from "./event-handler/index";
 import { createMiddleware } from "./middleware/index";
 import { middleware } from "./middleware/middleware";
 import { verifyAndReceive } from "./middleware/verify-and-receive";
@@ -52,6 +52,7 @@ class Webhooks<
       path: options.path || "/",
       secret: options.secret,
       hooks: {},
+      log: createLogger(options.log),
     };
 
     this.sign = sign.bind(null, options.secret);
diff --git a/src/middleware/README.md b/src/middleware/README.md
index d562586..654045f 100644
--- a/src/middleware/README.md
+++ b/src/middleware/README.md
@@ -16,6 +16,6 @@ require('http').createServer(middleware).listen(3000)
 
 ## API
 
-The `middleware` API implements [`.on()`](../#webhookson) and [`.removeListener()`](../#webhooksremovelistener).
+The `middleware` API implements [`.on()`](../../README.md#webhookson) and [`.removeListener()`](../../README.md#webhooksremovelistener).
 
-Back to [@octokit/webhooks README](..).
+Back to [@octokit/webhooks README](../../README.md).
diff --git a/src/middleware/index.ts b/src/middleware/index.ts
index ccde621..a7fa093 100644
--- a/src/middleware/index.ts
+++ b/src/middleware/index.ts
@@ -1,4 +1,5 @@
-import { createEventHandler } from "../event-handler/index";
+import { debug } from "debug";
+import { createEventHandler, createLogger } from "../event-handler/index";
 import { middleware } from "./middleware";
 import { Options, State } from "../types";
 
@@ -12,6 +13,7 @@ export function createMiddleware(options: Options<any>) {
     path: options.path || "/",
     secret: options.secret,
     hooks: {},
+    log: createLogger(options.log || { debug: debug("webhooks:receiver") }),
   };
 
   const api: any = middleware.bind(null, state);
diff --git a/src/middleware/middleware.ts b/src/middleware/middleware.ts
index 46976b1..c32457a 100644
--- a/src/middleware/middleware.ts
+++ b/src/middleware/middleware.ts
@@ -3,12 +3,9 @@ import { isntWebhook } from "./isnt-webhook";
 import { getMissingHeaders } from "./get-missing-headers";
 import { getPayload } from "./get-payload";
 import { verifyAndReceive } from "./verify-and-receive";
-import { debug } from "debug";
 import { IncomingMessage, ServerResponse } from "http";
 import { State, WebhookEventHandlerError } from "../types";
 
-const debugWebhooks = debug("webhooks:receiver");
-
 export function middleware(
   state: State,
   request: IncomingMessage,
@@ -25,7 +22,7 @@ export function middleware(
       return;
     }
 
-    debugWebhooks(`ignored: ${request.method} ${request.url}`);
+    state.log.debug(`ignored: ${request.method} ${request.url}`);
     response.statusCode = 404;
     response.end("Not found");
     return;
@@ -48,7 +45,7 @@ export function middleware(
   const signatureSHA256 = request.headers["x-hub-signature-256"] as string;
   const id = request.headers["x-github-delivery"] as string;
 
-  debugWebhooks(`${eventName} event received (id: ${id})`);
+  state.log.debug(`${eventName} event received (id: ${id})`);
 
   // GitHub will abort the request if it does not receive a response within 10s
   // See https://github.com/octokit/webhooks.js/issues/185
diff --git a/src/sign/README.md b/src/sign/README.md
index 6759362..2a60cf3 100644
--- a/src/sign/README.md
+++ b/src/sign/README.md
@@ -53,4 +53,4 @@ const signature = sign({ secret, algorithm }, eventPayload)
 
 Returns a `signature` string. Throws error if required arguments are not passed.
 
-Back to [@octokit/webhooks README](..).
+Back to [@octokit/webhooks README](../../README.md).
diff --git a/src/types.ts b/src/types.ts
index 8bb122f..f6d24a3 100644
--- a/src/types.ts
+++ b/src/types.ts
@@ -27,6 +27,7 @@ export interface Options<
   path?: string;
   secret?: string;
   transform?: TransformMethod<T, TTransformed>;
+  log?: Partial<Logger>;
 }
 
 type TransformMethod<T extends EmitterWebhookEvent, V = T> = (
@@ -42,9 +43,17 @@ type Hooks = {
   [key: string]: Function[];
 };
 
+export interface Logger {
+  debug: (message: string) => unknown;
+  info: (message: string) => unknown;
+  warn: (message: string) => unknown;
+  error: (message: string) => unknown;
+}
+
 export interface State extends Options<any> {
   eventHandler?: any;
   hooks: Hooks;
+  log: Logger;
 }
 
 /**
diff --git a/src/verify/README.md b/src/verify/README.md
index de6e415..6badc60 100644
--- a/src/verify/README.md
+++ b/src/verify/README.md
@@ -53,4 +53,4 @@ const matchesSignature = verify(secret, eventPayload, signature)
 
 Returns `true` or `false`. Throws error if `secret`, `eventPayload` or `signature` not passed.
 
-Back to [@octokit/webhooks README](..).
+Back to [@octokit/webhooks README](../../README.md).


Test patch:
diff --git a/test/integration/middleware-test.ts b/test/integration/middleware-test.ts
index dad5c60..b5da700 100644
--- a/test/integration/middleware-test.ts
+++ b/test/integration/middleware-test.ts
@@ -33,7 +33,7 @@ test("Invalid payload", () => {
     statusCode: 0,
   };
 
-  const middleware = createMiddleware({ secret: "mysecret" });
+  const middleware = createMiddleware({ secret: "mysecret", log: {} });
   const middlewareDone = middleware(requestMock, responseMock).then(() => {
     expect(responseMock.statusCode).toBe(400);
     expect(responseMock.end).toHaveBeenCalledWith(
@@ -61,7 +61,7 @@ test("request error", () => {
     statusCode: 0,
   };
 
-  const middleware = createMiddleware({ secret: "mysecret" });
+  const middleware = createMiddleware({ secret: "mysecret", log: {} });
   const middlewareDone = middleware(requestMock, responseMock).then(() => {
     expect(responseMock.statusCode).toBe(500);
     expect(responseMock.end).toHaveBeenCalledWith(
diff --git a/test/unit/event-handler-on-test.ts b/test/unit/event-handler-on-test.ts
index f2d8313..cffbc06 100644
--- a/test/unit/event-handler-on-test.ts
+++ b/test/unit/event-handler-on-test.ts
@@ -5,6 +5,7 @@ function noop() {}
 
 const state: State = {
   hooks: {},
+  log: console,
 };
 
 beforeEach(() => jest.resetAllMocks());
diff --git a/test/unit/event-handler-receive-test.ts b/test/unit/event-handler-receive-test.ts
index 9c3415b..240566e 100644
--- a/test/unit/event-handler-receive-test.ts
+++ b/test/unit/event-handler-receive-test.ts
@@ -4,6 +4,7 @@ import { State } from "../../src/types";
 const state: State = {
   secret: "mysecret",
   hooks: {},
+  log: console,
 };
 
 test("options: none", () => {
diff --git a/test/unit/event-handler-remove-listener-test.ts b/test/unit/event-handler-remove-listener-test.ts
index 8fb23ec..231be65 100644
--- a/test/unit/event-handler-remove-listener-test.ts
+++ b/test/unit/event-handler-remove-listener-test.ts
@@ -8,10 +8,11 @@ test("remove-listener: single listener", () => {
     hooks: {
       push: [push],
     },
+    log: console,
   };
 
   expect(() => removeListener(state, "push", push)).not.toThrow();
-  expect(state).toStrictEqual({ hooks: { push: [] } });
+  expect(state).toStrictEqual({ hooks: { push: [] }, log: console });
 });
 
 test("remove-listener: multiple listeners", () => {
@@ -26,6 +27,7 @@ test("remove-listener: multiple listeners", () => {
       push: [push1, push2, push3],
       ping: [ping],
     },
+    log: console,
   };
 
   expect(() => {
@@ -33,5 +35,8 @@ test("remove-listener: multiple listeners", () => {
     removeListener(state, "push", push2);
     removeListener(state, "push", push3);
   }).not.toThrow();
-  expect(state).toStrictEqual({ hooks: { push: [], ping: [ping] } });
+  expect(state).toStrictEqual({
+    hooks: { push: [], ping: [ping] },
+    log: console,
+  });
 });
diff --git a/test/unit/middleware-test.ts b/test/unit/middleware-test.ts
index cf82910..e18147b 100644
--- a/test/unit/middleware-test.ts
+++ b/test/unit/middleware-test.ts
@@ -1,23 +1,27 @@
 import { IncomingMessage, ServerResponse } from "http";
 import { middleware } from "../../src/middleware/middleware";
-import { getMissingHeaders } from "../../src/middleware/get-missing-headers";
 import { getPayload } from "../../src/middleware/get-payload";
 import { verifyAndReceive } from "../../src/middleware/verify-and-receive";
 
-jest.mock("../../src/middleware/get-missing-headers");
 jest.mock("../../src/middleware/get-payload");
 jest.mock("../../src/middleware/verify-and-receive");
 
-const mockGetMissingHeaders = getMissingHeaders as jest.Mock;
 const mockGetPayload = getPayload as jest.Mock;
 const mockVerifyAndReceive = verifyAndReceive as jest.Mock;
 
+const headers = {
+  "x-github-delivery": "123e4567-e89b-12d3-a456-426655440000",
+  "x-github-event": "push",
+  "x-hub-signature": "sha1=f4d795e69b5d03c139cc6ea991ad3e5762d13e2f",
+};
+
 test("next() callback", () => {
   const next = jest.fn();
 
   middleware(
     {
       hooks: {},
+      log: console,
     },
     { method: "POST", url: "/foo" } as IncomingMessage,
     {} as ServerResponse,
@@ -33,20 +37,20 @@ describe("when does a timeout on retrieving the payload", () => {
   });
 
   test("successfully, does NOT response.end(ok)", async () => {
+    const consoleDebugSpy = jest.spyOn(console, "debug").mockImplementation();
     const responseMock = ({ end: jest.fn() } as unknown) as ServerResponse;
     const next = jest.fn();
 
-    mockGetMissingHeaders.mockReturnValueOnce([]);
     mockGetPayload.mockResolvedValueOnce(undefined);
     mockVerifyAndReceive.mockResolvedValueOnce(undefined);
 
     const promiseMiddleware = middleware(
-      { hooks: {}, path: "/foo" },
-      {
+      { hooks: {}, path: "/foo", log: console },
+      ({
         method: "POST",
         url: "/foo",
-        headers: {},
-      } as IncomingMessage,
+        headers,
+      } as unknown) as IncomingMessage,
       responseMock,
       next
     );
@@ -56,26 +60,30 @@ describe("when does a timeout on retrieving the payload", () => {
     await promiseMiddleware;
 
     expect(next).not.toHaveBeenCalled();
+    expect(consoleDebugSpy).toHaveBeenCalledTimes(1);
+    expect(consoleDebugSpy).toHaveBeenLastCalledWith(
+      "push event received (id: 123e4567-e89b-12d3-a456-426655440000)"
+    );
     expect(setTimeout).toHaveBeenCalledTimes(1);
     expect(responseMock.end).toHaveBeenCalledWith("still processing\n");
     expect(responseMock.end).not.toHaveBeenCalledWith("ok\n");
   });
 
   test("failing, does NOT response.end(ok)", async () => {
+    const consoleDebugSpy = jest.spyOn(console, "debug").mockImplementation();
     const responseMock = ({ end: jest.fn() } as unknown) as ServerResponse;
     const next = jest.fn();
 
-    mockGetMissingHeaders.mockReturnValueOnce([]);
     mockGetPayload.mockResolvedValueOnce(undefined);
     mockVerifyAndReceive.mockRejectedValueOnce(new Error("random error"));
 
     const promiseMiddleware = middleware(
-      { hooks: {}, path: "/foo" },
-      {
+      { hooks: {}, path: "/foo", log: console },
+      ({
         method: "POST",
         url: "/foo",
-        headers: {},
-      } as IncomingMessage,
+        headers,
+      } as unknown) as IncomingMessage,
       responseMock,
       next
     );
@@ -85,6 +93,10 @@ describe("when does a timeout on retrieving the payload", () => {
     await promiseMiddleware;
 
     expect(next).not.toHaveBeenCalled();
+    expect(consoleDebugSpy).toHaveBeenCalledTimes(1);
+    expect(consoleDebugSpy).toHaveBeenLastCalledWith(
+      "push event received (id: 123e4567-e89b-12d3-a456-426655440000)"
+    );
     expect(setTimeout).toHaveBeenCalledTimes(1);
     expect(responseMock.end).toHaveBeenCalledWith("still processing\n");
     expect(responseMock.end).not.toHaveBeenCalledWith(