Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions .changeset/capture-output-own-events.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
'evlog': patch
---

Fix `captureOutput` in `evlog/next/instrumentation` sending evlog's own events to drains a second time: in JSON mode, each wide event printed to stdout came back as a `log.info` event, and error events as `log.error` through stderr. evlog now marks its own writes so the capture passes them through.
5 changes: 5 additions & 0 deletions .changeset/next-instrumentation-bundling.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
'evlog': patch
---

Fix every route returning 500 with `Cannot find package 'evlog'` in a Next.js app built with Turbopack and deployed without `node_modules` (Vercel, `output: 'standalone'`) when root `instrumentation.ts` uses `defineNodeInstrumentation({ ... })`. The gate loaded `evlog/next/instrumentation/create` through a computed `import()` that the build left out of the output file trace. It now imports the module behind `process.env.NEXT_RUNTIME === 'nodejs'`, so Next.js bundles it into the Node.js build and drops it from the Edge build. With webpack, the module used to load unbundled from `node_modules`, where `NEXT_RUNTIME` is unset, so `captureOutput` never applied. It applies now.
2 changes: 1 addition & 1 deletion apps/docs/content/4.integrate/frameworks/02.nextjs.md
Original file line number Diff line number Diff line change
Expand Up @@ -154,7 +154,7 @@ Next.js automatically calls these exports:
- `onRequestError()`: Called on every unhandled request error. Emits a structured error log with the error message, digest, stack trace, request path/method, and routing context (`routerKind`, `routePath`, `routeType`, `renderSource`).

::callout{icon="i-lucide-info" color="info"}
`captureOutput` only activates in the Node.js runtime (`NEXT_RUNTIME === 'nodejs'`). It patches `process.stdout.write` and `process.stderr.write` to emit structured `log.info` / `log.error` events. When `silent` is `false` (the default), captured output is shown once as structured terminal output, and the raw write is not duplicated. Set `silent: true` to keep the original passthrough alongside drain delivery. Known Next.js Edge bundler warnings are filtered by default so they are not re-emitted as evlog errors.
`captureOutput` only activates in the Node.js runtime (`NEXT_RUNTIME === 'nodejs'`). It patches `process.stdout.write` and `process.stderr.write` to emit structured `log.info` / `log.error` events. When `silent` is `false` (the default), captured output is shown once as structured terminal output, and the raw write is not duplicated. evlog's own output passes through the capture, so a drain receives each wide event once. Set `silent: true` to keep the original passthrough alongside drain delivery. Known Next.js Edge bundler warnings are filtered by default so they are not re-emitted as evlog errors.
::

### Configuration
Expand Down
26 changes: 15 additions & 11 deletions packages/evlog/src/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -16,15 +16,20 @@ const nativeStdoutWrite =
? process.stdout.write.bind(process.stdout)
: undefined

/** Cross-bundle global slot for the native stdout write registered by captureOutput patching. */
/** Cross-bundle flag read by captureOutput patching. */
export interface EvlogProcessOutputGlobal {
__evlogNativeStdoutWrite?: typeof process.stdout.write
/** Set while evlog writes its own output, so captureOutput passes the write through. */
__evlogOwnOutput?: boolean
}

function writePrettyStdout(text: string): void {
function writeOwnOutput(write: () => void): void {
const global = globalThis as EvlogProcessOutputGlobal
const write = global.__evlogNativeStdoutWrite ?? nativeStdoutWrite
write?.(text)
global.__evlogOwnOutput = true
try {
write()
} finally {
global.__evlogOwnOutput = false
}
}

function isPlainObject(val: unknown): val is Record<string, unknown> {
Expand Down Expand Up @@ -348,9 +353,9 @@ export function outputWideEvent(event: WideEvent): void {
if (state.pretty) {
prettyPrintWideEvent(event)
} else if (state.stringify) {
console[getConsoleMethod(event.level)](JSON.stringify(event))
writeOwnOutput(() => console[getConsoleMethod(event.level)](JSON.stringify(event)))
} else {
console[getConsoleMethod(event.level)](event)
writeOwnOutput(() => console[getConsoleMethod(event.level)](event))
}
}

Expand Down Expand Up @@ -378,7 +383,7 @@ function emitTaggedLog(level: LogLevel, tag: string, message: string): void {
} else {
const color = getLevelColor(level)
const timestamp = isoNow().slice(11, 23)
console.log(`${colors.dim}${timestamp}${colors.reset} ${color}[${tag}]${colors.reset} ${message}`)
writeOwnOutput(() => console.log(`${colors.dim}${timestamp}${colors.reset} ${color}[${tag}]${colors.reset} ${message}`))
}

return
Expand Down Expand Up @@ -634,16 +639,15 @@ function buildAIEntries(ai: Record<string, unknown>): TreeEntry[] {

function flushPrettyLines(lines: string[]): void {
if (lines.length === 0) return
const text = `${lines.join('\n')}\n`
if (
nativeStdoutWrite
&& !isBrowser()
&& process.env.VITEST !== 'true'
) {
writePrettyStdout(text)
writeOwnOutput(() => nativeStdoutWrite(`${lines.join('\n')}\n`))
return
}
console.log(lines.join('\n'))
writeOwnOutput(() => console.log(lines.join('\n')))
}

function prettyPrintWideEvent(event: Record<string, unknown>): void {
Expand Down
7 changes: 6 additions & 1 deletion packages/evlog/src/next/instrumentation-create.ts
Original file line number Diff line number Diff line change
Expand Up @@ -150,6 +150,10 @@ function resolveCaptureOutputOptions(
}
}

function isEvlogOwnOutput(): boolean {
return (globalThis as EvlogProcessOutputGlobal).__evlogOwnOutput === true
}

function shouldIgnoreCapturedOutput(message: string, ignore: Array<string | RegExp>): boolean {
return ignore.some((pattern) => {
if (typeof pattern === 'string') return message.includes(pattern)
Expand All @@ -170,13 +174,13 @@ function applyCaptureOutput(config: CaptureOutputOptions, logApi: Log, silent: b

if (activeCaptureOutput.stdout && !stdoutPatched) {
const originalStdoutWrite = proc.stdout.write.bind(proc.stdout)
;(globalThis as EvlogProcessOutputGlobal).__evlogNativeStdoutWrite = originalStdoutWrite
stdoutPatched = true
proc.stdout.write = function(chunk: unknown, ...args: unknown[]): boolean {
const message = String(chunk).trimEnd()
const active = activeCaptureOutput
if (
!patching
&& !isEvlogOwnOutput()
&& message.length > 0
&& active?.stdout
&& !shouldIgnoreCapturedOutput(message, active.ignore)
Expand All @@ -203,6 +207,7 @@ function applyCaptureOutput(config: CaptureOutputOptions, logApi: Log, silent: b
const active = activeCaptureOutput
if (
!patching
&& !isEvlogOwnOutput()
&& message.length > 0
&& active?.stderr
&& !shouldIgnoreCapturedOutput(message, active.ignore)
Expand Down
18 changes: 7 additions & 11 deletions packages/evlog/src/next/instrumentation-gate.ts
Original file line number Diff line number Diff line change
Expand Up @@ -28,15 +28,6 @@ export interface NodeInstrumentationModule {
) => void | Promise<void>
}

type CreateInstrumentationModule = typeof import('./instrumentation-create')

/** @internal Non-literal specifier so Turbopack does not pull the logger into the Edge bundle. */
const CREATE_ENTRY = ['evlog', 'next', 'instrumentation', 'create'].join('/')

function importCreateModule(): Promise<CreateInstrumentationModule> {
return import(/* webpackIgnore: true */ CREATE_ENTRY) as Promise<CreateInstrumentationModule>
}

function isLoader(
value: (() => Promise<NodeInstrumentationModule>) | InstrumentationOptions,
): value is () => Promise<NodeInstrumentationModule> {
Expand All @@ -45,8 +36,13 @@ function isLoader(

function createOptionsLoader(options: InstrumentationOptions): () => Promise<NodeInstrumentationModule> {
return async () => {
const { createInstrumentation } = await importCreateModule()
return createInstrumentation(options)
// Next.js inlines NEXT_RUNTIME in every module it bundles: the Node.js build
// includes this import, the Edge build drops the branch with it.
if (process.env.NEXT_RUNTIME === 'nodejs') {
const { createInstrumentation } = await import('./instrumentation-create')
return createInstrumentation(options)
}
throw new Error('[evlog] createInstrumentation only runs in the Node.js runtime')
}
}

Expand Down
75 changes: 75 additions & 0 deletions packages/evlog/test/next/instrumentation-bundle.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,75 @@
import { execFile } from 'node:child_process'
import { existsSync } from 'node:fs'
import { mkdtemp, rm, writeFile } from 'node:fs/promises'
import { tmpdir } from 'node:os'
import { dirname, join } from 'node:path'
import { fileURLToPath, pathToFileURL } from 'node:url'
import { promisify } from 'node:util'
import { build } from 'esbuild'
import { afterAll, beforeAll, describe, expect, it } from 'vitest'
import { defined } from '../helpers/defined'

const execFileAsync = promisify(execFile)

const distDir = join(dirname(fileURLToPath(import.meta.url)), '../../dist')
const gateEntry = join(distDir, 'next/instrumentation.mjs')
const distExists = existsSync(gateEntry)

if (!distExists) {
console.warn('[evlog test] Skipping Next instrumentation bundle check: dist/ not found. Run `pnpm --filter evlog run build` first.')
}

/**
* Bundle a root `instrumentation.ts` the way Next.js does: `NEXT_RUNTIME` inlined,
* evlog bundled into the output, `next` provided by the host.
*/
async function bundleInstrumentation(runtime: 'nodejs' | 'edge'): Promise<string> {
const result = await build({
stdin: {
contents: [
`import { defineNodeInstrumentation } from ${JSON.stringify(gateEntry)}`,
`export const { register, onRequestError } = defineNodeInstrumentation({ service: 'bundle-check', silent: true })`,
].join('\n'),
resolveDir: distDir,
loader: 'js',
},
bundle: true,
write: false,
format: 'esm',
platform: runtime === 'nodejs' ? 'node' : 'neutral',
define: { 'process.env.NEXT_RUNTIME': JSON.stringify(runtime) },
external: ['next', 'next/*'],
logLevel: 'silent',
})
return defined(result.outputFiles[0], 'esbuild output').text
}

describe.skipIf(!distExists)('defineNodeInstrumentation in a Next.js bundle', () => {
let workDir: string

beforeAll(async () => {
workDir = await mkdtemp(join(tmpdir(), 'evlog-next-bundle-'))
})

afterAll(async () => {
await rm(workDir, { recursive: true, force: true })
})

it('Node.js bundle runs register() without evlog in node_modules', async () => {
const file = join(workDir, 'instrumentation.mjs')
await writeFile(file, await bundleInstrumentation('nodejs'))

const script = `const m = await import(${JSON.stringify(pathToFileURL(file).href)}); await m.register(); console.log('registered')`
const { stdout } = await execFileAsync(process.execPath, ['--input-type=module', '-e', script], { cwd: workDir })

expect(stdout.trim()).toBe('registered')
})

it('Edge bundle leaves the logger out', async () => {
const code = await bundleInstrumentation('edge')

expect(code).toContain('function defineNodeInstrumentation(')
expect(code).not.toContain('function initLogger(')
expect(code).not.toContain('function createInstrumentation(')
})
})
65 changes: 65 additions & 0 deletions packages/evlog/test/next/instrumentation.test.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,6 @@
import { Console } from 'node:console'
import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'
import { waitForDrainCalls } from '../helpers/framework'

// Mock next/server to prevent import errors
vi.mock('next/server', () => ({ after: undefined }))
Expand Down Expand Up @@ -71,6 +73,25 @@ describe('createInstrumentation', () => {
await register()
}

/** Replace stdout/stderr with collectors and route `console` through them, as Node's console does outside Vitest. */
function collectProcessOutput() {
const stdout: string[] = []
const stderr: string[] = []
process.stdout.write = function(chunk: unknown) {
stdout.push(String(chunk))
return true
} as typeof process.stdout.write
process.stderr.write = function(chunk: unknown) {
stderr.push(String(chunk))
return true
} as typeof process.stderr.write
const nodeConsole = new Console({ stdout: process.stdout, stderr: process.stderr })
for (const method of ['log', 'info', 'warn', 'error'] as const) {
vi.spyOn(console, method).mockImplementation((...args: unknown[]) => nodeConsole[method](...args))
}
return { stdout, stderr }
}

it('register() calls initLogger() with correct config', async () => {
const createInstrumentation = await loadModule()
const drainMock = vi.fn()
Expand Down Expand Up @@ -414,6 +435,50 @@ describe('createInstrumentation', () => {
expect(logErrorSpy).not.toHaveBeenCalled()
})

it('captureOutput passes evlog JSON events through instead of capturing them again', async () => {
const createInstrumentation = await loadModule()
process.env.NEXT_RUNTIME = 'nodejs'
const output = collectProcessOutput()
const drain = vi.fn()

const { register } = createInstrumentation({ service: 'factory', pretty: false, captureOutput: true, drain })
await runRegister(register)

const { createLogger } = await import('../../src/logger')
createLogger({ path: '/api/github/webhook' }).emit()
const failing = createLogger({ path: '/api/github/webhook' })
failing.error(new Error('boom'))
failing.emit()

await waitForDrainCalls(drain, 2)
expect(drain.mock.calls.map(([ctx]) => [ctx.event.level, ctx.event.path, ctx.event.source])).toEqual([
['info', '/api/github/webhook', undefined],
['error', '/api/github/webhook', undefined],
])
expect(logInfoSpy).not.toHaveBeenCalled()
expect(logErrorSpy).not.toHaveBeenCalled()
expect(output.stdout.map(line => JSON.parse(line))).toMatchObject([{ level: 'info', path: '/api/github/webhook' }])
expect(output.stderr.map(line => JSON.parse(line))).toMatchObject([{ level: 'error', path: '/api/github/webhook' }])
})

it('captureOutput passes evlog pretty output and tagged logs through', async () => {
const createInstrumentation = await loadModule()
process.env.NEXT_RUNTIME = 'nodejs'
const output = collectProcessOutput()

const { register } = createInstrumentation({ service: 'factory', pretty: true, captureOutput: true })
await runRegister(register)

const { createLogger, log } = await import('../../src/logger')
createLogger({ path: '/api/github/webhook' }).emit()
log.info('auth', 'User logged in')

expect(logInfoSpy.mock.calls).toEqual([['auth', 'User logged in']])
expect(output.stdout.join('')).toContain('/api/github/webhook')
expect(output.stdout.join('')).toContain('[auth]')
expect(output.stdout.join('')).not.toContain('source')
})

it('captureOutput uses the latest registration filters without re-wrapping', async () => {
const createInstrumentation = await loadModule()
process.env.NEXT_RUNTIME = 'nodejs'
Expand Down
Loading