Logging | Backend Developer | Ephizen

Why Logging Matters#

It's 3am. Your API is down. Users are complaining. You need to figure out what's happening.

Without logs: "Something's broken... somewhere... somehow..."

With logs: "Ah, the payment service started timing out at 2:47am after we hit 1000 concurrent users."

Logs are your debugging lifeline in production.

Console.log is Not Enough#

javascript

// Development - fine
console.log('User created:', user);

// Production - problems
// - No timestamps
// - No log levels
// - No structured data
// - Goes to stdout (hard to search)
// - Performance issues with sync logging

Pino: Fast Structured Logging#

Pino is the fastest Node.js logger. It outputs JSON for easy parsing:

bash

npm install pino pino-pretty

javascript

// src/utils/logger.js
import pino from 'pino';
import { config } from '../config/index.js';

export const logger = pino({
  level: config.logLevel || 'info',

  // Pretty print in development
  transport: config.env === 'development'
    ? {
        target: 'pino-pretty',
        options: {
          colorize: true,
          translateTime: 'SYS:standard',
          ignore: 'pid,hostname',
        },
      }
    : undefined,
});

Basic Usage#

javascript

import { logger } from '../utils/logger.js';

// Different levels
logger.trace('Very detailed info');
logger.debug('Debug info');
logger.info('Normal info');
logger.warn('Warning');
logger.error('Error');
logger.fatal('Fatal error');

// With data
logger.info({ userId: '123', action: 'login' }, 'User logged in');

// With error
logger.error({ err: error, userId: '123' }, 'Login failed');

Output#

Development (pretty):

[14:23:45] INFO: User logged in
    userId: "123"
    action: "login"

Production (JSON):

json

{"level":30,"time":1640000000000,"userId":"123","action":"login","msg":"User logged in"}

Log Levels#

Level	Number	When to Use
trace	10	Very detailed debugging
debug	20	Debugging info
info	30	Normal operations
warn	40	Something unusual happened
error	50	Something failed
fatal	60	App is crashing

Set level via environment:

bash

# Development - see everything
LOG_LEVEL=debug

# Production - only important stuff
LOG_LEVEL=info

javascript

// Only logs at level and above are output
logger.level = 'info';
logger.debug('Not shown');
logger.info('Shown');
logger.error('Shown');

Structured Logging#

Always log structured data, not string concatenation:

javascript

// BAD - hard to parse and search
logger.info(`User ${userId} logged in from ${ip} at ${new Date()}`);

// GOOD - structured, searchable
logger.info({
  userId,
  ip,
  action: 'login',
}, 'User logged in');

Why structured?

Searchable: Query userId:123 in your log system
Parseable: Tools can extract fields automatically
Consistent: Same format everywhere

Request Logging Middleware#

Log every request automatically:

javascript

// src/middleware/requestLogger.js
import { logger } from '../utils/logger.js';
import { randomUUID } from 'crypto';

export function requestLogger(req, res, next) {
  // Generate unique request ID
  req.id = req.headers['x-request-id'] || randomUUID();

  // Create child logger with request context
  req.log = logger.child({
    requestId: req.id,
    method: req.method,
    path: req.path,
  });

  const start = Date.now();

  // Log when response finishes
  res.on('finish', () => {
    const duration = Date.now() - start;

    const logData = {
      statusCode: res.statusCode,
      duration,
      userAgent: req.headers['user-agent'],
      ip: req.ip,
    };

    if (res.statusCode >= 500) {
      req.log.error(logData, 'Request failed');
    } else if (res.statusCode >= 400) {
      req.log.warn(logData, 'Request error');
    } else {
      req.log.info(logData, 'Request completed');
    }
  });

  next();
}

Use it:

javascript

// src/app.js
import { requestLogger } from './middleware/requestLogger.js';

app.use(requestLogger);

Error Logging#

Log errors with full context:

javascript

// src/middleware/error.js
import { logger } from '../utils/logger.js';

export function errorHandler(err, req, res, next) {
  // Log the error
  logger.error({
    err,
    requestId: req.id,
    method: req.method,
    path: req.path,
    body: req.body, // Be careful with sensitive data
    userId: req.user?.id,
  }, err.message);

  // Send response
  res.status(err.statusCode || 500).json({
    error: {
      message: err.message || 'Internal server error',
      requestId: req.id, // Help users report issues
    },
  });
}

Child Loggers#

Add context that applies to multiple log calls:

javascript

// Create logger with user context
export function addUserContext(req, res, next) {
  if (req.user) {
    req.log = req.log.child({
      userId: req.user.id,
      userRole: req.user.role,
    });
  }
  next();
}

// Now all logs from this request include user info
req.log.info('Fetching orders'); // Includes userId, userRole automatically

Sensitive Data#

Never log passwords, tokens, or personal info:

javascript

// BAD
logger.info({ password, email, ssn }, 'User created');

// GOOD - exclude sensitive fields
const { password, ...safeUser } = user;
logger.info({ user: safeUser }, 'User created');

// Or use redaction
const logger = pino({
  redact: ['password', 'token', 'authorization', '*.ssn'],
});

Logging in Services#

javascript

// src/services/orders.js
import { logger } from '../utils/logger.js';

export async function createOrder(userId, items) {
  logger.info({ userId, itemCount: items.length }, 'Creating order');

  try {
    const order = await Order.create({ userId, items });
    logger.info({ orderId: order._id, total: order.total }, 'Order created');
    return order;
  } catch (error) {
    logger.error({ err: error, userId, items }, 'Order creation failed');
    throw error;
  }
}

Production Log Management#

In production, logs go to:

File Output#

javascript

// Log to file
const logger = pino(pino.destination('/var/log/app.log'));

// Or use streams
import { createWriteStream } from 'fs';
const logger = pino(createWriteStream('/var/log/app.log'));

Log Aggregation Services#

Send logs to centralized services:

Datadog
Logtail
Papertrail
AWS CloudWatch

javascript

// Example: Pino with transport
const logger = pino({
  transport: {
    target: '@logtail/pino',
    options: {
      sourceToken: process.env.LOGTAIL_TOKEN,
    },
  },
});

Docker/Kubernetes#

Just output to stdout - the platform handles collection:

javascript

// Default pino output to stdout works great
const logger = pino({ level: 'info' });

// Docker and K8s capture stdout automatically

What to Log#

Always Log#

Request start/end with duration
Errors with full context
Authentication events (login, logout, failed attempts)
Important business events (orders, payments)
External service calls

Never Log#

Passwords
Auth tokens
Credit card numbers
Personal info (SSN, etc.)
Full request bodies (might contain sensitive data)

Consider Logging#

Request bodies (sanitized)
Query parameters
Response times
Cache hits/misses

Example: Complete Logger Setup#

javascript

// src/utils/logger.js
import pino from 'pino';
import { config } from '../config/index.js';

const baseConfig = {
  level: config.logLevel || 'info',
  redact: [
    'password',
    'token',
    'authorization',
    'req.headers.authorization',
    '*.password',
    '*.token',
  ],
  serializers: {
    err: pino.stdSerializers.err,
    req: (req) => ({
      method: req.method,
      url: req.url,
      path: req.path,
      params: req.params,
      query: req.query,
    }),
  },
};

const devConfig = {
  ...baseConfig,
  transport: {
    target: 'pino-pretty',
    options: {
      colorize: true,
      translateTime: 'SYS:standard',
      ignore: 'pid,hostname',
    },
  },
};

export const logger = pino(
  config.env === 'development' ? devConfig : baseConfig
);

// Helper for creating request-scoped loggers
export function createRequestLogger(req) {
  return logger.child({
    requestId: req.id,
    method: req.method,
    path: req.path,
  });
}

Key Takeaways#

Use a proper logger - Pino is fast and structured
Log structured data - Objects, not string concatenation
Use log levels - Debug in dev, info in prod
Add request context - Request ID, user ID, method, path
Never log secrets - Use redaction
Log business events - Not just errors

The Rule

If something goes wrong in production, will your logs tell you what happened? If not, add more logging. If your logs are noisy, raise the log level.

Why Logging Matters#

It's 3am. Your API is down. Users are complaining. You need to figure out what's happening.

Without logs: "Something's broken... somewhere... somehow..."

With logs: "Ah, the payment service started timing out at 2:47am after we hit 1000 concurrent users."

Logs are your debugging lifeline in production.

Console.log is Not Enough#

javascript

// Development - fine
console.log('User created:', user);

// Production - problems
// - No timestamps
// - No log levels
// - No structured data
// - Goes to stdout (hard to search)
// - Performance issues with sync logging

Pino: Fast Structured Logging#

Pino is the fastest Node.js logger. It outputs JSON for easy parsing:

bash

npm install pino pino-pretty

javascript

// src/utils/logger.js
import pino from 'pino';
import { config } from '../config/index.js';

export const logger = pino({
  level: config.logLevel || 'info',

  // Pretty print in development
  transport: config.env === 'development'
    ? {
        target: 'pino-pretty',
        options: {
          colorize: true,
          translateTime: 'SYS:standard',
          ignore: 'pid,hostname',
        },
      }
    : undefined,
});

Basic Usage#

javascript

import { logger } from '../utils/logger.js';

// Different levels
logger.trace('Very detailed info');
logger.debug('Debug info');
logger.info('Normal info');
logger.warn('Warning');
logger.error('Error');
logger.fatal('Fatal error');

// With data
logger.info({ userId: '123', action: 'login' }, 'User logged in');

// With error
logger.error({ err: error, userId: '123' }, 'Login failed');

Output#

Development (pretty):

[14:23:45] INFO: User logged in
    userId: "123"
    action: "login"

Production (JSON):

json

{"level":30,"time":1640000000000,"userId":"123","action":"login","msg":"User logged in"}

Log Levels#

Level	Number	When to Use
trace	10	Very detailed debugging
debug	20	Debugging info
info	30	Normal operations
warn	40	Something unusual happened
error	50	Something failed
fatal	60	App is crashing

Set level via environment:

bash

# Development - see everything
LOG_LEVEL=debug

# Production - only important stuff
LOG_LEVEL=info

javascript

// Only logs at level and above are output
logger.level = 'info';
logger.debug('Not shown');
logger.info('Shown');
logger.error('Shown');

Structured Logging#

Always log structured data, not string concatenation:

javascript

// BAD - hard to parse and search
logger.info(`User ${userId} logged in from ${ip} at ${new Date()}`);

// GOOD - structured, searchable
logger.info({
  userId,
  ip,
  action: 'login',
}, 'User logged in');

Why structured?

Searchable: Query userId:123 in your log system
Parseable: Tools can extract fields automatically
Consistent: Same format everywhere

Request Logging Middleware#

Log every request automatically:

javascript

// src/middleware/requestLogger.js
import { logger } from '../utils/logger.js';
import { randomUUID } from 'crypto';

export function requestLogger(req, res, next) {
  // Generate unique request ID
  req.id = req.headers['x-request-id'] || randomUUID();

  // Create child logger with request context
  req.log = logger.child({
    requestId: req.id,
    method: req.method,
    path: req.path,
  });

  const start = Date.now();

  // Log when response finishes
  res.on('finish', () => {
    const duration = Date.now() - start;

    const logData = {
      statusCode: res.statusCode,
      duration,
      userAgent: req.headers['user-agent'],
      ip: req.ip,
    };

    if (res.statusCode >= 500) {
      req.log.error(logData, 'Request failed');
    } else if (res.statusCode >= 400) {
      req.log.warn(logData, 'Request error');
    } else {
      req.log.info(logData, 'Request completed');
    }
  });

  next();
}

Use it:

javascript

// src/app.js
import { requestLogger } from './middleware/requestLogger.js';

app.use(requestLogger);

Error Logging#

Log errors with full context:

javascript

// src/middleware/error.js
import { logger } from '../utils/logger.js';

export function errorHandler(err, req, res, next) {
  // Log the error
  logger.error({
    err,
    requestId: req.id,
    method: req.method,
    path: req.path,
    body: req.body, // Be careful with sensitive data
    userId: req.user?.id,
  }, err.message);

  // Send response
  res.status(err.statusCode || 500).json({
    error: {
      message: err.message || 'Internal server error',
      requestId: req.id, // Help users report issues
    },
  });
}

Child Loggers#

Add context that applies to multiple log calls:

javascript

// Create logger with user context
export function addUserContext(req, res, next) {
  if (req.user) {
    req.log = req.log.child({
      userId: req.user.id,
      userRole: req.user.role,
    });
  }
  next();
}

// Now all logs from this request include user info
req.log.info('Fetching orders'); // Includes userId, userRole automatically

Sensitive Data#

Never log passwords, tokens, or personal info:

javascript

// BAD
logger.info({ password, email, ssn }, 'User created');

// GOOD - exclude sensitive fields
const { password, ...safeUser } = user;
logger.info({ user: safeUser }, 'User created');

// Or use redaction
const logger = pino({
  redact: ['password', 'token', 'authorization', '*.ssn'],
});

Logging in Services#

javascript

// src/services/orders.js
import { logger } from '../utils/logger.js';

export async function createOrder(userId, items) {
  logger.info({ userId, itemCount: items.length }, 'Creating order');

  try {
    const order = await Order.create({ userId, items });
    logger.info({ orderId: order._id, total: order.total }, 'Order created');
    return order;
  } catch (error) {
    logger.error({ err: error, userId, items }, 'Order creation failed');
    throw error;
  }
}

Production Log Management#

In production, logs go to:

File Output#

javascript

// Log to file
const logger = pino(pino.destination('/var/log/app.log'));

// Or use streams
import { createWriteStream } from 'fs';
const logger = pino(createWriteStream('/var/log/app.log'));

Log Aggregation Services#

Send logs to centralized services:

Datadog
Logtail
Papertrail
AWS CloudWatch

javascript

// Example: Pino with transport
const logger = pino({
  transport: {
    target: '@logtail/pino',
    options: {
      sourceToken: process.env.LOGTAIL_TOKEN,
    },
  },
});

Docker/Kubernetes#

Just output to stdout - the platform handles collection:

javascript

// Default pino output to stdout works great
const logger = pino({ level: 'info' });

// Docker and K8s capture stdout automatically

What to Log#

Always Log#

Request start/end with duration
Errors with full context
Authentication events (login, logout, failed attempts)
Important business events (orders, payments)
External service calls

Never Log#

Passwords
Auth tokens
Credit card numbers
Personal info (SSN, etc.)
Full request bodies (might contain sensitive data)

Consider Logging#

Request bodies (sanitized)
Query parameters
Response times
Cache hits/misses

Example: Complete Logger Setup#

javascript

// src/utils/logger.js
import pino from 'pino';
import { config } from '../config/index.js';

const baseConfig = {
  level: config.logLevel || 'info',
  redact: [
    'password',
    'token',
    'authorization',
    'req.headers.authorization',
    '*.password',
    '*.token',
  ],
  serializers: {
    err: pino.stdSerializers.err,
    req: (req) => ({
      method: req.method,
      url: req.url,
      path: req.path,
      params: req.params,
      query: req.query,
    }),
  },
};

const devConfig = {
  ...baseConfig,
  transport: {
    target: 'pino-pretty',
    options: {
      colorize: true,
      translateTime: 'SYS:standard',
      ignore: 'pid,hostname',
    },
  },
};

export const logger = pino(
  config.env === 'development' ? devConfig : baseConfig
);

// Helper for creating request-scoped loggers
export function createRequestLogger(req) {
  return logger.child({
    requestId: req.id,
    method: req.method,
    path: req.path,
  });
}

Key Takeaways#

Use a proper logger - Pino is fast and structured
Log structured data - Objects, not string concatenation
Use log levels - Debug in dev, info in prod
Add request context - Request ID, user ID, method, path
Never log secrets - Use redaction
Log business events - Not just errors

The Rule

If something goes wrong in production, will your logs tell you what happened? If not, add more logging. If your logs are noisy, raise the log level.

Why Logging Matters#

Console.log is Not Enough#

Pino: Fast Structured Logging#

Basic Usage#

Output#

Log Levels#

Structured Logging#

Request Logging Middleware#

Error Logging#

Child Loggers#

Sensitive Data#

Logging in Services#

Production Log Management#

File Output#

Log Aggregation Services#

Docker/Kubernetes#

What to Log#

Always Log#

Never Log#

Consider Logging#

Example: Complete Logger Setup#

Key Takeaways#

Ready to level up your skills?

Why Logging Matters#

Console.log is Not Enough#

Pino: Fast Structured Logging#

Basic Usage#

Output#

Log Levels#

Structured Logging#

Request Logging Middleware#

Error Logging#

Child Loggers#

Sensitive Data#

Logging in Services#

Production Log Management#

File Output#

Log Aggregation Services#

Docker/Kubernetes#

What to Log#

Always Log#

Never Log#

Consider Logging#

Example: Complete Logger Setup#

Key Takeaways#

Ready to level up your skills?