performance-logger.ts13.9 KBView on GitHub
/**
 * Performance Logger
 *
 * šŸŽÆ GLOBAL TOGGLES:
 * - ENABLE_PERF_LOGGING: Controls all performance logs (set via VITE_PERFLOGS env var)
 * - ENABLE_SESSION_PROVIDER_LOGS: Controls session-provider.tsx logs separately (code constant)
 *
 * Usage:
 * import { perfLogger, ENABLE_PERF_LOGGING, ENABLE_SESSION_PROVIDER_LOGS, perfLog, perfEffect } from '@/lib/performance-logger';
 *
 * // For regular logs:
 * perfLog('message', 'color: red');
 *
 * // For session logs (timeline-aware):
 * perfSessionLog('session message', 'color: blue');
 *
 * // For useEffect logs (zero overhead when disabled):
 * perfEffect(() => {
 *   console.log('This only runs if ENABLE_PERF_LOGGING is true');
 * }, [deps]);
 *
 * // For operations:
 * perfLogger.start('operation-name');
 * // ... do work
 * perfLogger.end('operation-name');
 */

// Perf logging is opt-in via VITE_PERFLOGS=true.
export const ENABLE_PERF_LOGGING = import.meta.env.DEV && import.meta.env.VITE_PERFLOGS === 'true';

interface PerformanceEntry {
  name: string;
  startTime: number;
  endTime?: number;
  duration?: number;
  metadata?: Record<string, unknown>;
}

interface TimelineEvent {
  type: 'start' | 'end' | 'mark' | 'log';
  name: string;
  timestamp: number;
  duration?: number;
  metadata?: Record<string, unknown>;
  message?: string;
  style?: string;
}

interface PerformanceSession {
  name: string;
  startTime: number;
  events: TimelineEvent[];
  active: boolean;
}

// Hash function to generate consistent color from string
function hashToColor(str: string): string {
  if (!str) return '#888888';

  let hash = 0;
  for (let i = 0; i < str.length; i++) {
    hash = str.charCodeAt(i) + ((hash << 5) - hash);
    hash = hash & hash; // Convert to 32bit integer
  }

  // Generate bright, readable colors (avoid too dark or too light)
  const h = Math.abs(hash % 360);
  const s = 70 + (Math.abs(hash) % 20); // 70-90% saturation
  const l = 45 + (Math.abs(hash >> 8) % 15); // 45-60% lightness

  return `hsl(${h}, ${s}%, ${l}%)`;
}

class PerformanceLogger {
  private entries: Map<string, PerformanceEntry> = new Map();
  private logs: PerformanceEntry[] = [];
  private enabled = ENABLE_PERF_LOGGING && import.meta.env.DEV; // Only in development

  // Timeline session tracking
  private sessions: Map<string, PerformanceSession> = new Map();
  private activeSession: string | null = null;

  // ============================================
  // Session Management
  // ============================================

  /**
   * Start a performance tracking session
   * All logs during this session will be pooled and displayed together
   */
  startSession(sessionName: string) {
    if (!this.enabled) return;

    const session: PerformanceSession = {
      name: sessionName,
      startTime: performance.now(),
      events: [],
      active: true,
    };

    this.sessions.set(sessionName, session);
    this.activeSession = sessionName;

    // Log session start
    this.addEvent({
      type: 'mark',
      name: `SESSION START: ${sessionName}`,
      timestamp: performance.now(),
      metadata: {},
    });
  }

  /**
   * End a performance tracking session and display timeline
   */
  endSession(sessionName?: string) {
    if (!this.enabled) return;

    const name = sessionName || this.activeSession;
    if (!name) {
      console.warn('No active session to end');
      return;
    }

    const session = this.sessions.get(name);
    if (!session) {
      console.warn(`Session "${name}" not found`);
      return;
    }

    session.active = false;

    // Add session end event
    this.addEvent({
      type: 'mark',
      name: `SESSION END: ${name}`,
      timestamp: performance.now(),
      metadata: {},
    });

    // Display timeline
    this.displayTimeline(name);

    // Clear active session if this was the active one
    if (this.activeSession === name) {
      this.activeSession = null;
    }
  }

  /**
   * Add an event to the current session
   */
  private addEvent(event: TimelineEvent) {
    if (!this.enabled || !this.activeSession) return;

    const session = this.sessions.get(this.activeSession);
    if (session && session.active) {
      session.events.push(event);
    }
  }

  /**
   * Log a message within a session (will be pooled)
   */
  sessionLog(message: string, style?: string, metadata?: Record<string, unknown>) {
    if (!this.enabled) return;

    if (this.activeSession) {
      // Pool the log
      this.addEvent({
        type: 'log',
        name: message,
        timestamp: performance.now(),
        message,
        style,
        metadata,
      });
    } else {
      // No active session, log immediately
      if (style) {
        console.log(`%c${message}`, style, metadata);
      } else {
        console.log(message, metadata);
      }
    }
  }

  /**
   * Display timeline for a session
   */
  private displayTimeline(sessionName: string) {
    if (!this.enabled) return;

    const session = this.sessions.get(sessionName);
    if (!session) return;

    const totalDuration = performance.now() - session.startTime;

    console.groupCollapsed(
      `%cšŸ“Š ${sessionName} (${totalDuration.toFixed(2)}ms)`,
      'color: #ff00ff; font-weight: bold; font-size: 14px; background: #fff3cd; padding: 4px 8px; border-radius: 4px;',
    );

    // Sort events by timestamp
    const sortedEvents = [...session.events].sort((a, b) => a.timestamp - b.timestamp);

    // Display events in timeline order
    console.log('%c━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━', 'color: #888');

    sortedEvents.forEach((event) => {
      const relativeTime = event.timestamp - session.startTime;
      const timeStr = `+${relativeTime.toFixed(2)}ms`.padEnd(12);

      switch (event.type) {
        case 'start': {
          const color = hashToColor(event.name);
          const metadataStr = event.metadata ? ' ' + JSON.stringify(event.metadata) : '';
          console.log(
            `%c${timeStr} %cā–¶ START   %c${event.name}${metadataStr}`,
            'color: #666; font-family: monospace',
            `color: ${color}; font-weight: bold`,
            `color: ${color}`,
          );
          break;
        }
        case 'end': {
          const color = hashToColor(event.name);
          const durationStr = event.duration ? ` (${event.duration.toFixed(2)}ms)` : '';
          const metadataStr = event.metadata ? ' ' + JSON.stringify(event.metadata) : '';
          console.log(
            `%c${timeStr} %cā–  END     %c${event.name}${durationStr}${metadataStr}`,
            'color: #666; font-family: monospace',
            `color: ${color}; font-weight: bold`,
            `color: ${color}`,
          );
          break;
        }
        case 'mark': {
          const color = hashToColor(event.name);
          console.log(
            `%c${timeStr} %cāš‘ MARK    %c${event.name}`,
            'color: #666; font-family: monospace',
            `color: ${color}; font-weight: bold`,
            `color: ${color}`,
          );
          break;
        }
        case 'log': {
          const style = event.style || 'color: #000';
          console.log(
            `%c${timeStr} %cā—† LOG     %c${event.message}`,
            'color: #666; font-family: monospace',
            'color: #00aaff; font-weight: bold',
            style,
          );
          break;
        }
      }
    });

    console.log('%c━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━', 'color: #888');

    // Show summary statistics
    const startEvents = sortedEvents.filter((e) => e.type === 'start');
    const endEvents = sortedEvents.filter((e) => e.type === 'end');
    const marks = sortedEvents.filter((e) => e.type === 'mark');

    console.log(
      `%cšŸ“ˆ Summary: ${startEvents.length} operations started, ${endEvents.length} completed, ${marks.length} marks, ${sortedEvents.length} total events`,
      'color: #666; font-style: italic',
    );

    console.groupEnd();
  }

  start(name: string, metadata?: Record<string, unknown>) {
    if (!this.enabled) return;

    const startTime = performance.now();
    this.entries.set(name, {
      name,
      startTime,
      metadata,
    });

    // Add to session if active
    if (this.activeSession) {
      this.addEvent({
        type: 'start',
        name,
        timestamp: startTime,
        metadata,
      });
    } else {
      // No session, log immediately
      const color = hashToColor(name);
      const metadataStr = metadata ? ' ' + JSON.stringify(metadata) : '';
      console.log(`%c[${name}] [START]${metadataStr}`, `color: ${color}; font-weight: bold`);
    }
  }

  end(name: string, additionalMetadata?: Record<string, unknown>): void {
    if (!this.enabled) return;

    const entry = this.entries.get(name);
    if (!entry) {
      console.warn(`[${name}] [ERROR] No start entry found`);
      return;
    }

    const endTime = performance.now();
    const duration = endTime - entry.startTime;

    const completedEntry: PerformanceEntry = {
      ...entry,
      endTime,
      duration,
      metadata: { ...entry.metadata, ...additionalMetadata },
    };

    this.logs.push(completedEntry);
    this.entries.delete(name);

    // Add to session if active
    if (this.activeSession) {
      this.addEvent({
        type: 'end',
        name,
        timestamp: endTime,
        duration,
        metadata: completedEntry.metadata,
      });
    } else {
      // No session, log immediately
      const color = hashToColor(name);
      const metadataStr = completedEntry.metadata
        ? ' ' + JSON.stringify(completedEntry.metadata)
        : '';

      console.log(
        `%c[${name}] [END] ${duration.toFixed(2)}ms${metadataStr}`,
        `color: ${color}; font-weight: bold`,
      );
    }
  }

  mark(name: string, metadata?: Record<string, unknown>) {
    if (!this.enabled) return;

    // Add to session if active
    if (this.activeSession) {
      this.addEvent({
        type: 'mark',
        name,
        timestamp: performance.now(),
        metadata,
      });
    } else {
      // No session, log immediately
      const color = hashToColor(name);
      console.log(`%c[${name}] [MARK]`, `color: ${color}; font-weight: bold`);
    }
  }

  measure(name: string, fn: () => void) {
    if (!this.enabled) {
      fn();
      return;
    }

    this.start(name);
    fn();
    this.end(name);
  }

  async measureAsync<T>(name: string, fn: () => Promise<T>): Promise<T> {
    if (!this.enabled) {
      return fn();
    }

    this.start(name);
    try {
      const result = await fn();
      this.end(name);
      return result;
    } catch (error) {
      this.end(name, { error: true });
      throw error;
    }
  }

  getSummary() {
    if (!this.enabled) return;

    console.group('%c[PERF SUMMARY]', 'color: #aa00ff; font-weight: bold; font-size: 14px');

    const sorted = [...this.logs].sort((a, b) => (b.duration || 0) - (a.duration || 0));

    console.table(
      sorted.map((entry) => ({
        Name: entry.name,
        'Duration (ms)': entry.duration?.toFixed(2),
        Metadata: JSON.stringify(entry.metadata || {}),
      })),
    );

    const total = sorted.reduce((sum, entry) => sum + (entry.duration || 0), 0);
    console.log(`%cTotal Time: ${total.toFixed(2)}ms`, 'font-weight: bold; font-size: 14px');

    console.groupEnd();
  }

  clear() {
    this.entries.clear();
    this.logs = [];
  }

  // Get logs programmatically
  getLogs() {
    return [...this.logs];
  }

  // Enable/disable logging
  setEnabled(enabled: boolean) {
    this.enabled = enabled;
  }
}

export const perfLogger = new PerformanceLogger();

// Add to window for debugging
if (typeof window !== 'undefined') {
  (window as unknown as { perfLogger: PerformanceLogger }).perfLogger = perfLogger;
}

// ============================================
// Helper Functions for Conditional Logging
// ============================================

/**
 * Conditional console.log - only logs if ENABLE_PERF_LOGGING is true
 * Zero overhead when disabled (function call is eliminated by bundler)
 */
export const perfLog = ENABLE_PERF_LOGGING
  ? (message: string, style?: string, ...args: unknown[]) => {
      if (style) {
        console.log(`%c${message}`, style, ...args);
      } else {
        console.log(message, ...args);
      }
    }
  : () => {}; // No-op when disabled

/**
 * Session-aware log - pools logs when a session is active, otherwise logs immediately
 * Use this when you want logs to be included in timeline
 */
export const perfSessionLog = ENABLE_PERF_LOGGING
  ? (message: string, style?: string, metadata?: Record<string, unknown>) => {
      perfLogger.sessionLog(message, style, metadata);
    }
  : () => {}; // No-op when disabled

/**
 * Conditional useEffect for performance logging
 * When ENABLE_PERF_LOGGING is false, this returns a no-op hook
 * Zero overhead - useEffect is never created when disabled
 */
export const perfEffect = ENABLE_PERF_LOGGING
  ? (effect: React.EffectCallback, deps?: React.DependencyList) => {
      // eslint-disable-next-line react-hooks/exhaustive-deps
      return React.useEffect(effect, deps);
    }
  : () => {}; // No-op hook when disabled

/**
 * Conditional function execution
 * Only runs the function if ENABLE_PERF_LOGGING is true
 */
export const perfRun = ENABLE_PERF_LOGGING ? <T>(fn: () => T): T => fn() : <T>() => undefined as T;

/**
 * Measure performance of a synchronous operation
 * Returns the operation result, logs timing
 */
export const perfMeasure = ENABLE_PERF_LOGGING
  ? <T>(name: string, fn: () => T): T => {
      const start = performance.now();
      const result = fn();
      const duration = performance.now() - start;
      console.log(`%c[PERF] ${name}: ${duration.toFixed(2)}ms`, 'color: #00aa00');
      return result;
    }
  : <T>(name: string, fn: () => T): T => fn(); // Just run fn, no logging

// Re-export React for perfEffect
import React from 'react';