AI-Enhanced TypeScript Template

Appearance

Logging Best Practices ​

Comprehensive guide to effective logging practices in TypeScript applications using Winston.

Log Level Guidelines ​

When to Use Each Level ​

Error Level ​

Use for system errors, exceptions, and critical failures that require immediate attention.

typescript
// ✅ Good - System errors
logger.error('Database connection failed', { 
  host: 'localhost', 
  port: 5432, 
  error: error.message 
});

logger.error('Payment processing failed', { 
  orderId: '12345', 
  amount: 99.99, 
  error: error.stack 
});

// ❌ Bad - Not actually errors
logger.error('User not found'); // This is expected behavior
logger.error('Validation failed'); // This is normal application flow

Warn Level ​

Use for warning conditions, deprecated features, or recoverable errors.

typescript
// ✅ Good - Warning conditions
logger.warn('API rate limit approaching', { 
  current: 950, 
  limit: 1000, 
  resetTime: '2024-01-15T11:00:00Z' 
});

logger.warn('Using deprecated configuration option', { 
  option: 'oldSetting', 
  replacement: 'newSetting' 
});

logger.warn('Retrying failed operation', { 
  attempt: 2, 
  maxAttempts: 3, 
  operation: 'fetchUserData' 
});

Info Level ​

Use for general application flow, business logic events, and important state changes.

typescript
// ✅ Good - Important events
logger.info('User logged in', { 
  userId: user.id, 
  ip: req.ip, 
  userAgent: req.get('User-Agent') 
});

logger.info('Order completed', { 
  orderId: order.id, 
  userId: order.userId, 
  total: order.total 
});

logger.info('Server started', { 
  port: 3000, 
  environment: 'production' 
});

Debug Level ​

Use for detailed debugging information, function entry/exit, and development insights.

typescript
// ✅ Good - Debug information
logger.debug('Processing user input', { 
  input: sanitizedInput, 
  validationRules: rules 
});

logger.debug('Cache hit', { 
  key: 'user:123', 
  ttl: 3600 
});

logger.debug('Function entry', { 
  function: 'calculateTax', 
  parameters: { amount: 100, rate: 0.08 } 
});

Structured Logging ​

Use Objects for Metadata ​

typescript
// ✅ Good - Structured metadata
logger.info('User action performed', {
  userId: user.id,
  action: 'profile_update',
  timestamp: new Date().toISOString(),
  changes: ['email', 'phone'],
  ip: req.ip
});

// ❌ Bad - String concatenation
logger.info(`User ${user.id} updated profile with email and phone from ${req.ip}`);

Consistent Field Names ​

typescript
// ✅ Good - Consistent naming
const logContext = {
  userId: user.id,
  requestId: req.id,
  sessionId: req.session.id,
  timestamp: new Date().toISOString()
};

logger.info('Payment initiated', { ...logContext, amount: 99.99, currency: 'USD' });
logger.info('Payment completed', { ...logContext, transactionId: 'tx_123' });

// ❌ Bad - Inconsistent naming
logger.info('Payment initiated', { user_id: user.id, amount: 99.99 });
logger.info('Payment completed', { userId: user.id, txId: 'tx_123' });

Avoid Logging Sensitive Information ​

typescript
// ✅ Good - Sanitized logging
logger.info('User authentication attempt', {
  email: user.email,
  success: true,
  ip: req.ip,
  // Don't log password, tokens, or other sensitive data
});

// ❌ Bad - Sensitive data exposure
logger.info('User login', {
  email: user.email,
  password: user.password, // Never log passwords!
  token: authToken // Never log tokens!
});

// ✅ Good - Sanitization helper
function sanitizeForLogging(obj: any): any {
  const sensitiveFields = ['password', 'token', 'secret', 'key', 'ssn', 'creditCard'];
  const sanitized = { ...obj };
  
  for (const field of sensitiveFields) {
    if (sanitized[field]) {
      sanitized[field] = '[REDACTED]';
    }
  }
  
  return sanitized;
}

logger.info('User data processed', sanitizeForLogging(userData));

Performance Optimization ​

Conditional Expensive Operations ​

typescript
// ✅ Good - Conditional expensive logging
if (logger.level === 'debug') {
  logger.debug('Complex operation result', {
    result: JSON.stringify(complexObject),
    metrics: calculateExpensiveMetrics()
  });
}

// ✅ Better - Lazy evaluation
logger.debug('Complex operation result', () => ({
  result: JSON.stringify(complexObject),
  metrics: calculateExpensiveMetrics()
}));

Avoid Synchronous File Operations ​

typescript
// ✅ Good - Async logging (Winston handles this automatically)
logger.info('Operation completed', { duration: Date.now() - start });

// ❌ Bad - Synchronous file operations
fs.writeFileSync('debug.log', `Operation completed at ${new Date()}\n`, { flag: 'a' });

Log Sampling for High-Volume Events ​

typescript
// Sample high-volume logs
class SampledLogger {
  private counters = new Map<string, number>();
  
  constructor(private logger: ILogger) {}
  
  sampleLog(key: string, sampleRate: number, level: 'info' | 'debug', message: string, meta?: object) {
    const count = this.counters.get(key) || 0;
    this.counters.set(key, count + 1);
    
    if (count % sampleRate === 0) {
      this.logger[level](message, { ...meta, sampleCount: count });
    }
  }
}

// Usage
const sampledLogger = new SampledLogger(logger);

// Log every 100th request
sampledLogger.sampleLog('api_requests', 100, 'info', 'API request processed', {
  endpoint: '/api/users',
  method: 'GET'
});

Error Logging ​

Include Stack Traces ​

typescript
// ✅ Good - Complete error information
try {
  await riskyOperation();
} catch (error) {
  logger.error('Operation failed', {
    error: {
      name: error.name,
      message: error.message,
      stack: error.stack
    },
    operation: 'riskyOperation',
    context: { userId: user.id, timestamp: new Date().toISOString() }
  });
  throw error;
}

Error Context ​

typescript
// ✅ Good - Rich error context
function logErrorWithContext(error: Error, context: {
  operation: string;
  userId?: string;
  requestId?: string;
  additionalData?: object;
}) {
  logger.error(`Error in ${context.operation}`, {
    error: {
      name: error.name,
      message: error.message,
      stack: error.stack
    },
    context: {
      operation: context.operation,
      userId: context.userId,
      requestId: context.requestId,
      timestamp: new Date().toISOString(),
      ...context.additionalData
    }
  });
}

// Usage
try {
  await processPayment(paymentData);
} catch (error) {
  logErrorWithContext(error, {
    operation: 'payment_processing',
    userId: user.id,
    requestId: req.id,
    additionalData: { 
      amount: paymentData.amount, 
      currency: paymentData.currency 
    }
  });
  throw error;
}

Application Lifecycle Logging ​

Startup Logging ​

typescript
async function startApplication() {
  loggerUtils.logStartup(logger, 'MyApp', '1.0.0');
  
  try {
    // Log configuration loading
    logger.info('Loading configuration', { configPath: './config.json' });
    const config = await loadConfiguration();
    logger.info('Configuration loaded successfully', { 
      environment: config.environment,
      features: Object.keys(config.features).filter(key => config.features[key])
    });
    
    // Log database connection
    logger.info('Connecting to database', { host: config.database.host });
    await connectToDatabase(config.database);
    logger.info('Database connected successfully');
    
    // Log server startup
    logger.info('Starting HTTP server', { port: config.server.port });
    await startServer(config.server);
    logger.info('Server started successfully', { 
      port: config.server.port,
      host: config.server.host 
    });
    
    loggerUtils.logCompletion(logger, 'Application startup completed');
  } catch (error) {
    logger.error('Application startup failed', { error: error.message });
    process.exit(1);
  }
}

Shutdown Logging ​

typescript
async function gracefulShutdown() {
  logger.info('Received shutdown signal, starting graceful shutdown');
  
  try {
    logger.info('Closing HTTP server');
    await server.close();
    logger.info('HTTP server closed');
    
    logger.info('Closing database connections');
    await database.close();
    logger.info('Database connections closed');
    
    loggerUtils.logCompletion(logger, 'Graceful shutdown completed');
  } catch (error) {
    logger.error('Error during shutdown', { error: error.message });
  }
  
  process.exit(0);
}

process.on('SIGTERM', gracefulShutdown);
process.on('SIGINT', gracefulShutdown);

Request/Response Logging ​

HTTP Request Logging ​

typescript
function createRequestLogger(logger: ILogger) {
  return (req: Request, res: Response, next: NextFunction) => {
    const start = Date.now();
    const requestId = req.headers['x-request-id'] || generateRequestId();
    
    // Add request ID to request object
    req.requestId = requestId;
    
    // Log incoming request
    logger.info('Incoming request', {
      requestId,
      method: req.method,
      path: req.path,
      query: req.query,
      ip: req.ip,
      userAgent: req.get('User-Agent'),
      contentLength: req.get('Content-Length')
    });
    
    // Override res.end to log response
    const originalEnd = res.end;
    res.end = function(...args) {
      const duration = Date.now() - start;
      
      logger.info('Request completed', {
        requestId,
        method: req.method,
        path: req.path,
        statusCode: res.statusCode,
        duration: `${duration}ms`,
        contentLength: res.get('Content-Length')
      });
      
      originalEnd.apply(this, args);
    };
    
    next();
  };
}

Database Query Logging ​

typescript
class DatabaseLogger {
  constructor(private logger: ILogger) {}
  
  logQuery(query: string, params: any[], duration: number) {
    this.logger.debug('Database query executed', {
      query: this.sanitizeQuery(query),
      paramCount: params.length,
      duration: `${duration}ms`
    });
  }
  
  logSlowQuery(query: string, params: any[], duration: number, threshold: number) {
    if (duration > threshold) {
      this.logger.warn('Slow database query detected', {
        query: this.sanitizeQuery(query),
        paramCount: params.length,
        duration: `${duration}ms`,
        threshold: `${threshold}ms`
      });
    }
  }
  
  private sanitizeQuery(query: string): string {
    // Remove sensitive data from queries
    return query.replace(/('.*?'|".*?")/g, '[SANITIZED]');
  }
}

Testing and Development ​

Test Environment Logging ​

typescript
// Test configuration
const testLogger = createLogger({
  level: 'error', // Only log errors in tests
  outputFile: null,
  includeTimestamp: false,
  useColors: false
});

// Mock logger for unit tests
const mockLogger: ILogger = {
  error: jest.fn(),
  warn: jest.fn(),
  info: jest.fn(),
  debug: jest.fn()
};

// Test helper to verify logging
function expectLoggedError(mockLogger: jest.Mocked<ILogger>, message: string) {
  expect(mockLogger.error).toHaveBeenCalledWith(
    expect.stringContaining(message),
    expect.any(Object)
  );
}

Development Debugging ​

typescript
// Development-only detailed logging
if (process.env.NODE_ENV === 'development') {
  logger.debug('Detailed state information', {
    userState: user,
    requestState: req.body,
    sessionState: req.session,
    timestamp: new Date().toISOString()
  });
}

// Conditional debug logging
const debugLogger = process.env.DEBUG_LOGGING === 'true' ? logger : {
  debug: () => {}, // No-op in production
  info: logger.info.bind(logger),
  warn: logger.warn.bind(logger),
  error: logger.error.bind(logger)
};

Monitoring and Alerting ​

Log-Based Metrics ​

typescript
// Track metrics through logging
class MetricsLogger {
  constructor(private logger: ILogger) {}
  
  recordMetric(name: string, value: number, unit: string, tags?: object) {
    this.logger.info('Metric recorded', {
      metric: {
        name,
        value,
        unit,
        timestamp: new Date().toISOString()
      },
      tags
    });
  }
  
  recordEvent(event: string, properties?: object) {
    this.logger.info('Event recorded', {
      event: {
        name: event,
        timestamp: new Date().toISOString()
      },
      properties
    });
  }
}

// Usage
const metricsLogger = new MetricsLogger(logger);
metricsLogger.recordMetric('response_time', 150, 'ms', { endpoint: '/api/users' });
metricsLogger.recordEvent('user_signup', { source: 'web', plan: 'premium' });

Alert-Worthy Events ​

typescript
// Log events that should trigger alerts
function logAlertEvent(logger: ILogger, severity: 'low' | 'medium' | 'high' | 'critical', event: string, details: object) {
  logger.error(`ALERT [${severity.toUpperCase()}]: ${event}`, {
    alert: {
      severity,
      event,
      timestamp: new Date().toISOString(),
      requiresAction: severity === 'high' || severity === 'critical'
    },
    details
  });
}

// Usage
logAlertEvent(logger, 'high', 'Database connection pool exhausted', {
  activeConnections: 100,
  maxConnections: 100,
  queuedRequests: 50
});

Common Anti-Patterns to Avoid ​

❌ Don't Do These ​

typescript
// Don't log in loops without sampling
for (const item of largeArray) {
  logger.info('Processing item', { item }); // This will spam logs
}

// Don't log the same information repeatedly
logger.info('User data', user);
logger.info('Processing user', user); // Redundant

// Don't use string concatenation
logger.info('User ' + user.id + ' performed action ' + action); // Hard to parse

// Don't log without context
logger.error('Something failed'); // Not helpful

// Don't ignore log levels
logger.error('User not found'); // This isn't an error

// Don't log sensitive data
logger.info('User login', { password: user.password }); // Security risk

✅ Do These Instead ​

typescript
// Sample high-volume logs
if (Math.random() < 0.01) { // 1% sampling
  logger.debug('Processing item', { itemId: item.id, batchSize: largeArray.length });
}

// Consolidate related information
logger.info('User processing started', { 
  userId: user.id, 
  action: action, 
  timestamp: new Date().toISOString() 
});

// Use structured logging
logger.info('User action performed', { userId: user.id, action });

// Provide context
logger.error('Database query failed', { 
  query: 'SELECT * FROM users', 
  error: error.message,
  duration: queryDuration 
});

// Use appropriate levels
logger.info('User not found', { requestedUserId: userId }); // This is information

// Sanitize sensitive data
logger.info('User login attempt', { 
  email: user.email, 
  success: true,
  // password field omitted
});

Next Steps ​

Released under the MIT License.

Copyright © 2024 AI-Enhanced TypeScript Template