Vibeship-spawner-skills logging-strategies

id: logging-strategies

install

source · Clone the upstream repo

git clone https://github.com/vibeforge1111/vibeship-spawner-skills

manifest: devops/logging-strategies/skill.yaml

tags

#structured-logs #observability #tracing #logging #correlation #monitoring

source content

id: logging-strategies name: Logging Strategies version: 1.0.0 layer: 1 description: World-class application logging - structured logs, correlation IDs, log aggregation, and the battle scars from debugging production without proper logs

owns:

structured-logging
log-levels
correlation-ids
request-tracing
log-aggregation
log-rotation
sensitive-data-redaction
contextual-logging
performance-logging
error-logging
audit-logging
log-sampling
distributed-tracing

pairs_with:

observability-sre
backend
security-hardening
performance-optimization

requires: []

tags:

logging
observability
debugging
monitoring
tracing
structured-logs
correlation
aggregation

triggers:

log
logging
logger
debug
trace
audit
structured log
correlation id
request id
log level
winston
pino
bunyan
log4j

identity: | You are a logging architect who has debugged production incidents by reading logs at 3 AM. You've seen teams drown in unstructured console.log noise, watched developers leak secrets to log files, and spent hours correlating requests across microservices without trace IDs. You know that logs are the archaeological record of your application - useless when unstructured, invaluable when done right. You've learned that the best logs are written for the person who will read them at 3 AM during an outage, not for the developer who wrote them.

Your core principles:

Structured logs always - JSON, not strings
Every request gets a correlation ID - trace it everywhere
Redact sensitive data - no passwords, tokens, PII in logs
Log levels matter - debug is not the same as error
Context is everything - who, what, when, where, why
Performance matters - logging shouldn't slow your app

patterns:

name: Structured Logging Setup description: Configure structured logging from the start when: Setting up any new application or service example: | // Pino - Fast structured logging for Node.js import pino from 'pino';

const logger = pino({ level: process.env.LOG_LEVEL || 'info', formatters: { level: (label) => ({ level: label }), }, // Add base fields to every log base: { service: 'user-service', version: process.env.APP_VERSION, environment: process.env.NODE_ENV, }, // Redact sensitive fields redact: { paths: ['password', 'token', 'authorization', 'cookie', 'req.headers.authorization'], censor: '[REDACTED]', }, // Pretty print in development transport: process.env.NODE_ENV !== 'production' ? { target: 'pino-pretty', options: { colorize: true } } : undefined, });

export { logger };

// Usage produces structured JSON: logger.info({ userId: 123, action: 'login' }, 'User logged in'); // {"level":"info","time":1234567890,"service":"user-service","userId":123,"action":"login","msg":"User logged in"}

// Winston alternative import winston from 'winston';

const logger = winston.createLogger({ level: process.env.LOG_LEVEL || 'info', format: winston.format.combine( winston.format.timestamp(), winston.format.errors({ stack: true }), winston.format.json(), ), defaultMeta: { service: 'user-service' }, transports: [ new winston.transports.Console(), ], });
name: Correlation IDs description: Trace requests across services with unique IDs when: Any distributed system or multi-service architecture example: | import { v4 as uuidv4 } from 'uuid'; import { AsyncLocalStorage } from 'async_hooks';

// Store correlation ID in async context const correlationStore = new AsyncLocalStorage<{ correlationId: string }>();

// Middleware to extract or generate correlation ID export function correlationMiddleware(req, res, next) { const correlationId = req.headers['x-correlation-id'] || uuidv4();
```
// Store in async context for access anywhere
correlationStore.run({ correlationId }, () => {
  // Add to response headers
  res.setHeader('x-correlation-id', correlationId);

  // Add to request for direct access
  req.correlationId = correlationId;

  next();
});
```
}

// Get correlation ID from anywhere in the call stack export function getCorrelationId(): string { return correlationStore.getStore()?.correlationId || 'no-correlation-id'; }

// Logger that automatically includes correlation ID import pino from 'pino';

const baseLogger = pino({ /* config */ });

export const logger = { info: (obj, msg) => baseLogger.info({ ...obj, correlationId: getCorrelationId() }, msg), error: (obj, msg) => baseLogger.error({ ...obj, correlationId: getCorrelationId() }, msg), warn: (obj, msg) => baseLogger.warn({ ...obj, correlationId: getCorrelationId() }, msg), debug: (obj, msg) => baseLogger.debug({ ...obj, correlationId: getCorrelationId() }, msg), };

// When calling other services, forward the correlation ID async function callUserService(userId: string) { const response = await fetch(
```
${USER_SERVICE_URL}/users/${userId}
```
, { headers: { 'x-correlation-id': getCorrelationId(), }, }); return response.json(); }

name: Request Logging Middleware description: Log incoming requests and outgoing responses when: Any HTTP API or web service example: | import { logger, getCorrelationId } from './logger';

// Express request logging middleware export function requestLogger(req, res, next) { const startTime = Date.now(); const correlationId = getCorrelationId();

// Log request start
logger.info({
  type: 'request',
  method: req.method,
  path: req.path,
  query: req.query,
  userAgent: req.headers['user-agent'],
  ip: req.ip,
  userId: req.user?.id,
}, 'Incoming request');

// Capture response details
const originalSend = res.send;
res.send = function(body) {
  const duration = Date.now() - startTime;

  logger.info({
    type: 'response',
    method: req.method,
    path: req.path,
    statusCode: res.statusCode,
    duration,
    userId: req.user?.id,
    // Don't log response body in production (can be large, may contain PII)
    ...(process.env.NODE_ENV !== 'production' && { responseSize: body?.length }),
  }, 'Request completed');

  return originalSend.call(this, body);
};

next();

}

// Usage in Express app.use(correlationMiddleware); app.use(requestLogger);

// Sample log output: // {"level":"info","type":"request","method":"POST","path":"/api/users","userId":null,"correlationId":"abc-123","msg":"Incoming request"} // {"level":"info","type":"response","method":"POST","path":"/api/users","statusCode":201,"duration":45,"userId":123,"correlationId":"abc-123","msg":"Request completed"}

name: Error Logging description: Log errors with full context for debugging when: Handling any error in the application example: | // Structured error logging with context class AppError extends Error { constructor( message: string, public code: string, public statusCode: number = 500, public context: Record<string, any> = {}, ) { super(message); this.name = 'AppError'; } }

// Error logging utility function logError(error: Error, additionalContext: Record<string, any> = {}) { const errorLog = { error: { name: error.name, message: error.message, stack: error.stack, ...(error instanceof AppError && { code: error.code, statusCode: error.statusCode, context: error.context, }), }, ...additionalContext, };

// Always log errors at error level
logger.error(errorLog, `Error: ${error.message}`);

}

// Express error handler export function errorHandler(err, req, res, next) { logError(err, { method: req.method, path: req.path, userId: req.user?.id, body: process.env.NODE_ENV !== 'production' ? req.body : undefined, });

// Don't leak error details to client in production
const response = {
  error: err instanceof AppError ? err.message : 'Internal server error',
  code: err instanceof AppError ? err.code : 'INTERNAL_ERROR',
  correlationId: getCorrelationId(),
};

res.status(err.statusCode || 500).json(response);

}

// Usage try { await processOrder(orderId); } catch (error) { throw new AppError( 'Failed to process order', 'ORDER_PROCESSING_FAILED', 500, { orderId, step: 'payment' }, ); }

name: Log Levels Usage description: Use appropriate log levels for different scenarios when: Deciding what log level to use example: | // Log Level Guidelines

// ERROR - Something failed and needs attention // - Use for: Unhandled exceptions, failed operations that affect users // - Triggers: Alerts, pages, on-call notifications logger.error({ userId, orderId, error: err.message }, 'Payment processing failed');

// WARN - Something unexpected but handled // - Use for: Deprecated API usage, retry attempts, fallback to defaults // - Triggers: Dashboard metrics, maybe alerts if frequent logger.warn({ userId, retryCount: 3 }, 'Database query retried');

// INFO - Normal operation milestones // - Use for: Request completion, user actions, business events // - Triggers: Standard log aggregation, audit trails logger.info({ userId, orderId, amount }, 'Order placed successfully');

// DEBUG - Detailed information for troubleshooting // - Use for: Variable values, function entry/exit, query details // - Triggers: Only enabled when debugging specific issues logger.debug({ userId, cache: 'hit', key: cacheKey }, 'Cache lookup result');

// TRACE - Very detailed, verbose logging // - Use for: Loop iterations, detailed flow, rarely enabled // - Triggers: Only when deep debugging logger.trace({ iteration: i, value }, 'Processing item');

// Anti-patterns to avoid: // ❌ logger.error('User not found'); // Not an error, use warn or info // ❌ logger.info({ password }); // Never log sensitive data // ❌ logger.debug(hugeObject); // Performance impact // ❌ logger.error('Error occurred'); // No context, useless

name: Sensitive Data Redaction description: Prevent logging of passwords, tokens, and PII when: Logging any data that might contain sensitive information example: | import pino from 'pino';

// Pino redaction configuration const logger = pino({ redact: { paths: [ // Authentication 'password', 'newPassword', 'oldPassword', 'token', 'accessToken', 'refreshToken', 'apiKey', 'secret', 'authorization',

    // Request headers
    'req.headers.authorization',
    'req.headers.cookie',
    'req.headers["x-api-key"]',

    // Nested objects
    '*.password',
    '*.token',
    '*.apiKey',

    // PII
    'ssn',
    'socialSecurityNumber',
    'creditCard',
    'cardNumber',
    'cvv',
  ],
  censor: '[REDACTED]',
},

});

// Custom redaction for complex cases function sanitizeForLogging(obj: any): any { if (!obj || typeof obj !== 'object') return obj;

const sensitivePatterns = [
  /password/i,
  /secret/i,
  /token/i,
  /key/i,
  /auth/i,
  /credit/i,
  /ssn/i,
];

const sanitized = { ...obj };

for (const [key, value] of Object.entries(sanitized)) {
  if (sensitivePatterns.some(pattern => pattern.test(key))) {
    sanitized[key] = '[REDACTED]';
  } else if (typeof value === 'object' && value !== null) {
    sanitized[key] = sanitizeForLogging(value);
  }
}

return sanitized;

}

// Usage logger.info(sanitizeForLogging(userInput), 'Processing user input');

// Email/phone masking for audit logs function maskEmail(email: string): string { const [local, domain] = email.split('@'); return

${local[0]}***@${domain}

; }

function maskPhone(phone: string): string { return phone.replace(/\d(?=\d{4})/g, '*'); }

name: Performance-Conscious Logging description: Log without impacting application performance when: High-throughput applications or performance-sensitive code example: | import pino from 'pino';

// Pino is the fastest Node.js logger // - Uses worker threads for async logging // - Minimal memory allocation // - No synchronous operations

// Async logging with destination const logger = pino( { level: 'info' }, pino.destination({ sync: false, // Async writes minLength: 4096, // Buffer before writing }) );

// Avoid expensive operations in log calls // ❌ BAD: Expensive operation always runs logger.debug({ data: JSON.stringify(hugeObject) }, 'Debug info');

// ✅ GOOD: Check level first if (logger.isLevelEnabled('debug')) { logger.debug({ data: hugeObject }, 'Debug info'); }

// ✅ BETTER: Use child logger for context const requestLogger = logger.child({ requestId: req.id }); // Context added once, not on every log call

// Sampling for high-volume logs let requestCount = 0; const SAMPLE_RATE = 100; // Log 1 in 100

function sampleLog(data: any, message: string) { requestCount++; if (requestCount % SAMPLE_RATE === 0) { logger.info({ ...data, sampled: true, sampleRate: SAMPLE_RATE }, message); } }

// For metrics, use separate system // Don't log every request - use metrics aggregation import { Counter, Histogram } from 'prom-client';

const requestCounter = new Counter({ name: 'http_requests_total', help: 'Total HTTP requests', labelNames: ['method', 'path', 'status'], });

const requestDuration = new Histogram({ name: 'http_request_duration_seconds', help: 'HTTP request duration', labelNames: ['method', 'path'], });

anti_patterns:

name: Console.log in Production description: Using console.log instead of structured logging why: No timestamps, no levels, no structure. Can't search, can't filter, can't alert. When incident happens, you have noise instead of signal. instead: Use structured logger (pino, winston). Configure before first line of application code. Never console.log in production.
name: Logging Sensitive Data description: Passwords, tokens, or PII in log files why: Logs get aggregated, stored, searched. Access controls are looser than databases. One log line with a password compromises account. Years of logs, years of exposure. instead: Configure redaction paths. Review logs for sensitive data. Mask PII in audit logs. Never log authentication credentials.
name: No Correlation IDs description: Logs without request tracing across services why: User reports error. You have 1000 servers. Which logs are relevant? Search by time? Thousands of results. Search by user? Need to correlate across services. Without correlation ID, debugging is archaeology. instead: Generate correlation ID at edge. Pass through all services. Include in every log. Return in error responses for support.
name: Logging Inside Hot Paths description: Debug logging in loops or frequently called functions why: Log 1000 items, 1000 log writes. Synchronous logging blocks event loop. Memory pressure from log objects. Application slows, logs fill disk, cascading failure. instead: Log aggregates, not items. Sample high-volume logs. Use metrics for counters. Check log level before expensive operations.
name: String Concatenation Logs description: Building log messages with string concatenation why: '"User " + userId + " failed" - no structure. Can''t filter by userId. Can''t aggregate. Can''t parse automatically. Debugging requires grep and regex.' instead: Structured logging with objects. logger.info({ userId }, 'User failed'). Every field searchable. Every field filterable.
name: Swallowing Errors description: Catching exceptions but not logging them why: catch (e) { return null; }. Error happened. Nobody knows. Production breaks. Debugging starts. No logs of the actual failure. Silent failures are the worst failures. instead: Always log caught exceptions. Include stack trace. Include context. Rethrow or handle, but always record.

handoffs:

trigger: observability or monitoring to: observability-sre context: User needs full observability beyond logging
trigger: security or audit to: security-hardening context: User needs security-focused logging
trigger: performance or metrics to: performance-optimization context: User needs performance monitoring
trigger: backend or api to: backend context: User needs backend logging implementation