Debugging Tips

Master the art of debugging with these patterns and best practices.

Strategic Logging

Log at Entry and Exit Points

import { log } from 'logluxe';

function processOrder(order: Order) {
  log.group(`processOrder(${order.id})`);
  log.debug('Input:', order);
  
  try {
    // Step 1
    log.debug('Validating order...');
    validateOrder(order);
    
    // Step 2
    log.debug('Calculating totals...');
    const totals = calculateTotals(order);
    log.debug('Totals:', totals);
    
    // Step 3
    log.debug('Processing payment...');
    const payment = processPayment(order, totals);
    
    log.success('Order processed');
    log.debug('Result:', payment);
    
    return payment;
  } catch (error) {
    log.error('Failed to process order');
    log.error(error.message);
    throw error;
  } finally {
    log.end();
  }
}

Order Processing Logs

┌ processOrder(ord_12345)

●│ ● Input: { id: 'ord_12345', items: [...], total: 99.99 }

●│ ● Validating order...

●│ ● Calculating totals...

●│ ● Totals: { subtotal: 89.99, tax: 10.00, total: 99.99 }

●│ ● Processing payment...

✔│ ✔ Order processed

●│ ● Result: { transactionId: 'txn_abc123', status: 'completed' }

└

🎮 Try Entry/Exit Logging

Log State Changes

function updateUser(id: string, updates: Partial<User>) {
  log.group(`updateUser(${id})`);
  
  // Log before state
  const before = getUser(id);
  log.debug('Before:', before);
  
  // Log changes
  log.debug('Updates:', updates);
  
  // Apply changes
  const after = applyUpdates(before, updates);
  
  // Log after state
  log.debug('After:', after);
  
  // Log what changed
  const diff = computeDiff(before, after);
  log.info('Changed fields:', Object.keys(diff));
  
  log.end();
  return after;
}

State Change Logging

┌ updateUser(usr_123)

●│ ● Before: { name: 'John', email: 'john@old.com', role: 'user' }

●│ ● Updates: { email: 'john@new.com', role: 'admin' }

●│ ● After: { name: 'John', email: 'john@new.com', role: 'admin' }

ℹ│ ℹ Changed fields: [ 'email', 'role' ]

└

Debug Levels

Use Appropriate Log Levels

// Debug: Development only, verbose information
log.debug('Variable state:', { x, y, z });
log.debug('Entering function with params:', params);

// Info: Notable events, useful in production too
log.info('User logged in', { userId });
log.info('Configuration loaded');

// Warn: Potential issues, recoverable errors
log.warn('Rate limit approaching');
log.warn('Using deprecated API');

// Error: Actual errors, needs attention
log.error('Payment failed', error);
log.error('Database connection lost');

// Success: Completed operations
log.success('Order completed');
log.success('Backup finished');

Log Levels Example

●● Variable state: { x: 10, y: 20, z: 30 }

●● Entering function with params: { userId: 'abc' }

ℹℹ User logged in { userId: 'usr_123' }

ℹℹ Configuration loaded

⚠⚠ Rate limit approaching (85% used)

⚠⚠ Using deprecated API: v1/users

✖✖ Payment failed: Card declined

✖✖ Database connection lost

✔✔ Order completed

✔✔ Backup finished

🎮 Try Log Levels

Conditional Debugging

Debug Flags

const DEBUG = {
  SQL: process.env.DEBUG_SQL === 'true',
  HTTP: process.env.DEBUG_HTTP === 'true',
  AUTH: process.env.DEBUG_AUTH === 'true',
  CACHE: process.env.DEBUG_CACHE === 'true'
};

function executeQuery(sql: string) {
  if (DEBUG.SQL) {
    log.debug(`SQL: ${sql}`);
    log.perf('sql-query');
  }
  
  const result = db.query(sql);
  
  if (DEBUG.SQL) {
    log.perfEnd('sql-query');
    log.debug(`Rows: ${result.length}`);
  }
  
  return result;
}

DEBUG_SQL=true

●● SQL: SELECT * FROM users WHERE status = 'active'

●⏱ Started: sql-query

●⏱ sql-query: 45ms

●● Rows: 156

Debug by Feature

const debugModule = (name: string) => {
  const isEnabled = process.env.DEBUG?.includes(name);
  
  return {
    log: (...args: unknown[]) => {
      if (isEnabled) log.debug(`[${name}]`, ...args);
    },
    group: (label: string) => {
      if (isEnabled) log.group(`${name}: ${label}`);
    },
    end: () => {
      if (isEnabled) log.end();
    }
  };
};

// Usage
const authDebug = debugModule('auth');
const dbDebug = debugModule('db');

// Enable with: DEBUG=auth,db node app.js

DEBUG=auth,db

●[auth] Validating token...

●[auth] Token valid for user: usr_123

●[db] Connecting to database...

●[db] Connection established

Tracing Execution

Request Tracing

function createTracer(requestId: string) {
  let step = 0;
  
  return {
    trace: (message: string, data?: unknown) => {
      step++;
      log.debug(`[${requestId}] Step ${step}: ${message}`, data);
    },
    error: (message: string, error?: Error) => {
      log.error(`[${requestId}] Error at step ${step}: ${message}`);
      if (error) log.stack(error);
    }
  };
}

// Usage
async function handleRequest(req: Request) {
  const tracer = createTracer(req.id);
  
  tracer.trace('Request received', { method: req.method, path: req.path });
  
  tracer.trace('Authenticating user');
  const user = await authenticate(req);
  tracer.trace('User authenticated', { userId: user.id });
  
  tracer.trace('Fetching data');
  const data = await fetchData(user);
  tracer.trace('Data fetched', { count: data.length });
  
  tracer.trace('Sending response');
  return { success: true, data };
}

Request Trace

●[abc123] Step 1: Request received { method: 'GET', path: '/api/users' }

●[abc123] Step 2: Authenticating user

●[abc123] Step 3: User authenticated { userId: 'usr_456' }

●[abc123] Step 4: Fetching data

●[abc123] Step 5: Data fetched { count: 42 }

●[abc123] Step 6: Sending response

🎮 Try Request Tracing

Call Stack Tracking

function trackCalls<T extends (...args: any[]) => any>(
  fn: T,
  name: string
): T {
  return ((...args: Parameters<T>) => {
    log.group(`${name}()`);
    log.debug('Arguments:', args);
    log.perf(name);
    
    try {
      const result = fn(...args);
      
      if (result instanceof Promise) {
        return result
          .then(r => {
            log.perfEnd(name);
            log.debug('Result:', r);
            log.end();
            return r;
          })
          .catch(e => {
            log.perfEnd(name);
            log.error('Threw:', e);
            log.end();
            throw e;
          });
      }
      
      log.perfEnd(name);
      log.debug('Result:', result);
      log.end();
      return result;
    } catch (error) {
      log.perfEnd(name);
      log.error('Threw:', error);
      log.end();
      throw error;
    }
  }) as T;
}

// Usage
const trackedFetch = trackCalls(fetchUser, 'fetchUser');
await trackedFetch('user123');

Call Stack Tracking

┌ fetchUser()

●│ ● Arguments: [ 'user123' ]

●│ ⏱ Started: fetchUser

●│ ⏱ fetchUser: 89ms

●│ ● Result: { id: 'user123', name: 'John Doe' }

└

Debugging Patterns

Snapshot Debugging

function snapshotDebug<T>(label: string, data: T): T {
  log.group(`Snapshot: ${label}`);
  log.debug('Data:', JSON.parse(JSON.stringify(data)));
  log.debug('Type:', typeof data);
  if (Array.isArray(data)) {
    log.debug('Length:', data.length);
  } else if (typeof data === 'object' && data !== null) {
    log.debug('Keys:', Object.keys(data));
  }
  log.end();
  return data;
}

// Usage
const users = snapshotDebug('raw users', await fetchUsers());
const filtered = snapshotDebug('filtered', users.filter(u => u.active));
const mapped = snapshotDebug('mapped', filtered.map(u => u.name));

Snapshot Debugging

┌ Snapshot: raw users

●│ ● Data: [ { id: 1, name: 'John', active: true }, ...]

●│ ● Type: object

●│ ● Length: 100

└

┌ Snapshot: filtered

●│ ● Data: [ { id: 1, name: 'John', active: true }, ...]

●│ ● Type: object

●│ ● Length: 42

└

┌ Snapshot: mapped

●│ ● Data: ['John', 'Jane', 'Bob', ...]

●│ ● Type: object

●│ ● Length: 42

└

Diff Debugging

function debugDiff(label: string, before: unknown, after: unknown) {
  log.group(`Diff: ${label}`);
  log.debug('Before:', before);
  log.debug('After:', after);
  
  if (typeof before === 'object' && typeof after === 'object') {
    const beforeKeys = new Set(Object.keys(before || {}));
    const afterKeys = new Set(Object.keys(after || {}));
    
    const added = [...afterKeys].filter(k => !beforeKeys.has(k));
    const removed = [...beforeKeys].filter(k => !afterKeys.has(k));
    const changed = [...beforeKeys].filter(k => 
      afterKeys.has(k) && (before as any)[k] !== (after as any)[k]
    );
    
    if (added.length) log.debug('Added:', added);
    if (removed.length) log.debug('Removed:', removed);
    if (changed.length) {
      changed.forEach(k => {
        log.debug(`Changed ${k}:`, (before as any)[k], '→', (after as any)[k]);
      });
    }
  }
  
  log.end();
}

Diff Debugging

┌ Diff: User Update

●│ ● Before: { name: 'John', email: 'old@mail.com', role: 'user' }

●│ ● After: { name: 'John', email: 'new@mail.com', role: 'admin', verified: true }

●│ ● Added: [ 'verified' ]

●│ ● Changed email: 'old@mail.com' → 'new@mail.com'

●│ ● Changed role: 'user' → 'admin'

└

🎮 Try Diff Debugging

Performance Debugging

Find Slow Operations

async function profileOperation(name: string, fn: () => Promise<void>) {
  const iterations = 100;
  const times: number[] = [];
  
  log.info(`Profiling ${name} (${iterations} iterations)`);
  
  for (let i = 0; i < iterations; i++) {
    const start = performance.now();
    await fn();
    times.push(performance.now() - start);
  }
  
  const avg = times.reduce((a, b) => a + b) / times.length;
  const min = Math.min(...times);
  const max = Math.max(...times);
  
  log.group(`Profile: ${name}`);
  log.info(`Average: ${avg.toFixed(2)}ms`);
  log.info(`Min: ${min.toFixed(2)}ms`);
  log.info(`Max: ${max.toFixed(2)}ms`);
  log.end();
}

Performance Profile

ℹℹ Profiling fetchUsers (100 iterations)

┌ Profile: fetchUsers

ℹ│ ℹ Average: 45.23ms

ℹ│ ℹ Min: 32.10ms

ℹ│ ℹ Max: 127.89ms

└

Memory Debugging

function debugMemory(label: string) {
  if (typeof process !== 'undefined' && process.memoryUsage) {
    const usage = process.memoryUsage();
    
    log.group(`Memory: ${label}`);
    log.debug(`Heap Used: ${Math.round(usage.heapUsed / 1024 / 1024)}MB`);
    log.debug(`Heap Total: ${Math.round(usage.heapTotal / 1024 / 1024)}MB`);
    log.debug(`RSS: ${Math.round(usage.rss / 1024 / 1024)}MB`);
    log.end();
  }
}

// Usage
debugMemory('Before processing');
await processLargeDataset();
debugMemory('After processing');

Memory Debugging

┌ Memory: Before processing

●│ ● Heap Used: 45MB

●│ ● Heap Total: 67MB

●│ ● RSS: 89MB

└

┌ Memory: After processing

●│ ● Heap Used: 312MB

●│ ● Heap Total: 456MB

●│ ● RSS: 512MB

└

Error Debugging

Comprehensive Error Logging

function debugError(error: unknown, context?: Record<string, unknown>) {
  log.group('Error Details');
  
  if (error instanceof Error) {
    log.error(`Type: ${error.constructor.name}`);
    log.error(`Message: ${error.message}`);
    
    // Custom error properties
    if ('code' in error) log.debug(`Code: ${(error as any).code}`);
    if ('statusCode' in error) log.debug(`Status: ${(error as any).statusCode}`);
    
    // Stack trace
    if (error.stack) {
      log.debug('Stack:');
      error.stack.split('\n').slice(1).forEach(line => {
        log.debug(`  ${line.trim()}`);
      });
    }
  } else {
    log.error(`Non-Error thrown: ${String(error)}`);
  }
  
  // Context
  if (context) {
    log.debug('Context:', context);
  }
  
  log.end();
}

Comprehensive Error Log

┌ Error Details

✖│ ✖ Type: DatabaseError

✖│ ✖ Message: Connection timeout after 5000ms

●│ ● Code: ETIMEDOUT

●│ ● Status: 503

●│ ● Stack:

●│ at Database.connect (db.ts:45:11)

●│ at UserService.findAll (users.ts:23:5)

●│ at apiHandler (api.ts:67:12)

●│ ● Context: { operation: 'fetchUsers', userId: 'usr_123' }

└

🎮 Try Error Debugging

Tips and Tricks

1. Use Once for Repeated Warnings

// Good: Shows once
function deprecatedMethod() {
  log.once('deprecated-method', 'Warning: This method is deprecated');
}

// Bad: Spams console
function deprecatedMethod() {
  log.warn('Warning: This method is deprecated');
}

log.once() vs log.warn()

With log.once():

⚠⚠ Warning: This method is deprecated

(called 100 times, logged once)

Without log.once():

⚠⚠ Warning: This method is deprecated

... (100 more times)

// Good: Organized
log.group('User Registration');
log.info('Validating input...');
log.info('Creating user...');
log.info('Sending email...');
log.success('Registration complete');
log.end();

// Bad: Scattered
log.info('Validating input...');
log.info('Creating user...');
log.info('Sending email...');
log.success('Registration complete');

3. Use Perf for Bottlenecks

log.perf('total');

log.perf('step1');
await step1();
log.perfEnd('step1');

log.perf('step2');
await step2();
log.perfEnd('step2');

log.perfEnd('total');

Finding Bottlenecks

●⏱ Started: total

●⏱ Started: step1

●⏱ step1: 45ms

●⏱ Started: step2

●⏱ step2: 2.3s ← Found the bottleneck!

●⏱ total: 2.35s

4. Conditional Detail Levels

function debugRequest(req: Request) {
  log.info(`${req.method} ${req.path}`);
  
  // Only show body in debug mode
  log.dev('Body:', req.body);
  log.dev('Headers:', req.headers);
  log.dev('Query:', req.query);
}

Next: TypeScript Support →

Strategic Logging​

Log at Entry and Exit Points​

Log State Changes​

Debug Levels​

Use Appropriate Log Levels​

Conditional Debugging​

Debug Flags​

Debug by Feature​

Tracing Execution​

Request Tracing​

Call Stack Tracking​

Debugging Patterns​

Snapshot Debugging​

Diff Debugging​

Performance Debugging​

Find Slow Operations​

Memory Debugging​

Error Debugging​

Comprehensive Error Logging​

Tips and Tricks​

1. Use Once for Repeated Warnings​

2. Group Related Logs​

3. Use Perf for Bottlenecks​

4. Conditional Detail Levels​

Strategic Logging

Log at Entry and Exit Points

Log State Changes

Debug Levels

Use Appropriate Log Levels

Conditional Debugging

Debug Flags

Debug by Feature

Tracing Execution

Request Tracing

Call Stack Tracking

Debugging Patterns

Snapshot Debugging

Diff Debugging

Performance Debugging

Find Slow Operations

Memory Debugging

Error Debugging

Comprehensive Error Logging

Tips and Tricks

1. Use Once for Repeated Warnings

2. Group Related Logs

3. Use Perf for Bottlenecks

4. Conditional Detail Levels