# 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

```typescript
// 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

```typescript
// 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

```typescript
// 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)

```json
{"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

```typescript
// 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`:

```typescript
// 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

```typescript
// 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

```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:

```typescript
// 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:

```typescript
// 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

```typescript
// 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.