Skip to content

Commit 3e82fbe

Browse files
nikosdouvlisnikosdouvlis
committed
feat(nextjs): Add more middleware logs
chore(nextjs): Simplify logger creation chore(nextjs): Rename log to debug So it better conforms to common interfaces used by level-based loggers fix(nextjs): Split getAuth and auth In order to throw more targetted error messages feat(nextjs): Add more logs to authMiddleware feat(nextjs): Introduce a withLogger wrapper
1 parent 26d748f commit 3e82fbe

8 files changed

Lines changed: 284 additions & 35 deletions

File tree

‎packages/nextjs/src/app-router/server/auth.ts‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,12 @@
1-
import { buildClerkProps, getAuth } from '../../server/getAuth';
1+
import { authAuthHeaderMissing } from '../../server/errors';
2+
import { buildClerkProps, createGetAuth } from '../../server/getAuth';
23
import { buildRequestLike } from './utils';
34

45
export const auth = () => {
5-
return getAuth(buildRequestLike());
6+
return createGetAuth({
7+
debugLoggerName: 'auth()',
8+
noAuthStatusMessage: authAuthHeaderMissing(),
9+
})(buildRequestLike());
610
};
711

812
export const initialState = () => {

‎packages/nextjs/src/server/authMiddleware.ts‎

Lines changed: 22 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -4,13 +4,14 @@ import type Link from 'next/link';
44
import type { NextFetchEvent, NextMiddleware, NextRequest } from 'next/server';
55
import { NextResponse } from 'next/server';
66

7-
import { isRedirect, mergeResponses, paths, setHeader } from '../utils';
7+
import { isRedirect, mergeResponses, paths, setHeader, stringifyHeaders } from '../utils';
8+
import { withLogger } from '../utils/debugLogger';
89
import { authenticateRequest, handleInterstitialState, handleUnknownState } from './authenticateRequest';
910
import { SIGN_IN_URL, SIGN_UP_URL } from './clerkClient';
1011
import { receivedRequestForIgnoredRoute } from './errors';
1112
import { redirectToSignIn } from './redirect';
1213
import type { NextMiddlewareResult, WithAuthOptions } from './types';
13-
import { decorateRequest } from './utils';
14+
import { decorateRequest, setRequestHeadersOnNextResponse } from './utils';
1415

1516
type WithPathPatternWildcard<T> = `${T & string}(.*)`;
1617
type NextTypedRoute<T = Parameters<typeof Link>['0']['href']> = T extends string ? T : never;
@@ -100,41 +101,57 @@ const authMiddleware: AuthMiddleware = (...args: unknown[]) => {
100101
const isPublicRoute = createRouteMatcher(withDefaultPublicRoutes(publicRoutes));
101102
const defaultAfterAuth = createDefaultAfterAuth(isPublicRoute);
102103

103-
return async (req: NextRequest, evt: NextFetchEvent) => {
104+
return withLogger('authMiddleware', logger => async (req: NextRequest, evt: NextFetchEvent) => {
105+
if (options.debug) {
106+
logger.enable();
107+
}
108+
109+
logger.debug('URL debug', { url: req.nextUrl.href, method: req.method, headers: stringifyHeaders(req.headers) });
110+
logger.debug('Options debug', { ...options, beforeAuth: !!beforeAuth, afterAuth: !!afterAuth });
111+
104112
if (isIgnoredRoute(req)) {
113+
logger.debug({ isIgnoredRoute: true });
105114
console.warn(receivedRequestForIgnoredRoute(req.nextUrl.href, JSON.stringify(DEFAULT_CONFIG_MATCHER)));
106115
return setHeader(NextResponse.next(), constants.Headers.AuthReason, 'ignored-route');
107116
}
108117

109118
const beforeAuthRes = await (beforeAuth && beforeAuth(req, evt));
110119

111120
if (beforeAuthRes === false) {
121+
logger.debug('Before auth returned false, skipping');
112122
return setHeader(NextResponse.next(), constants.Headers.AuthReason, 'skip');
113123
} else if (beforeAuthRes && isRedirect(beforeAuthRes)) {
124+
logger.debug('Before auth returned redirect, following redirect');
114125
return setHeader(beforeAuthRes, constants.Headers.AuthReason, 'redirect');
115126
}
116127

117128
const requestState = await authenticateRequest(req, options);
118129
if (requestState.isUnknown) {
130+
logger.debug('authenticateRequest state is unknown', requestState);
119131
return handleUnknownState(requestState);
120132
} else if (requestState.isInterstitial) {
133+
logger.debug('authenticateRequest state is interstitial', requestState);
121134
return handleInterstitialState(requestState, options);
122135
}
123136

124137
const auth = Object.assign(requestState.toAuth(), { isPublicRoute: isPublicRoute(req) });
138+
logger.debug(() => ({ auth: JSON.stringify(auth) }));
125139
const afterAuthRes = await (afterAuth || defaultAfterAuth)(auth, req, evt);
126140
const finalRes = mergeResponses(beforeAuthRes, afterAuthRes) || NextResponse.next();
141+
logger.debug(() => ({ mergedHeaders: stringifyHeaders(finalRes.headers) }));
127142

128143
if (isRedirect(finalRes)) {
144+
logger.debug('Final response is redirect, following redirect');
129145
return setHeader(finalRes, constants.Headers.AuthReason, 'redirect');
130146
}
131147

132148
if (options.debug) {
133-
setHeader(finalRes, constants.Headers.EnableDebug, 'true');
149+
setRequestHeadersOnNextResponse(finalRes, req, { [constants.Headers.EnableDebug]: 'true' });
150+
logger.debug(`Added ${constants.Headers.EnableDebug} on request`);
134151
}
135152

136153
return decorateRequest(req, finalRes, requestState);
137-
};
154+
});
138155
};
139156

140157
export { authMiddleware };

‎packages/nextjs/src/server/errors.ts‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,3 +31,9 @@ export const config = {
3131
3232
If you intentionally want to run the authMiddleware for this route, you can exclude it from the default ignoredRoutes.
3333
`;
34+
35+
export const getAuthAuthHeaderMissing = () =>
36+
'You need to use "withClerkMiddleware" in your Next.js middleware file. You also need to make sure that your middleware matcher is configured correctly and matches this route or page. See https://clerk.com/docs/quickstarts/get-started-with-nextjs';
37+
38+
export const authAuthHeaderMissing = () =>
39+
"Clerk: auth() was called but it looks like you aren't using `authMiddleware` in your middleware file. Please use `authMiddleware` and make sure your middleware matcher is configured correctly and it matches this route or page. See https://clerk.com/docs/quickstarts/get-started-with-nextjs";

‎packages/nextjs/src/server/getAuth.ts‎

Lines changed: 50 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -10,42 +10,65 @@ import {
1010
} from '@clerk/backend';
1111
import type { SecretKeyOrApiKey } from '@clerk/types';
1212

13+
import { withLogger } from '../utils/debugLogger';
1314
import { API_KEY, API_URL, API_VERSION, SECRET_KEY } from './clerkClient';
15+
import { getAuthAuthHeaderMissing } from './errors';
1416
import type { RequestLike } from './types';
1517
import { getAuthKeyFromRequest, getCookie, getHeader, injectSSRStateIntoObject } from './utils';
1618

1719
type GetAuthOpts = Partial<SecretKeyOrApiKey>;
18-
export const getAuth = (req: RequestLike, opts?: GetAuthOpts): SignedInAuthObject | SignedOutAuthObject => {
19-
// When the auth status is set, we trust that the middleware has already run
20-
// Then, we don't have to re-verify the JWT here,
21-
// we can just strip out the claims manually.
22-
const authStatus = getAuthKeyFromRequest(req, 'AuthStatus');
23-
const authMessage = getAuthKeyFromRequest(req, 'AuthMessage');
24-
const authReason = getAuthKeyFromRequest(req, 'AuthReason');
2520

26-
if (!authStatus) {
27-
throw new Error(
28-
'You need to use "withClerkMiddleware" in your Next.js middleware file. You also need to make sure that your middleware matcher is configured correctly and matches this route or page. See https://clerk.com/docs/quickstarts/get-started-with-nextjs',
29-
);
30-
}
21+
export const createGetAuth = ({
22+
debugLoggerName,
23+
noAuthStatusMessage,
24+
}: {
25+
noAuthStatusMessage: string;
26+
debugLoggerName: string;
27+
}) =>
28+
withLogger(debugLoggerName, logger => {
29+
return (req: RequestLike, opts?: GetAuthOpts): SignedInAuthObject | SignedOutAuthObject => {
30+
const debug = getHeader(req, constants.Headers.EnableDebug) === 'true';
31+
if (debug) {
32+
logger.enable();
33+
}
3134

32-
const options = {
33-
apiKey: opts?.apiKey || API_KEY,
34-
secretKey: opts?.secretKey || SECRET_KEY,
35-
apiUrl: API_URL,
36-
apiVersion: API_VERSION,
37-
authStatus,
38-
authMessage,
39-
authReason,
40-
};
35+
// When the auth status is set, we trust that the middleware has already run
36+
// Then, we don't have to re-verify the JWT here,
37+
// we can just strip out the claims manually.
38+
const authStatus = getAuthKeyFromRequest(req, 'AuthStatus');
39+
const authMessage = getAuthKeyFromRequest(req, 'AuthMessage');
40+
const authReason = getAuthKeyFromRequest(req, 'AuthReason');
41+
logger.debug('Headers debug', { authStatus, authMessage, authReason });
4142

42-
if (authStatus !== AuthStatus.SignedIn) {
43-
return signedOutAuthObject(options);
44-
}
43+
if (!authStatus) {
44+
throw new Error(noAuthStatusMessage);
45+
}
4546

46-
const jwt = parseJwt(req);
47-
return signedInAuthObject(jwt.payload, { ...options, token: jwt.raw.text });
48-
};
47+
const options = {
48+
apiKey: opts?.apiKey || API_KEY,
49+
secretKey: opts?.secretKey || SECRET_KEY,
50+
apiUrl: API_URL,
51+
apiVersion: API_VERSION,
52+
authStatus,
53+
authMessage,
54+
authReason,
55+
};
56+
logger.debug('Options debug', options);
57+
58+
if (authStatus !== AuthStatus.SignedIn) {
59+
return signedOutAuthObject(options);
60+
}
61+
62+
const jwt = parseJwt(req);
63+
logger.debug('JWT debug', jwt.raw.text);
64+
return signedInAuthObject(jwt.payload, { ...options, token: jwt.raw.text });
65+
};
66+
});
67+
68+
export const getAuth = createGetAuth({
69+
debugLoggerName: 'getAuth()',
70+
noAuthStatusMessage: getAuthAuthHeaderMissing(),
71+
});
4972

5073
type BuildClerkPropsInitState = { user?: User | null; session?: Session | null; organization?: Organization | null };
5174

‎packages/nextjs/src/server/index.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
export * from './clerkClient';
2-
export * from './getAuth';
2+
export { buildClerkProps, getAuth } from './getAuth';
33
export * from './withClerkMiddleware';
44
export * from './redirect';
55

‎packages/nextjs/src/utils/debugLogger.test.ts‎

Lines changed: 114 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,114 @@
1+
import { expectTypeOf } from 'expect-type';
2+
3+
import { withLogger } from './debugLogger';
4+
5+
describe('withLogger', () => {
6+
let logger: any;
7+
8+
beforeEach(() => {
9+
logger = {
10+
enable: jest.fn(),
11+
log: jest.fn(),
12+
commit: jest.fn(),
13+
};
14+
});
15+
16+
it('should return the type of the passed handler', function () {
17+
type Options = { name: string; test: number };
18+
const handler = withLogger(
19+
() => logger,
20+
logger => (opts: Options) => {
21+
logger.commit();
22+
return opts.name;
23+
},
24+
);
25+
26+
expectTypeOf(handler).toMatchTypeOf<(opts: Options) => string>();
27+
});
28+
29+
it('should log upon return of a sync function', function () {
30+
const handler = withLogger(
31+
() => logger,
32+
logger => () => {
33+
logger.enable();
34+
logger.log('test');
35+
return 'test';
36+
},
37+
);
38+
expect(logger.enable).not.toHaveBeenCalled();
39+
expect(logger.log).not.toHaveBeenCalled();
40+
expect(logger.commit).not.toHaveBeenCalled();
41+
handler();
42+
expect(logger.enable).toHaveBeenCalled();
43+
expect(logger.log).toHaveBeenCalled();
44+
expect(logger.commit).toHaveBeenCalled();
45+
});
46+
47+
it('should log before an error is thrown inside of a sync function', function () {
48+
const handler = withLogger(
49+
() => logger,
50+
logger => () => {
51+
logger.enable();
52+
logger.log('test');
53+
throw new Error();
54+
},
55+
);
56+
expect(logger.enable).not.toHaveBeenCalled();
57+
expect(logger.log).not.toHaveBeenCalled();
58+
expect(logger.commit).not.toHaveBeenCalled();
59+
try {
60+
handler();
61+
} catch (e) {
62+
expect(e).toBeDefined();
63+
expect(logger.enable).toHaveBeenCalled();
64+
expect(logger.log).toHaveBeenCalled();
65+
expect(logger.commit).toHaveBeenCalled();
66+
}
67+
});
68+
69+
it('should log upon return of a async function', async function () {
70+
const handler = withLogger(
71+
() => logger,
72+
logger => async () => {
73+
logger.enable();
74+
logger.log('test');
75+
const res = await new Promise(resolve => {
76+
resolve('test');
77+
});
78+
return res;
79+
},
80+
);
81+
expect(logger.enable).not.toHaveBeenCalled();
82+
expect(logger.log).not.toHaveBeenCalled();
83+
expect(logger.commit).not.toHaveBeenCalled();
84+
await handler();
85+
expect(logger.enable).toHaveBeenCalled();
86+
expect(logger.log).toHaveBeenCalled();
87+
expect(logger.commit).toHaveBeenCalled();
88+
});
89+
90+
it('should log before an error is thrown inside of an async function', async function () {
91+
const handler = withLogger(
92+
() => logger,
93+
logger => async () => {
94+
logger.enable();
95+
logger.log('test');
96+
const res = await new Promise((_, reject) => {
97+
reject(new Error());
98+
});
99+
return res;
100+
},
101+
);
102+
expect(logger.enable).not.toHaveBeenCalled();
103+
expect(logger.log).not.toHaveBeenCalled();
104+
expect(logger.commit).not.toHaveBeenCalled();
105+
try {
106+
await handler();
107+
} catch (e) {
108+
expect(e).toBeDefined();
109+
expect(logger.enable).toHaveBeenCalled();
110+
expect(logger.log).toHaveBeenCalled();
111+
expect(logger.commit).toHaveBeenCalled();
112+
}
113+
});
114+
});

‎packages/nextjs/src/utils/debugLogger.ts‎

Lines changed: 73 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,73 @@
1+
// TODO: Replace with a more sophisticated logging solution
2+
3+
type Log = string | Record<string, unknown>;
4+
type Logger<L = Log> = {
5+
commit: () => void;
6+
debug: (...args: Array<L | (() => L)>) => void;
7+
enable: () => void;
8+
};
9+
10+
export const createDebugLogger = (name: string) => (): Logger => {
11+
type LogEntry = Log | Log[];
12+
const entries: LogEntry[] = [];
13+
let isEnabled = false;
14+
15+
const logEntry = (entry: LogEntry) => {
16+
return (Array.isArray(entry) ? entry : [entry]).map(e => JSON.stringify(e)).join(', ');
17+
};
18+
19+
return {
20+
enable: () => {
21+
isEnabled = true;
22+
},
23+
debug: (...args) => {
24+
if (isEnabled) {
25+
entries.push(args.map(arg => (typeof arg === 'function' ? arg() : arg)));
26+
}
27+
},
28+
commit: () => {
29+
if (isEnabled) {
30+
console.log(
31+
`Clerk debug start :: ${name}\n${entries
32+
.map(logEntry)
33+
.map(e => `-- ${e}\n`)
34+
.join('')}`,
35+
);
36+
}
37+
},
38+
};
39+
};
40+
41+
type WithLogger = <L extends Logger, H extends (...args: any[]) => any>(
42+
loggerFactoryOrName: string | (() => L),
43+
handlerCtor: (logger: Omit<L, 'commit'>) => H,
44+
) => H;
45+
46+
export const withLogger: WithLogger = (loggerFactoryOrName, handlerCtor) => {
47+
return ((...args: any) => {
48+
const factory =
49+
typeof loggerFactoryOrName === 'string' ? createDebugLogger(loggerFactoryOrName) : loggerFactoryOrName;
50+
const logger = factory();
51+
const handler = handlerCtor(logger as any);
52+
try {
53+
const res = handler(...args);
54+
if (typeof res === 'object' && 'then' in res && typeof res.then === 'function') {
55+
return res
56+
.then((val: any) => {
57+
logger.commit();
58+
return val;
59+
})
60+
.catch((err: any) => {
61+
logger.commit();
62+
throw err;
63+
});
64+
}
65+
// handle sync methods
66+
logger.commit();
67+
return res;
68+
} catch (err: any) {
69+
logger.commit();
70+
throw err;
71+
}
72+
}) as ReturnType<typeof handlerCtor>;
73+
};

0 commit comments

Comments
 (0)