Files
vercel__workflow/packages/utils/src/debug-log.test.ts
Pranay Prakash ffc58078d0 Stop logging on healthy workflow execution (#3878)
A successful run printed several lines that described the runtime working
correctly. Most of it was fallout from defaulting the events transport to
WebSockets (#3702): three breadcrumbs written while the transport was opt-in
became default-path output, because each one reported a choice the caller no
longer makes.

- `world-vercel: using ws events transport (…)` ran once per cold start on
  every deployment, naming the transport it was always going to use.
- The `projectConfig` proxy fallback warned once per process. That World cannot
  hold a socket, so with WS on by default every CLI command and the
  observability app warned about a fallback nobody asked for and nobody can act
  on. Debug-gated and reworded from "requested but" to "unavailable for".
- The `max_duration` / `auth_expiry` drain notice is routine: the transport
  reconnects from the close that follows and no write is lost.

Swept for the same shape elsewhere:

- `world-local`'s queue-concurrency notice fired per message once a fan-out
  exceeded the limit — the semaphore doing its job.
- `@workflow/world`'s active-run recovery line printed on every dev-server
  restart with work in flight. The re-enqueue *failure* above it stays
  unconditional; that one leaves a run unresumed.
- The port-detection diagnostics in `@workflow/utils` keyed off
  `NODE_ENV=development`, which is the only environment that reaches them, so
  the gate made them unconditional for their whole audience.

All of it moves behind `DEBUG=workflow:*` via a new `debugLog` in
`@workflow/utils`, joining world-vercel's existing `httpLog` and `logRetry`
output under one selector. Warnings and errors are untouched, so a run that
actually goes wrong is no quieter than before — the ws-transport tests that
assert failures are never silent still pass unchanged.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

Co-Authored-By: Pranay Prakash <1797812+pranaygp@users.noreply.github.com>
2026-08-27 20:45:20 -07:00

75 lines
2.1 KiB
TypeScript

import { afterEach, describe, expect, it, vi } from 'vitest';
import { debugLog, isWorkflowDebugEnabled } from './debug-log.js';
describe('isWorkflowDebugEnabled', () => {
afterEach(() => {
vi.unstubAllEnvs();
vi.restoreAllMocks();
});
it('is off when DEBUG is unset or empty', () => {
vi.stubEnv('DEBUG', undefined);
expect(isWorkflowDebugEnabled()).toBe(false);
vi.stubEnv('DEBUG', '');
expect(isWorkflowDebugEnabled()).toBe(false);
});
it('accepts the selectors a namespaced logger would match', () => {
for (const value of [
'workflow:*',
'*',
'workflow:runtime:debug',
'app:*,workflow:world-vercel:*',
]) {
vi.stubEnv('DEBUG', value);
expect(isWorkflowDebugEnabled(), value).toBe(true);
}
});
it("ignores another library's DEBUG selector", () => {
// A user debugging their own package must not be handed the SDK's
// transport breadcrumbs as well.
vi.stubEnv('DEBUG', 'express:*');
expect(isWorkflowDebugEnabled()).toBe(false);
});
it('re-reads DEBUG on every call', () => {
// Worlds are built long after import, so a value captured at module load
// answers for the wrong moment.
vi.stubEnv('DEBUG', '');
expect(isWorkflowDebugEnabled()).toBe(false);
vi.stubEnv('DEBUG', 'workflow:*');
expect(isWorkflowDebugEnabled()).toBe(true);
});
});
describe('debugLog', () => {
afterEach(() => {
vi.unstubAllEnvs();
vi.restoreAllMocks();
});
it('writes nothing at all when DEBUG is off', () => {
vi.stubEnv('DEBUG', '');
const spies = (['log', 'debug', 'info', 'warn', 'error'] as const).map(
(level) => vi.spyOn(console, level).mockImplementation(() => {})
);
debugLog('a breadcrumb', { runId: 'wrun_1' });
for (const spy of spies) expect(spy).not.toHaveBeenCalled();
});
it('forwards every argument to console.debug under DEBUG', () => {
vi.stubEnv('DEBUG', 'workflow:*');
const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {});
const detail = { runId: 'wrun_1' };
debugLog('a breadcrumb', detail);
expect(debugSpy).toHaveBeenCalledWith('a breadcrumb', detail);
});
});