Skip to content

LOGGING_IMPLEMENTATION.md

Latest commit

 

History

History
440 lines (345 loc) · 12.3 KB

LOGGING_IMPLEMENTATION.md

File metadata and controls

440 lines (345 loc) · 12.3 KB
Raw

Comprehensive Request/Response Logging Implementation

Overview

Nest.js backend now has production-grade request/response logging with:

  • Correlation IDs — unique ID per request for distributed tracing
  • Structured logging — JSON logs via Pino for machine parsing
  • Sensitive data sanitization — automatic redaction of secrets, passwords, tokens
  • Performance tracking — request duration logged on every response
  • APM integration ready — correlation IDs forwarded to Sentry/DataDog/etc.
  • Log retention — configurable via pino transports (file, S3, CloudWatch, etc.)

Components

1. Correlation ID Middleware

File: src/common/middleware/correlation-id.middleware.ts

  • Runs first on every request
  • Generates or accepts X-Correlation-ID from client headers
  • Attaches to req.correlationId for downstream use
  • Echoes back in response headers for client tracing
  • Records request start time for duration calculation

Client Usage:

curl -H "X-Correlation-ID: abc123" http://localhost:3001/api/health
# Response includes: X-Correlation-ID: abc123

2. Correlation ID Interceptor

File: src/common/interceptors/correlation-id.interceptor.ts

  • Safety net to ensure ID exists even if middleware is bypassed
  • Augments pino logger context so correlation ID appears in all logs

3. Request Logging Interceptor

File: src/common/interceptors/request-logging.interceptor.ts

  • Logs incoming request: method, URL, IP, user agent, user ID, wallet address (masked)
  • Logs outgoing response: status code, duration, content length
  • Logs errors: stack trace (server errors only), error name, message
  • Skips noisy paths: /api/health, /api/metrics, /favicon.ico
  • Uses pino for structured JSON logs

Log Format:

{
  "msg": "→ POST /api/v2/auth/login",
  "type": "REQUEST",
  "correlationId": "a1b2c3d4-...",
  "method": "POST",
  "url": "/api/v2/auth/login",
  "ip": "192.168.1.100",
  "userAgent": "Mozilla/5.0...",
  "timestamp": "2026-06-02T10:15:30.123Z"
}
{
  "msg": "← POST /api/v2/auth/login 200 (145ms)",
  "type": "RESPONSE",
  "correlationId": "a1b2c3d4-...",
  "method": "POST",
  "url": "/api/v2/auth/login",
  "statusCode": 200,
  "duration": 145,
  "userId": "user_123",
  "timestamp": "2026-06-02T10:15:30.268Z"
}

4. Log Sanitizer Service

File: src/common/services/log-sanitizer.service.ts

Automatically redacts:

  • Headers: Authorization, Cookie, Set-Cookie, X-API-Key, Proxy-Authorization
  • Body fields: password, secret, token, privateKey, mnemonic, seedPhrase, apiKey, otp, pin, cvv, ssn
  • Stellar secret keys: Detects S[A-Z2-7]{55} pattern → [STELLAR_SECRET_REDACTED]
  • Long values: Truncates to 500 chars → ...[truncated]
  • Wallet addresses: Masks to GABCDE...XY01 (first 6 + last 4)

Methods:

  • sanitizeHeaders(headers) — redact sensitive headers
  • sanitizeBody(body) — deep redact sensitive fields
  • sanitizeUrl(url) — remove tokens from query strings
  • maskAddress(address) — privacy-safe address logging

5. Pino Configuration

File: src/app.module.ts (LoggerModule.forRootAsync)

Features:

  • Correlation ID injection — every log line includes correlationId via customProps
  • Redaction — auto-redacts req.headers.authorization, req.body.password, etc.
  • Serializers — structured req/res/err objects
  • Pretty printing in dev — pino-pretty with custom format: [{correlationId}] {msg}
  • JSON logs in production — machine-parsable for log aggregation

6. HTTP Exception Filter

File: src/common/filters/http-exception.filter.ts

Now includes correlationId in all error responses:

{
  "success": false,
  "statusCode": 404,
  "correlationId": "a1b2c3d4-...",
  "timestamp": "2026-06-02T10:15:30.456Z",
  "path": "/api/v2/users/999",
  "message": "User not found"
}

Distributed Tracing

Propagating Correlation IDs Across Services:

When making HTTP calls to other services (e.g., Horizon, Soroban RPC, internal microservices), forward the correlation ID:

import { Request } from 'express';

@Injectable()
export class MyService {
  async callExternalApi(request: Request) {
    const correlationId = (request as any).correlationId;

    const response = await fetch('https://external-api.com/data', {
      headers: {
        'X-Correlation-ID': correlationId,
        'Content-Type': 'application/json',
      },
    });

    return response.json();
  }
}

APM Integration (Sentry, DataDog, New Relic):

Correlation IDs are automatically included in all pino logs. Configure your log shipper (Fluentd, Logstash, CloudWatch Logs, etc.) to parse correlationId and send to your APM:

# Example: Fluentd config to forward logs to DataDog
<source>
  @type tail
  path /var/log/nestera-api.log
  format json
  tag nestera.api
</source>

<match nestera.api>
  @type datadog
  api_key YOUR_DATADOG_API_KEY
  service nestera-api
  dd_source nestjs
  dd_tags env:production,service:api
</match>

Log Retention

Pino supports multiple transports for log shipping:

Option 1: File Rotation (Local)

npm install pino-roll

Update app.module.ts:

transport: {
  target: 'pino-roll',
  options: {
    file: '/var/log/nestera-api.log',
    frequency: 'daily',
    mkdir: true,
    size: '100m', // Rotate when file reaches 100MB
  },
},

Option 2: AWS CloudWatch

npm install pino-cloudwatch
transport: {
  target: 'pino-cloudwatch',
  options: {
    logGroupName: '/aws/lambda/nestera-api',
    logStreamName: 'production',
    awsRegion: 'us-east-1',
    awsAccessKeyId: process.env.AWS_ACCESS_KEY_ID,
    awsSecretAccessKey: process.env.AWS_SECRET_ACCESS_KEY,
  },
},

Option 3: Fluentd/Logstash (Production Standard)

Configure pino to write JSON to stdout, then ship via Fluentd/Logstash to:

  • ElasticSearch (ELK stack)
  • Splunk
  • DataDog
  • New Relic
  • Sumo Logic

No pino config change needed — just pipe stdout to your log shipper.

Option 4: S3 Archival

Use pino-s3 for long-term archival:

npm install pino-s3
transport: {
  target: 'pino-s3',
  options: {
    bucket: 'nestera-logs',
    region: 'us-east-1',
    prefix: 'api-logs/',
  },
},

Environment Variables

Add to .env:

# Logging Configuration
LOG_LEVEL=info                    # debug | info | warn | error
LOG_RETENTION_DAYS=30             # For file-based rotation
LOG_CLOUDWATCH_GROUP=/aws/nestera/api  # For CloudWatch
LOG_S3_BUCKET=nestera-logs        # For S3 archival

# APM Integration
SENTRY_DSN=https://...            # Error tracking
DATADOG_API_KEY=...               # APM/metrics
NEW_RELIC_LICENSE_KEY=...         # APM

Usage in Code

Access Correlation ID in Services

import { Inject, Injectable } from '@nestjs/common';
import { REQUEST } from '@nestjs/core';
import { Request } from 'express';

@Injectable()
export class MyService {
  constructor(@Inject(REQUEST) private readonly request: Request) {}

  async doSomething() {
    const correlationId = (this.request as any).correlationId;
    console.log(`[${correlationId}] Processing request...`);
  }
}

Log with Pino

import { Logger } from 'nestjs-pino';

@Injectable()
export class MyService {
  constructor(private readonly logger: Logger) {}

  async processPayment(amount: number) {
    this.logger.log({
      msg: 'Processing payment',
      amount,
      currency: 'USD',
    });

    // correlationId is automatically added by pino
  }
}

Sanitize Before Logging

import { LogSanitizerService } from './common/services/log-sanitizer.service';

@Injectable()
export class MyService {
  constructor(private readonly sanitizer: LogSanitizerService) {}

  logUserData(user: any) {
    const sanitized = this.sanitizer.sanitizeBody(user);
    console.log('User data:', sanitized);
    // password, secret, privateKey are [REDACTED]
  }
}

Testing

Check Correlation ID Propagation:

curl -i -H "X-Correlation-ID: test123" http://localhost:3001/api/health
# Response should include: x-correlation-id: test123

Check Logs:

# Dev mode (pretty printed)
npm run start:dev

# Logs show:
# [test123] → GET /api/health
# [test123] ← GET /api/health 200 (5ms)

Production Logs (JSON):

NODE_ENV=production npm start
# {"level":30,"correlationId":"test123","msg":"→ GET /api/health",...}

Migration Notes

Existing interceptors updated:

  • RequestLoggingInterceptor — now uses pino + sanitizer
  • CorrelationIdInterceptor — simplified (middleware does heavy lifting)

New components:

  • LogSanitizerService — sensitive data redaction
  • CorrelationIdMiddleware — upgraded to set start time

Breaking changes: None — all changes are additive or internal improvements.

Performance Impact

  • Negligible — correlation ID generation is ~1μs
  • Log sanitization only runs if LogSanitizerService is injected
  • Pino is one of the fastest Node.js loggers (benchmarked)
  • Health check paths skipped from verbose logging

Security

✅ Passwords never logged — redacted automatically
✅ Stellar secret keys never logged — detected & redacted
✅ Authorization headers redacted — JWT tokens not exposed
✅ Query string tokens redacted — ?token=xyz → ?token=[REDACTED]
✅ Wallet addresses masked — only first 6 + last 4 chars
✅ PII compliant — no SSN, card numbers, or sensitive fields logged

Troubleshooting

Correlation ID missing in logs?

  • Check middleware is registered: app.configure() in app.module.ts
  • Verify pino customProps config includes correlationId

Sensitive data still appearing?

  • Check LogSanitizerService is registered in CommonModule
  • Add new sensitive fields to SENSITIVE_BODY_KEYS set

Logs not shipping to APM?

  • Verify pino transport config matches APM requirements
  • Check environment variables (API keys, region, etc.)
  • Test with console.log to ensure stdout is captured

Audit Log Database Retention Policy

The audit log entries stored in the database (audit_logs table) are subject to a configurable retention policy separate from the Pino log transport layer above.

Retention Configuration

Variable Default Description
audit.retentionDays 90 How long (in days) audit log rows are kept in the primary database

Configured via environment or config:

# .env
AUDIT_RETENTION_DAYS=90

Cleanup

The AdminAuditLogsService.cleanupOldLogs() method deletes rows older than retentionDays:

  • Called on-demand via POST /admin/audit-logs/cleanup
  • Deletes all rows where timestamp < NOW() - retentionDays
  • Returns the count of deleted rows

Archival (Automated)

The AdminAuditLogsArchivalService runs daily at 01:00 UTC via a @Cron('0 1 * * *') scheduled task:

  1. Batch read — fetches logs older than retention in batches of 10,000 (configurable via audit.archivalBatchSize)
  2. Local file — writes each batch to a JSONL file (audit-logs-{timestamp}.jsonl)
  3. Compression — gzips the file (enabled by default via audit.compression.enabled)
  4. Cold storage — uploads to S3 Glacier when audit.coldStorage.enabled is true (requires audit.coldStorage.s3Bucket, awsAccessKeyId, awsSecretAccessKey)
  5. Deletion — removes the archived rows from the primary database

Cold Storage Configuration

AUDIT_COLD_STORAGE_ENABLED=true
AUDIT_COLD_STORAGE_S3_BUCKET=nestera-audit-logs
AUDIT_COLD_STORAGE_REGION=us-east-1
AUDIT_COLD_STORAGE_AWS_ACCESS_KEY_ID=...
AUDIT_COLD_STORAGE_AWS_SECRET_ACCESS_KEY=...
AUDIT_COMPRESSION_ENABLED=true
AUDIT_ARCHIVE_PATH=/var/archive/audit-logs
AUDIT_ARCHIVAL_BATCH_SIZE=10000

Verification

Query retention policy status:

GET /admin/audit-logs/retention-policy
# → { "retentionDays": 90, "configured": true }

Query archival statistics:

GET /admin/audit-logs/stats
# → { totalLogsInDb, logsOlderThanRetention, retentionDays, estimatedStorageGb }

Future Enhancements

  • Add request/response size tracking
  • Implement log sampling for high-traffic endpoints
  • Add trace ID for multi-hop distributed tracing (OpenTelemetry)
  • Integrate with Jaeger/Zipkin for full trace visualization
  • Add performance budgets (alert if p95 > threshold)