logging-observability

# Logging & Observability

Patterns for building observable systems across the three pillars: logs, metrics, and traces.

## Three Pillars

| Pillar | Purpose | Question It Answers | Example |
|--------|---------|---------------------|---------|
| **Logs** | What happened | Why did this request fail? | `{"level":"error","msg":"payment declined","user_id":"u_82"}` |
| **Metrics** | How much / how fast | Is latency increasing? | `http_request_duration_seconds{route="/api/orders"} 0.342` |
| **Traces** | Request flow | Where is the bottleneck? | Span: `api-gateway → auth → order-service → db` |

Each pillar is strongest when correlated. Embed `trace_id` in every log line to jump from a log entry to the full distributed trace.


## Installation

### OpenClaw / Moltbot / Clawbot

```bash
npx clawhub@latest install logging-observability
```


---

## Structured Logging

Always emit logs as structured JSON — never free-text strings.

### Required Fields

| Field | Purpose | Required |
|-------|---------|----------|
| `timestamp` | ISO-8601 with milliseconds | Yes |
| `level` | Severity (DEBUG … FATAL) | Yes |
| `service` | Originating service name | Yes |
| `message` | Human-readable description | Yes |
| `trace_id` | Distributed trace correlation | Yes |
| `span_id` | Current span within trace | Yes |
| `correlation_id` | Business-level correlation (order ID) | When applicable |
| `error` | Structured error object | On errors |
| `context` | Request-specific metadata | Recommended |

### Context Enrichment

Attach context at the middleware level so downstream logs inherit automatically:

```typescript
app.use((req, res, next) => {
  const ctx = {
    trace_id: req.headers['x-trace-id'] || crypto.randomUUID(),
    request_id: crypto.randomUUID(),
    user_id: req.user?.id,
    method: req.method,
    path: req.path,
  };
  asyncLocalStorage.run(ctx, () => next());
});
```

### Library Recommendations

| Library | Language | Strengths | Perf |
|---------|----------|-----------|------|
| **Pino** | Node.js | Fastest Node logger, low overhead | Excellent |
| **structlog** | Python | Composable processors, context binding | Good |
| **zerolog** | Go | Zero-allocation JSON logging | Excellent |
| **zap** | Go | High performance, typed fields | Excellent |
| **tracing** | Rust | Spans + events, async-aware | Excellent |

Choose a logger that outputs structured JSON natively. Avoid loggers requiring post-processing.

---

## Log Levels

| Level | When to Use | Example |
|-------|-------------|---------|
| **FATAL** | App cannot continue, process will exit | Database connection pool exhausted |
| **ERROR** | Operation failed, needs attention | Payment charge failed: CARD_DECLINED |
| **WARN** | Unexpected but recoverable | Retry 2/3 for upstream timeout |
| **INFO** | Normal business events | Order ORD-1234 placed successfully |
| **DEBUG** | Developer troubleshooting | Cache miss for key user:82:preferences |
| **TRACE** | Very fine-grained (rarely in prod) | Entering validateAddress with payload |

**Rules:** Production default = INFO and above. If you log an ERROR, someone should act on it. Every FATAL should trigger an alert.

---

## Distributed Tracing

### OpenTelemetry Setup

Always prefer OpenTelemetry over vendor-specific SDKs:

```typescript
import { NodeSDK } from '@opentelemetry/sdk-node';
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';

const sdk = new NodeSDK({
  serviceName: 'order-service',
  traceExporter: new OTLPTraceExporter({
    url: 'http://otel-collector:4318/v1/traces',
  }),
  instrumentations: [getNodeAutoInstrumentations()],
});
sdk.start();
```

### Span Creation

```typescript
const tracer = trace.getTracer('order-service');

async function processOrder(order: Order) {
  return tracer.startActiveSpan('processOrder', async (span) => {
    try {
      span.setAttribute('order.id', order.id);
      span.setAttribute('order.total_cents', order.totalCents);
      await validateInventory(order);
      await chargePayment(order);
      span.setStatus({ code: SpanStatusCode.OK });
    } catch (err) {
      span.setStatus({ code: SpanStatusCode.ERROR, message: err.message });
      span.recordException(err);
      throw err;
    } finally {
      span.end();
    }
  });
}
```

### Context Propagation

- Use W3C Trace Context (`traceparent` header) — default in OTel
- Propagate across HTTP, gRPC, and message queues
- For async workers: serialise `traceparent` into the job payload

### Trace Sampling

| Strategy | Use When |
|----------|----------|
| **Always On** | Low-traffic services, debugging |
| **Probabilistic** (N%) | General production use |
| **Rate-limited** (N/sec) | High-throughput services |
| **Tail-based** | When you need all error traces |

Always sample 100% of error traces regardless of strategy.

---

## Metrics Collection

### RED Method (Request-Driven)

Monitor these three for every service endpoint:

| Metric | What It Measures | Prometheus Example |
|--------|-----------------|-------------------|
| **Rate** | Requests/sec | `rate(http_requests_total[5m])` |
| **Errors** | Failed request ratio | `rate(http_requests_total{status=~"5.."}[5m])` |
| **Duration** | Response time | `histogram_quantile(0.99, http_request_duration_seconds)` |

### USE Method (Resource-Driven)

For infrastructure components (CPU, memory, disk, network):

| Metric | What It Measures | Example |
|--------|-----------------|---------|
| **Utilization** | % resource busy | CPU usage at 78% |
| **Saturation** | Work queued/waiting | 12 requests queued in thread pool |
| **Errors** | Error events on resource | 3 disk I/O errors in last minute |

---

## Monitoring Stack

| Tool | Category | Best For |
|------|----------|----------|
| **Prometheus** | Metrics | Pull-based metrics, alerting rules |
| **Grafana** | Visualisation | Dashboards for metrics, logs, traces |
| **Jaeger** | Tracing | Distributed trace visualisation |
| **Loki** | Logs | Log aggregation (pairs with Grafana) |
| **OpenTelemetry** | Collection | Vendor-neutral telemetry collection |

**Recommendation:** Start with OTel Collector → Prometheus + Grafana + Loki + Jaeger. Migrate to SaaS only when operational overhead justifies cost.

---

## Alert Design

### Severity Levels

| Severity | Response Time | Example |
|----------|---------------|---------|
| **P1** | Immediate | Service fully down, data loss |
| **P2** | < 30 min | Error rate > 5%, latency p99 > 5s |
| **P3** | Business hours | Disk > 80%, cert expiring in 7 days |
| **P4** | Best effort | Non-critical deprecation warning |

### Alert Fatigue Prevention

- **Alert on symptoms, not causes** — "error rate > 5%" not "pod restarted"
- **Multi-window, multi-burn-rate** — catch both sudden spikes and slow burns
- **Require runbook links** — every alert must link to diagnosis and remediation
- **Review monthly** — delete or tune alerts that never fire or always fire
- **Group related alerts** — use inhibition rules to suppress child alerts
- **Set appropriate thresholds** — if alert fires daily and is ignored, raise threshold or delete

---

## Dashboard Patterns

### Overview Dashboard ("War Room")
- Total requests/sec across all services
- Global error rate (%) with trendline
- p50 / p95 / p99 latency
- Active alerts count by severity
- Deployment markers overlaid on graphs

### Service Dashboard (Per-Service)
- RED metrics for each endpoint
- Dependency health (upstream/downstream success rates)
- Resource utilisation (CPU, memory, connections)
- Top errors table with count and last seen

---

## Observability Checklist

Every service must have:

- [ ] Structured JSON logging with consistent schema
- [ ] Correlation / trace IDs propagated on all requests
- [ ] RED metrics exposed for every external endpoint
- [ ] Health check endpoints (`/healthz` and `/readyz`)
- [ ] Distributed tracing with OpenTelemetry
- [ ] Dashboards for RED metrics and resource utilisation
- [ ] Alerts for error rate, latency, and saturation with runbook links
- [ ] Log level configurable at runtime without redeployment
- [ ] PII scrubbing verified and tested
- [ ] Retention policies defined for logs, metrics, and traces

## Anti-Patterns

| Anti-Pattern | Problem | Fix |
|-------------|---------|-----|
| Logging PII | Privacy/compliance violation | Mask or exclude PII; use token references |
| Excessive logging | Storage costs balloon, signal drowns | Log business events, not data flow |
| Unstructured logs | Cannot query or alert on fields | Use structured JSON with consistent schema |
| String interpolation | Breaks structured fields, injection risk | Pass fields as metadata, not in message |
| Missing correlation IDs | Cannot trace across services | Generate and propagate trace_id everywhere |
| Alert storms | On-call fatigue, real issues buried | Use grouping, inhibition, deduplication |
| Metrics with high cardinality | Prometheus OOM, dashboard timeouts | Never use user ID or request ID as label |

## NEVER Do

1. **NEVER log passwords, tokens, API keys, or secrets** — even at DEBUG level
2. **NEVER use console.log / print in production** — use a structured logger
3. **NEVER use user IDs, emails, or request IDs as metric labels** — cardinality will explode
4. **NEVER create alerts without a runbook link** — unactionable alerts erode trust
5. **NEVER rely on logs alone** — you need metrics and traces for full observability
6. **NEVER log request/response bodies by default** — opt-in only, with PII redaction
7. **NEVER ignore log volume** — set budgets and alert when a service exceeds daily quota
8. **NEVER skip context propagation in async flows** — broken traces are worse than no traces