fix(nextjs): Execute logger.commit() on every middleware invocation

We are using the `withLogger` wrapper to handle the logger.commit on
every time the wrapped function is executed.

In `clerkMiddleware` we are wrapping the whole function with the
`withLogger` instead of the returned nextMiddleware that is executed
in every request causing the `logger.commit()` to be executed once
during the initialization of the `clerkMiddleware()` (on 1st request).
To make debug logs working for `clerkMiddleware` on every request we
need to move the `withLogger` to wrap the returned middleware instead.

In `authMiddleware` we are wrapping the returned nextMiddleware which
makes the debugging logs works without any change.

Author: dimkl

packages/nextjs/src/server/__tests__/clerkMiddleware.test.ts

@@ -7,7 +7,9 @@ import { NextRequest, NextResponse } from 'next/server';
 
 const publishableKey = 'pk_test_Y2xlcmsuaW5jbHVkZWQua2F0eWRpZC05Mi5sY2wuZGV2JA';
 const authenticateRequestMock = jest.fn().mockResolvedValue({
-  toAuth: () => ({}),
+  toAuth: () => ({
+    debug: (d: any) => d,
+  }),
   headers: new Headers(),
   publishableKey,
 });
@@ -33,12 +35,15 @@ import { decryptClerkRequestData } from '../utils';
  * Disable console warnings about config matchers
  */
 const consoleWarn = console.warn;
-global.console.warn = jest.fn();
+const consoleLog = console.log;
+
 beforeAll(() => {
   global.console.warn = jest.fn();
+  global.console.log = jest.fn();
 });
 afterAll(() => {
   global.console.warn = consoleWarn;
+  global.console.log = consoleLog;
 });
 
 // Removing this mock will cause the clerkMiddleware tests to fail due to missing publishable key
@@ -168,24 +173,6 @@ describe('createRouteMatcher', () => {
   });
 });
 
-describe('authenticateRequest & handshake', () => {
-  beforeEach(() => {
-    authenticateRequestMock.mockClear();
-  });
-
-  it('returns 307 and starts the handshake flow for handshake requestState status', async () => {
-    const mockLocationUrl = 'https://example.com';
-    authenticateRequestMock.mockResolvedValueOnce({
-      publishableKey,
-      status: AuthStatus.Handshake,
-      headers: new Headers({ Location: mockLocationUrl }),
-    });
-    const resp = await clerkMiddleware()(mockRequest({ url: '/protected' }), {} as NextFetchEvent);
-    expect(resp?.status).toEqual(307);
-    expect(resp?.headers.get('Location')).toEqual(mockLocationUrl);
-  });
-});
-
 describe('clerkMiddleware(params)', () => {
   it('renders route as normally when used without params', async () => {
     const signInResp = await clerkMiddleware()(mockRequest({ url: '/sign-in' }), {} as NextFetchEvent);
@@ -203,7 +190,7 @@ describe('clerkMiddleware(params)', () => {
     expect(signInResp?.headers.get('a-custom-header')).toEqual('1');
   });
 
-  it('renders route when when exported directly without being called', async () => {
+  it('renders route when exported directly without being called', async () => {
     // This is equivalent to export default clerkMiddleware;
     const signInResp = await clerkMiddleware(mockRequest({ url: '/sign-in' }), {} as NextFetchEvent);
     expect(signInResp?.status).toEqual(200);
@@ -567,6 +554,32 @@ describe('clerkMiddleware(params)', () => {
       expect(clerkClient().authenticateRequest).toBeCalled();
     });
   });
+
+  describe('debug', () => {
+    beforeEach(() => {
+      (global.console.log as jest.Mock).mockClear();
+    });
+
+    it('outputs debug logs when used with only params', async () => {
+      const signInResp = await clerkMiddleware({ debug: true })(mockRequest({ url: '/sign-in' }), {} as NextFetchEvent);
+      expect(signInResp?.status).toEqual(200);
+      // 6 times results from header, footer, options, url, requestState, auth logs
+      expect(global.console.log).toBeCalledTimes(6);
+    });
+
+    it('outputs debug logs when used with a custom handler', async () => {
+      const signInResp = await clerkMiddleware(
+        (_, request) => {
+          expect(request.url).toContain('/sign-in');
+          return NextResponse.next({ headers: { 'a-custom-header': '1' } });
+        },
+        { debug: true },
+      )(mockRequest({ url: '/sign-in' }), {} as NextFetchEvent);
+      expect(signInResp?.status).toEqual(200);
+      // 6 times results from header, footer, options, url, requestState, auth logs
+      expect(global.console.log).toBeCalledTimes(6);
+    });
+  });
 });
 
 describe('Dev Browser JWT when redirecting to cross origin for page requests', function () {

packages/nextjs/src/server/clerkMiddleware.ts

@@ -73,12 +73,9 @@ interface ClerkMiddleware {
 
 export const clerkMiddlewareRequestDataStore = new AsyncLocalStorage<Partial<AuthenticateRequestOptions>>();
 
-export const clerkMiddleware: ClerkMiddleware = withLogger('clerkMiddleware', logger => (...args: unknown[]): any => {
+export const clerkMiddleware: ClerkMiddleware = (...args: unknown[]): any => {
   const [request, event] = parseRequestAndEvent(args);
   const [handler, params] = parseHandlerAndOptions(args);
-  if (params.debug) {
-    logger.enable();
-  }
 
   const publishableKey = assertKey(params.publishableKey || PUBLISHABLE_KEY, () =>
     errorThrower.throwMissingPublishableKeyError(),
@@ -104,7 +101,10 @@ export const clerkMiddleware: ClerkMiddleware = withLogger('clerkMiddleware', lo
       }),
     );
 
-    const nextMiddleware: NextMiddleware = async (request, event) => {
+    const nextMiddleware: NextMiddleware = withLogger('clerkMiddleware', logger => async (request, event) => {
+      if (params.debug) {
+        logger.enable();
+      }
       const clerkRequest = createClerkRequest(request);
       logger.debug('options', options);
       logger.debug('url', () => clerkRequest.toJSON());
@@ -164,7 +164,7 @@ export const clerkMiddleware: ClerkMiddleware = withLogger('clerkMiddleware', lo
       decorateRequest(clerkRequest, handlerResult, requestState, params);
 
       return handlerResult;
-    };
+    });
 
     // If we have a request and event, we're being called as a middleware directly
     // eg, export default clerkMiddleware;
@@ -176,7 +176,7 @@ export const clerkMiddleware: ClerkMiddleware = withLogger('clerkMiddleware', lo
     // eg, export default clerkMiddleware(auth => { ... });
     return nextMiddleware;
   });
-});
+};
 
 const parseRequestAndEvent = (args: unknown[]) => {
   return [args[0] instanceof Request ? args[0] : undefined, args[0] instanceof Request ? args[1] : undefined] as [