tessl/npm-winston

A comprehensive, multi-transport logging library for Node.js applications providing flexible and extensible logging capabilities.

—

Pending

Overview

Eval results

Files

Profiling

Name: tessl/npm-winston
Author: tessl

Built-in profiling utilities for measuring operation performance and logging execution times.

Capabilities

Profiler Class

Class for measuring execution time of operations and logging performance metrics.

/**
 * Profiler for measuring operation execution time
 */
class Profiler {
  constructor(logger: Logger);
  
  /** Associated logger instance */
  logger: Logger;
  /** Start timestamp in milliseconds */
  start: number;
}

Profiler Methods

Methods for completing profiling measurements and logging results.

/**
 * Complete the profiling measurement and log the duration
 * @param args - Optional arguments, last one can be info object
 * @returns Boolean indicating success
 */
done(...args: any[]): boolean;

Usage Examples:

const winston = require('winston');

const logger = winston.createLogger({
  transports: [new winston.transports.Console()]
});

// Manual profiler creation
const profiler = new winston.Profiler(logger);

// Simulate some work
setTimeout(() => {
  profiler.done('Database query completed');
  // Logs: { level: 'info', message: 'Database query completed', durationMs: 1002 }
}, 1000);

// With custom info object
const profiler2 = new winston.Profiler(logger);
setTimeout(() => {
  profiler2.done({
    message: 'API request processed',
    level: 'debug',
    operation: 'getUserData',
    userId: 123
  });
  // Logs with durationMs added to the info object
}, 500);

Logger Profiling Methods

Built-in profiling methods available on Logger instances for convenient performance measurement.

/**
 * Start a timer and return a Profiler instance
 * @returns Profiler instance for measuring duration
 */
startTimer(): Profiler;

/**
 * Profile an operation by ID, logging start and completion
 * @param id - Unique identifier for the operation
 * @param meta - Optional metadata for the profile log
 * @returns Logger instance for chaining
 */
profile(id: string | number, meta?: Record<string, any>): Logger;

Usage Examples:

const winston = require('winston');

const logger = winston.createLogger({
  transports: [new winston.transports.Console()]
});

// Using startTimer
const timer = logger.startTimer();
// ... perform some operation
timer.done('Operation completed');

// Using profile method
logger.profile('database-query');
// ... perform database query
logger.profile('database-query'); // Logs the duration

// Profile with metadata
logger.profile('api-request', { endpoint: '/users', method: 'GET' });
// ... process API request
logger.profile('api-request', { endpoint: '/users', method: 'GET' });

Global Profiling Methods

Profiling methods available on the winston module using the default logger.

/**
 * Start a timer using the default logger
 * @returns Profiler instance
 */
function startTimer(): Profiler;

/**
 * Profile an operation using the default logger
 * @param id - Unique identifier for the operation
 * @param meta - Optional metadata
 * @returns Default logger instance
 */
function profile(id: string | number, meta?: Record<string, any>): Logger;

Usage Examples:

const winston = require('winston');

// Configure default logger
winston.add(new winston.transports.Console());

// Global profiling
const timer = winston.startTimer();
// ... perform operation
timer.done('Global operation completed');

// Global profile method
winston.profile('global-task');
// ... perform task
winston.profile('global-task');

Advanced Profiling Patterns

Multiple concurrent profiles:

const winston = require('winston');

const logger = winston.createLogger({
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.json()
  ),
  transports: [new winston.transports.Console()]
});

class PerformanceTracker {
  constructor(logger) {
    this.logger = logger;
    this.activeProfiles = new Map();
  }

  start(operationId, metadata = {}) {
    const timer = this.logger.startTimer();
    this.activeProfiles.set(operationId, {
      timer,
      metadata,
      startTime: Date.now()
    });
    
    this.logger.info('Operation started', {
      operationId,
      ...metadata
    });
  }

  end(operationId, additionalData = {}) {
    const profile = this.activeProfiles.get(operationId);
    if (profile) {
      profile.timer.done({
        message: 'Operation completed',
        operationId,
        ...profile.metadata,
        ...additionalData
      });
      
      this.activeProfiles.delete(operationId);
    }
  }

  checkpoint(operationId, checkpointName) {
    const profile = this.activeProfiles.get(operationId);
    if (profile) {
      const elapsed = Date.now() - profile.startTime;
      this.logger.info('Operation checkpoint', {
        operationId,
        checkpoint: checkpointName,
        elapsedMs: elapsed,
        ...profile.metadata
      });
    }
  }
}

// Usage
const tracker = new PerformanceTracker(logger);

tracker.start('user-registration', { userId: 123 });
// ... validate input
tracker.checkpoint('user-registration', 'validation-complete');
// ... save to database  
tracker.checkpoint('user-registration', 'database-save-complete');
// ... send email
tracker.end('user-registration', { emailSent: true });

HTTP request profiling middleware:

const winston = require('winston');

const logger = winston.createLogger({
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.json()
  ),
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({ filename: 'performance.log' })
  ]
});

// Express middleware for request profiling
const profileRequests = (req, res, next) => {
  const requestId = req.headers['x-request-id'] || Date.now().toString();
  const timer = logger.startTimer();
  
  req.requestId = requestId;
  req.startTime = Date.now();
  
  logger.info('Request started', {
    requestId,
    method: req.method,
    url: req.url,
    userAgent: req.headers['user-agent'],
    ip: req.ip
  });

  // Override res.end to capture response time
  const originalEnd = res.end;
  res.end = function(...args) {
    timer.done({
      message: 'Request completed',
      requestId,
      method: req.method,
      url: req.url,
      statusCode: res.statusCode,
      contentLength: res.get('content-length') || 0
    });
    
    originalEnd.apply(this, args);
  };

  next();
};

module.exports = profileRequests;

Database query profiling:

const winston = require('winston');

const logger = winston.createLogger({
  transports: [new winston.transports.Console()]
});

class DatabaseProfiler {
  constructor(logger) {
    this.logger = logger;
  }

  async profileQuery(queryName, queryFn, queryParams = {}) {
    const timer = this.logger.startTimer();
    const startTime = Date.now();
    
    this.logger.debug('Database query started', {
      query: queryName,
      params: queryParams
    });

    try {
      const result = await queryFn();
      
      timer.done({
        message: 'Database query completed',
        query: queryName,
        params: queryParams,
        resultCount: Array.isArray(result) ? result.length : 1,
        level: 'debug'
      });
      
      return result;
    } catch (error) {
      const elapsed = Date.now() - startTime;
      
      this.logger.error('Database query failed', {
        query: queryName,
        params: queryParams,
        error: error.message,
        durationMs: elapsed
      });
      
      throw error;
    }
  }
}

// Usage
const dbProfiler = new DatabaseProfiler(logger);

async function getUserById(userId) {
  return await dbProfiler.profileQuery(
    'getUserById',
    () => database.users.findById(userId),
    { userId }
  );
}

async function getOrdersByUser(userId, limit = 10) {
  return await dbProfiler.profileQuery(
    'getOrdersByUser',
    () => database.orders.findByUserId(userId, limit),
    { userId, limit }
  );
}

Performance monitoring with thresholds:

const winston = require('winston');

const logger = winston.createLogger({
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.json()
  ),
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({ filename: 'performance.log' })
  ]
});

class PerformanceMonitor {
  constructor(logger, thresholds = {}) {
    this.logger = logger;
    this.thresholds = {
      warn: 1000,  // 1 second
      error: 5000, // 5 seconds
      ...thresholds
    };
  }

  profile(operationName, operation, metadata = {}) {
    return new Promise((resolve, reject) => {
      const timer = this.logger.startTimer();
      const startTime = Date.now();

      Promise.resolve(operation())
        .then(result => {
          const duration = Date.now() - startTime;
          const level = this.getLogLevel(duration);
          
          timer.done({
            message: `Operation ${operationName} completed`,
            operation: operationName,
            level,
            ...metadata,
            performanceFlag: duration > this.thresholds.warn ? 'SLOW' : 'NORMAL'
          });

          resolve(result);
        })
        .catch(error => {
          const duration = Date.now() - startTime;
          
          this.logger.error(`Operation ${operationName} failed`, {
            operation: operationName,
            error: error.message,
            durationMs: duration,
            ...metadata
          });

          reject(error);
        });
    });
  }

  getLogLevel(duration) {
    if (duration >= this.thresholds.error) return 'error';
    if (duration >= this.thresholds.warn) return 'warn';
    return 'info';
  }
}

// Usage
const monitor = new PerformanceMonitor(logger, {
  warn: 500,  // 500ms
  error: 2000 // 2 seconds
});

// Monitor async operations
monitor.profile('file-processing', async () => {
  const data = await fs.readFile('large-file.txt');
  return processData(data);
}, { fileSize: '10MB' });

// Monitor API calls
monitor.profile('external-api-call', () => {
  return fetch('https://api.example.com/data');
}, { endpoint: '/data' });

Install with Tessl CLI