From f8b3f3c0344a17a5330ad5b3581978c7d638fbcb Mon Sep 17 00:00:00 2001 From: Bryce Kalow Date: Wed, 11 Oct 2023 21:46:44 -0500 Subject: [PATCH 1/5] feat(nextjs): Improve debug logging, use individual console.log calls to avoid platform limitations --- packages/nextjs/src/utils/debugLogger.ts | 40 +++++++++++++++++++----- 1 file changed, 32 insertions(+), 8 deletions(-) diff --git a/packages/nextjs/src/utils/debugLogger.ts b/packages/nextjs/src/utils/debugLogger.ts index 6c8dd7d927b..d2ddab16040 100644 --- a/packages/nextjs/src/utils/debugLogger.ts +++ b/packages/nextjs/src/utils/debugLogger.ts @@ -1,5 +1,7 @@ // TODO: Replace with a more sophisticated logging solution +import nextPkg from 'next/package.json'; + import { logFormatter } from './logFormatter'; export type Log = string | Record; @@ -25,15 +27,29 @@ export const createDebugLogger = (name: string, formatter: (val: LogEntry) => st }, commit: () => { if (isEnabled) { - const log = `Clerk debug start :: ${name}\n${entries - .map(log => formatter(log)) - .map(e => `-- ${e}\n`) - .join('')}`; - if (process.env.VERCEL) { - console.log(truncate(log, 4096)); - } else { - console.log(log); + console.log(debugLogHeader(name)); + + /** + * We buffer each collected log entry so we can format them and log them all at once. + * Individual console.log calls are used to ensure we don't hit platform-specific log limits (Vercel and Netlify are 4kb). + */ + for (const log of entries) { + let output = formatter(log); + + output = output + .split('\n') + .map(l => ` ${l}`) + .join('\n'); + + // Vercel errors if the output is > 4kb, so we truncate it + if (process.env.VERCEL) { + output = truncate(output, 4096); + } + + console.log(output); } + + console.log(debugLogFooter(name)); } }, }; @@ -77,6 +93,14 @@ export const withLogger: WithLogger = (loggerFactoryOrName, handlerCtor) => { }) as ReturnType; }; +function debugLogHeader(name: string) { + return `[clerk debug start: ${name}]`; +} + +function debugLogFooter(name: string) { + return `[clerk debug end: ${name}] (@clerk/nextjs=${PACKAGE_VERSION},next=${nextPkg.version})`; +} + // ref: https://stackoverflow.com/questions/57769465/javascript-truncate-text-by-bytes-length function truncate(str: string, maxLength: number) { const encoder = new TextEncoder(); From f6688beb5ae5e9859512b1301839140adc4564c0 Mon Sep 17 00:00:00 2001 From: Bryce Kalow Date: Wed, 11 Oct 2023 21:51:02 -0500 Subject: [PATCH 2/5] chore(repo): Add changeset --- .changeset/tough-masks-knock.md | 5 +++++ 1 file changed, 5 insertions(+) create mode 100644 .changeset/tough-masks-knock.md diff --git a/.changeset/tough-masks-knock.md b/.changeset/tough-masks-knock.md new file mode 100644 index 00000000000..82f4adbd159 --- /dev/null +++ b/.changeset/tough-masks-knock.md @@ -0,0 +1,5 @@ +--- +'@clerk/nextjs': patch +--- + +Improves the debug log output, and changes the internal behavior to use multiple `console.log()` calls. This will help to avoid any platform logging limitations per call. From 3888ef59068a98b85223e1d6403aac5ea147dbcc Mon Sep 17 00:00:00 2001 From: Bryce Kalow Date: Wed, 11 Oct 2023 21:57:15 -0500 Subject: [PATCH 3/5] chore(nextjs): Fix tests --- packages/nextjs/jest.config.js | 3 +++ packages/nextjs/src/utils/debugLogger.test.ts | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/nextjs/jest.config.js b/packages/nextjs/jest.config.js index 6ec859b3bf8..6a91935b956 100644 --- a/packages/nextjs/jest.config.js +++ b/packages/nextjs/jest.config.js @@ -1,5 +1,8 @@ /** @type {import('ts-jest').JestConfigWithTsJest} */ module.exports = { + globals: { + PACKAGE_VERSION: '0.0.0-test', + }, displayName: 'nextjs', injectGlobals: true, roots: ['/src'], diff --git a/packages/nextjs/src/utils/debugLogger.test.ts b/packages/nextjs/src/utils/debugLogger.test.ts index 7d8cfc8347c..f70b9824c22 100644 --- a/packages/nextjs/src/utils/debugLogger.test.ts +++ b/packages/nextjs/src/utils/debugLogger.test.ts @@ -125,7 +125,7 @@ describe('withLogger', () => { logger.debug(veryLongString); }); handler(); - expect(log.mock.calls[0][0]).toHaveLength(4096); + expect(log.mock.calls[1][0]).toHaveLength(4096); // restore original console log and reset environment value process.env.VERCEL = undefined; From bb38a2e56c6dc2589ed33c97f2faeda08e7ad362 Mon Sep 17 00:00:00 2001 From: Bryce Kalow Date: Thu, 12 Oct 2023 09:25:44 -0500 Subject: [PATCH 4/5] chore(nextjs): Adjust test to validate each log line --- packages/nextjs/src/utils/debugLogger.test.ts | 6 +++++- playground/app-router/src/app/layout.tsx | 5 +++-- playground/app-router/src/middleware.ts | 2 +- 3 files changed, 9 insertions(+), 4 deletions(-) diff --git a/packages/nextjs/src/utils/debugLogger.test.ts b/packages/nextjs/src/utils/debugLogger.test.ts index f70b9824c22..7cb3e72763d 100644 --- a/packages/nextjs/src/utils/debugLogger.test.ts +++ b/packages/nextjs/src/utils/debugLogger.test.ts @@ -123,9 +123,13 @@ describe('withLogger', () => { const handler = withLogger('test-logger', logger => () => { logger.enable(); logger.debug(veryLongString); + logger.debug(veryLongString); }); handler(); - expect(log.mock.calls[1][0]).toHaveLength(4096); + + for (const mockCall of log.mock.calls) { + expect(mockCall[0].length).toBeLessThanOrEqual(4096); + } // restore original console log and reset environment value process.env.VERCEL = undefined; diff --git a/playground/app-router/src/app/layout.tsx b/playground/app-router/src/app/layout.tsx index c90b61270fd..98dd8990cbe 100644 --- a/playground/app-router/src/app/layout.tsx +++ b/playground/app-router/src/app/layout.tsx @@ -2,6 +2,7 @@ import './globals.css'; import { Inter } from 'next/font/google'; import { ClerkProvider } from '@clerk/nextjs'; import { Links } from '@/common/Links'; +import { Provider } from './provider'; const inter = Inter({ subsets: ['latin'] }); @@ -13,7 +14,7 @@ export const metadata = { export default function RootLayout({ children }: { children: React.ReactNode }) { // console.log(auth()); return ( - + @@ -23,6 +24,6 @@ export default function RootLayout({ children }: { children: React.ReactNode }) - + ); } diff --git a/playground/app-router/src/middleware.ts b/playground/app-router/src/middleware.ts index 29719011a9e..d32c935b690 100644 --- a/playground/app-router/src/middleware.ts +++ b/playground/app-router/src/middleware.ts @@ -23,7 +23,7 @@ export default authMiddleware({ res.headers.set('x-after-auth', 'true'); return res; }, - debug: true + // debug: true }); export const config = { From 27df664a3799b314f93f75f1dfeac867dce33f50 Mon Sep 17 00:00:00 2001 From: Bryce Kalow Date: Thu, 12 Oct 2023 09:30:45 -0500 Subject: [PATCH 5/5] chore(repo): Undo changes to playground --- playground/app-router/src/app/layout.tsx | 5 ++--- playground/app-router/src/middleware.ts | 2 +- 2 files changed, 3 insertions(+), 4 deletions(-) diff --git a/playground/app-router/src/app/layout.tsx b/playground/app-router/src/app/layout.tsx index 98dd8990cbe..c90b61270fd 100644 --- a/playground/app-router/src/app/layout.tsx +++ b/playground/app-router/src/app/layout.tsx @@ -2,7 +2,6 @@ import './globals.css'; import { Inter } from 'next/font/google'; import { ClerkProvider } from '@clerk/nextjs'; import { Links } from '@/common/Links'; -import { Provider } from './provider'; const inter = Inter({ subsets: ['latin'] }); @@ -14,7 +13,7 @@ export const metadata = { export default function RootLayout({ children }: { children: React.ReactNode }) { // console.log(auth()); return ( - + @@ -24,6 +23,6 @@ export default function RootLayout({ children }: { children: React.ReactNode }) - + ); } diff --git a/playground/app-router/src/middleware.ts b/playground/app-router/src/middleware.ts index d32c935b690..29719011a9e 100644 --- a/playground/app-router/src/middleware.ts +++ b/playground/app-router/src/middleware.ts @@ -23,7 +23,7 @@ export default authMiddleware({ res.headers.set('x-after-auth', 'true'); return res; }, - // debug: true + debug: true }); export const config = {