Backend Logging System #

Overview #

The backend adapter communicates with the Fyrox frontend via JSON-lines over stdin/stdout. This creates a critical constraint: stdout is reserved exclusively for IPC messages. Any non-JSON output to stdout will break the protocol and cause parse errors on the frontend.

This document defines a logging system that prevents accidental stdout pollution while providing structured, debuggable logs.

Problem Statement #

The stdout Trap #

// THIS IS DANGEROUS - breaks IPC protocol!
console.log('[Debug] Processing message...');

// Frontend tries to parse this as JSON:
// Error: expected value at line 1 column 2

Common sources of stdout pollution:

1. console.log() calls (should be console.error())
2. Libraries that log to stdout by default
3. Uncaught exceptions printed to stdout
4. Debug statements left in production code

Requirements #

1. Hard stdout protection: Make it impossible to accidentally write to stdout
2. Structured logging: JSON-formatted logs with levels, timestamps, context
3. Log levels: trace, debug, info, warn, error
4. Performance: Minimal overhead, async-safe
5. Testability: Logs can be captured and asserted in tests
6. Source tracking: Know which module emitted each log

Design #

Architecture #

┌─────────────────────────────────────────────────────────┐
│                    Backend Process                       │
├─────────────────────────────────────────────────────────┤
│                                                          │
│  ┌──────────────┐     ┌──────────────┐                  │
│  │  IPC Module  │────►│    stdout    │  (JSON-lines)    │
│  └──────────────┘     └──────────────┘                  │
│                                                          │
│  ┌──────────────┐     ┌──────────────┐                  │
│  │    Logger    │────►│    stderr    │  (structured)    │
│  └──────────────┘     └──────────────┘                  │
│         ▲                                                │
│         │                                                │
│  ┌──────┴───────┬───────────────┬──────────────┐       │
│  │ sdk-adapter  │  oauth-manager │    proxy     │       │
│  └──────────────┴───────────────┴──────────────┘       │
│                                                          │
└─────────────────────────────────────────────────────────┘

Logger API #

// packages/logger/src/index.ts

export type LogLevel = 'trace' | 'debug' | 'info' | 'warn' | 'error';

export interface LogContext {
  module?: string;
  [key: string]: unknown;
}

export interface Logger {
  trace(message: string, context?: LogContext): void;
  debug(message: string, context?: LogContext): void;
  info(message: string, context?: LogContext): void;
  warn(message: string, context?: LogContext): void;
  error(message: string, context?: LogContext): void;

  // Create a child logger with preset context
  child(context: LogContext): Logger;
}

// Factory function
export function createLogger(module: string): Logger;

// Global configuration
export function configureLogging(options: {
  level?: LogLevel;
  format?: 'json' | 'pretty';
}): void;

Usage #

// In sdk-adapter.ts
import { createLogger } from '@tiny-workshop/logger';

const log = createLogger('sdk-adapter');

log.info('Initializing SDK adapter');
log.debug('OAuth proxy started', { port: 12345 });
log.error('Failed to exchange code', { error: err.message });

// Child loggers for subsystems
const queryLog = log.child({ subsystem: 'query' });
queryLog.info('Starting query', { sessionId: '123' });

Output Format #

JSON Format (default for production) #

{"ts":"2025-01-04T12:00:00.000Z","level":"info","module":"sdk-adapter","msg":"OAuth proxy started","port":12345}
{"ts":"2025-01-04T12:00:01.000Z","level":"error","module":"proxy","msg":"Request failed","error":"ConnectionRefused","url":"https://api.anthropic.com/v1/messages"}

Pretty Format (for development) #

12:00:00.000 INFO  [sdk-adapter] OAuth proxy started port=12345
12:00:01.000 ERROR [proxy] Request failed error=ConnectionRefused url=https://api.anthropic.com/v1/messages

Implementation #

// packages/logger/src/index.ts

const LOG_LEVELS: Record<LogLevel, number> = {
  trace: 0,
  debug: 1,
  info: 2,
  warn: 3,
  error: 4,
};

let currentLevel: LogLevel = 'info';
let format: 'json' | 'pretty' = 'json';

export function configureLogging(options: {
  level?: LogLevel;
  format?: 'json' | 'pretty';
}): void {
  if (options.level) currentLevel = options.level;
  if (options.format) format = options.format;
}

function shouldLog(level: LogLevel): boolean {
  return LOG_LEVELS[level] >= LOG_LEVELS[currentLevel];
}

function formatMessage(
  level: LogLevel,
  module: string,
  message: string,
  context?: LogContext
): string {
  const ts = new Date().toISOString();

  if (format === 'json') {
    return JSON.stringify({
      ts,
      level,
      module,
      msg: message,
      ...context,
    });
  }

  // Pretty format
  const time = ts.split('T')[1].replace('Z', '');
  const levelStr = level.toUpperCase().padEnd(5);
  const contextStr = context
    ? ' ' + Object.entries(context)
        .filter(([k]) => k !== 'module')
        .map(([k, v]) => `${k}=${v}`)
        .join(' ')
    : '';

  return `${time} ${levelStr} [${module}] ${message}${contextStr}`;
}

function write(
  level: LogLevel,
  module: string,
  message: string,
  context?: LogContext
): void {
  if (!shouldLog(level)) return;

  const formatted = formatMessage(level, module, message, context);

  // CRITICAL: Always write to stderr, never stdout!
  console.error(formatted);
}

class LoggerImpl implements Logger {
  constructor(
    private module: string,
    private baseContext: LogContext = {}
  ) {}

  trace(message: string, context?: LogContext): void {
    write('trace', this.module, message, { ...this.baseContext, ...context });
  }

  debug(message: string, context?: LogContext): void {
    write('debug', this.module, message, { ...this.baseContext, ...context });
  }

  info(message: string, context?: LogContext): void {
    write('info', this.module, message, { ...this.baseContext, ...context });
  }

  warn(message: string, context?: LogContext): void {
    write('warn', this.module, message, { ...this.baseContext, ...context });
  }

  error(message: string, context?: LogContext): void {
    write('error', this.module, message, { ...this.baseContext, ...context });
  }

  child(context: LogContext): Logger {
    return new LoggerImpl(this.module, { ...this.baseContext, ...context });
  }
}

export function createLogger(module: string): Logger {
  return new LoggerImpl(module);
}

Stdout Protection #

To prevent accidental stdout usage, we can optionally patch console.log:

// packages/logger/src/protect-stdout.ts

const originalLog = console.log;
let stdoutProtectionEnabled = false;

export function enableStdoutProtection(): void {
  if (stdoutProtectionEnabled) return;

  console.log = (...args: unknown[]) => {
    // In development, warn loudly
    if (process.env.NODE_ENV !== 'production') {
      console.error(
        '[STDOUT PROTECTION] console.log() called! Use logger instead:',
        ...args
      );
      console.error(new Error().stack);
    }

    // In production, silently redirect to stderr
    console.error('[REDIRECTED]', ...args);
  };

  stdoutProtectionEnabled = true;
}

export function disableStdoutProtection(): void {
  console.log = originalLog;
  stdoutProtectionEnabled = false;
}

Initialization #

// packages/adapter/src/index.ts

import { configureLogging, createLogger } from '@tiny-workshop/logger';
import { enableStdoutProtection } from '@tiny-workshop/logger/protect-stdout';

// First thing: protect stdout
enableStdoutProtection();

// Configure logging based on environment
configureLogging({
  level: process.env.LOG_LEVEL as LogLevel ?? 'info',
  format: process.env.NODE_ENV === 'development' ? 'pretty' : 'json',
});

const log = createLogger('main');
log.info('Backend adapter starting');

Package Structure #

backend/
└── packages/
    └── logger/
        ├── package.json
        ├── src/
        │   ├── index.ts           # Main logger API
        │   ├── protect-stdout.ts  # Stdout protection
        │   └── types.ts           # Type definitions
        └── tests/
            └── logger.test.ts

package.json #

{
  "name": "@tiny-workshop/logger",
  "version": "0.1.0",
  "type": "module",
  "exports": {
    ".": "./src/index.ts",
    "./protect-stdout": "./src/protect-stdout.ts"
  },
  "devDependencies": {
    "typescript": "^5.0.0"
  }
}

Integration with Existing Code #

Migration Path #

1. Create logger package with the API above
2. Add stdout protection to adapter entry point
3. Replace console.error calls with logger calls:

// Before
console.error('[Auth] OAuth proxy started on port', port);

// After
import { createLogger } from '@tiny-workshop/logger';
const log = createLogger('auth');
log.info('OAuth proxy started', { port });

4. Update proxy.ts to use logger
5. Update sdk-adapter.ts to use logger
6. Update ipc.ts to use logger (but keep emit() using stdout!)

IPC Module Exception #

The ipc.ts module is the ONLY code allowed to write to stdout:

// packages/adapter/src/ipc.ts
import { createLogger } from '@tiny-workshop/logger';

const log = createLogger('ipc');

export function emit(message: BackendMessage): void {
  // This is the ONLY place stdout is used
  const json = JSON.stringify(message);
  process.stdout.write(json + '\n');

  // Log what we emitted (to stderr via logger)
  log.debug('Emitted message', { type: message.type });
}

Testing #

// packages/logger/tests/logger.test.ts
import { describe, it, expect, beforeEach, afterEach } from 'bun:test';
import { createLogger, configureLogging } from '../src';

describe('Logger', () => {
  let stderrOutput: string[] = [];
  const originalStderr = process.stderr.write;

  beforeEach(() => {
    stderrOutput = [];
    process.stderr.write = (chunk: string) => {
      stderrOutput.push(chunk.toString());
      return true;
    };
  });

  afterEach(() => {
    process.stderr.write = originalStderr;
  });

  it('writes to stderr, not stdout', () => {
    const log = createLogger('test');
    log.info('Hello');

    expect(stderrOutput.length).toBe(1);
    expect(stderrOutput[0]).toContain('Hello');
  });

  it('respects log levels', () => {
    configureLogging({ level: 'warn' });
    const log = createLogger('test');

    log.debug('Should not appear');
    log.warn('Should appear');

    expect(stderrOutput.length).toBe(1);
    expect(stderrOutput[0]).toContain('Should appear');
  });

  it('includes context in output', () => {
    configureLogging({ format: 'json' });
    const log = createLogger('test');

    log.info('Test', { userId: 123 });

    const parsed = JSON.parse(stderrOutput[0]);
    expect(parsed.userId).toBe(123);
  });
});

Environment Variables #

Variable	Values	Default	Description
LOG_LEVEL	trace, debug, info, warn, error	info	Minimum log level
LOG_FORMAT	json, pretty	json	Output format
PROTECT_STDOUT	true, false	true	Enable stdout protection

Future Enhancements #

1. File logging: Write logs to file in addition to stderr
2. Log rotation: Rotate log files by size/time
3. Remote logging: Send logs to external service
4. Correlation IDs: Track requests across async boundaries
5. Performance metrics: Log timing information automatically
6. Sampling: Reduce log volume in high-traffic scenarios

Open Questions #

1. Should we use an existing logging library? (e.g., pino, winston)

   • Pro: Battle-tested, feature-rich
   • Con: May write to stdout by default, needs configuration

2. Should logs include stack traces for errors?

   • Pro: Easier debugging
   • Con: Verbose, may leak sensitive info

3. How to handle logs from dependencies?

   • Some npm packages log to stdout/stderr directly
   • May need to patch or configure them

Summary #

This logging system provides:

• Safety: stdout is protected, all debug output goes to stderr
• Structure: JSON-formatted logs with consistent schema
• Flexibility: Log levels, formats, child loggers
• Debuggability: Module names, timestamps, context data
• Testability: Logs can be captured and asserted

The key invariant: stdout is sacred - only IPC JSON messages go there.