Assist_Design/docs/operations/logging.md

# Centralized Logging System

This guide covers the centralized, high-performance logging system implemented using **Pino** - the fastest JSON logger for Node.js applications.

---

## Architecture Overview

### Single Logger System

- **Backend (BFF)**: `nestjs-pino` with Pino
- **Frontend**: Custom structured logger compatible with backend
- **Shared**: Common interfaces and configurations

### Benefits

- **Performance**: Pino is 5x faster than winston
- **Security**: Automatic sensitive data sanitization
- **Structured**: JSON logging for better parsing
- **Correlation**: Request tracking across services
- **Monitoring**: Easy integration with log aggregation

---

## Log Levels

| Level   | Numeric | What You'll See      | Best For               |
| ------- | ------- | -------------------- | ---------------------- |
| `error` | 0       | Only critical errors | Production monitoring  |
| `warn`  | 1       | Warnings + errors    | Quiet development      |
| `info`  | 2       | General operations   | **Normal development** |
| `debug` | 3       | Detailed debugging   | Troubleshooting issues |
| `trace` | 4       | Very verbose tracing | Deep debugging         |

---

## Configuration

### Environment Variables

```bash
# Core logging
LOG_LEVEL="info"                    # Main log level
DISABLE_HTTP_LOGGING="false"        # Set to "true" to disable HTTP logs entirely

# Application context
APP_NAME="customer-portal-bff"      # Service name in logs
NODE_ENV="development"              # Affects log formatting
```

### Using the Script

```bash
# Check current level
./scripts/set-log-level.sh

# Set to minimal logging (production-like)
./scripts/set-log-level.sh warn

# Set to normal development logging
./scripts/set-log-level.sh info

# Set to detailed debugging
./scripts/set-log-level.sh debug
```

---

## Implementation

### Backend (BFF) - NestJS + Pino

```typescript
// ✅ CORRECT: Use nestjs-pino Logger
import { Logger } from "nestjs-pino";

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

  async findUser(id: string) {
    this.logger.info(`Finding user ${id}`);
    // ... implementation
  }
}
```

### Frontend - Structured Logger

```typescript
// ✅ CORRECT: Use shared logger interface
import { logger } from "@/lib/logger";

export function handleApiCall() {
  logger.logApiCall("/api/users", "GET", 200, 150);
  logger.logUserAction("user123", "login");
}
```

---

## Usage Examples

### Basic Logging

```typescript
// Simple messages
logger.info("User authentication successful");
logger.warn("Rate limit approaching");
logger.error("Database connection failed");

// With structured data
logger.info("Invoice created", {
  invoiceId: "INV-001",
  amount: 99.99,
  userId: "user123",
});
```

### API Call Logging

```typescript
logger.logApiCall("/api/invoices", "POST", 201, 250, {
  userId: "user123",
  invoiceId: "INV-001",
});
```

### User Action Logging

```typescript
logger.logUserAction("user123", "password_change", {
  ipAddress: "192.168.1.1",
  userAgent: "Mozilla/5.0...",
});
```

### Error Logging

```typescript
try {
  // ... operation
} catch (error) {
  logger.logError(error, "user_creation", {
    userId: "user123",
    email: "user@example.com",
  });
}
```

---

## Request Correlation

### Automatic Correlation IDs

```typescript
// Every request gets a unique correlation ID
// Headers: x-correlation-id: 1703123456789-abc123def

logger.info("Processing request", {
  correlationId: req.headers["x-correlation-id"],
  endpoint: req.url,
  method: req.method,
});
```

### Manual Correlation

```typescript
// Set correlation context
logger.setCorrelationId("req-123");
logger.setUserId("user-456");
logger.setRequestId("req-789");

// All subsequent logs include this context
logger.info("User action completed");
```

---

## What's Been Optimized

### Reduced Noise

- **HTTP requests/responses**: Filtered out health checks, static assets
- **Request bodies**: Hidden by default (security + noise reduction)
- **Response bodies**: Hidden by default (reduces overwhelming output)
- **Session checks**: Frequent `/api/auth/session` calls ignored

### Cleaner Output

- **Pretty formatting**: Colored, timestamped logs in development
- **Message focus**: Emphasizes actual log messages over metadata
- **Structured data**: Still available but not overwhelming

### Security Enhanced

- **Sensitive data**: Automatically redacted (tokens, passwords, etc.)
- **Production ready**: No debug info exposed to customers

---

## Production Logging

### Structured JSON Output

```json
{
  "timestamp": "2025-01-22T10:30:00.000Z",
  "level": "info",
  "service": "customer-portal-bff",
  "environment": "production",
  "message": "User authentication successful",
  "correlationId": "req-123",
  "userId": "user-456",
  "data": {
    "ipAddress": "192.168.1.1",
    "userAgent": "Mozilla/5.0..."
  }
}
```

### File Logging

```
# Automatic log rotation
- Combined logs: logs/customer-portal-bff-combined.log
- Error logs: logs/customer-portal-bff-error.log
- Console output: stdout (for container logs)
```

---

## Security Features

### Automatic Data Sanitization

```typescript
// Sensitive data is automatically redacted
logger.info("User login", {
  email: "user@example.com",
  password: "[REDACTED]", // Automatically sanitized
  token: "[REDACTED]", // Automatically sanitized
  ipAddress: "192.168.1.1", // Safe to log
});
```

### Sanitized Headers

```json
{
  "authorization": "[REDACTED]",
  "cookie": "[REDACTED]",
  "x-api-key": "[REDACTED]",
  "user-agent": "Mozilla/5.0...",
  "accept": "application/json"
}
```

---

## What NOT to Do

### Don't Use Multiple Logging Systems

```typescript
// ❌ WRONG: Mixing logging systems
import { Logger } from "@nestjs/common"; // Don't use this

// ✅ CORRECT: Use centralized logger
import { Logger } from "nestjs-pino";
```

### Don't Use Console Methods

```typescript
// ❌ WRONG: Direct console usage
console.log("Debug info");
console.error("Error occurred");

// ✅ CORRECT: Structured logging
logger.debug("Debug info");
logger.error("Error occurred");
```

---

## Performance Benefits

### Benchmarks (Pino vs Winston)

| Operation            | Pino | Winston | Improvement   |
| -------------------- | ---- | ------- | ------------- |
| JSON serialization   | 1x   | 5x      | **5x faster** |
| Object serialization | 1x   | 3x      | **3x faster** |
| String interpolation | 1x   | 2x      | **2x faster** |
| Overall performance  | 1x   | 5x      | **5x faster** |

---

## Common Scenarios

| Need                  | Command                            |
| --------------------- | ---------------------------------- |
| Too much noise        | `./scripts/set-log-level.sh warn`  |
| Debugging issues      | `./scripts/set-log-level.sh debug` |
| Normal development    | `./scripts/set-log-level.sh info`  |
| Production monitoring | `./scripts/set-log-level.sh error` |

After changing log levels, restart your development server for changes to take effect.

---

## Best Practices

### Do's

- Use structured logging with context
- Include correlation IDs in all logs
- Log at appropriate levels
- Sanitize sensitive data
- Use consistent message formats

### Don'ts

- Don't mix logging systems
- Don't use console methods in production
- Don't log sensitive information
- Don't log large objects unnecessarily
- Don't use string interpolation for logging