feat: Phase 8: Log-trace correlation — trace_id injection, Loki ingestion, Grafana linking

.cspell.config.yaml

@@ -180,6 +180,7 @@ words:
   - libxrpl
   - llection
   - LOCALGOOD
+  - logql
   - logwstream
   - Lombrozo
   - lresolv
@@ -238,6 +239,7 @@ words:
   - onlatest
   - ostr
   - otelc
+  - otelcol
   - otool
   - oxalica
   - pargs

OpenTelemetryPlan/06-implementation-phases.md

@@ -52,6 +52,15 @@ gantt
 
     section Phase 5
     Documentation & Deploy    :p5, after p4, 1w
+
+    section Phase 6
+    StatsD Metrics Bridge     :p6, after p5, 1w
+
+    section Phase 7
+    Native OTel Metrics       :p7, after p6, 2w
+
+    section Phase 8
+    Log-Trace Correlation     :p8, after p7, 1w
 ```
 
 ---
@@ -561,6 +570,154 @@ See [Phase7_taskList.md](./Phase7_taskList.md) for detailed per-task breakdown.
 
 ---
 
+## 6.8.1 Phase 8: Log-Trace Correlation and Centralized Log Ingestion (Week 13)
+
+### Motivation
+
+xrpld's `beast::Journal` logs and OpenTelemetry traces are currently two disjoint observability signals. When investigating an issue, operators must manually correlate timestamps between log files and Jaeger/Tempo traces. Phase 8 bridges this gap by injecting trace context (`trace_id`, `span_id`) into every log line emitted within an active, sampled span, and ingesting those logs into Grafana Loki via the OTel Collector's file_log receiver.
+
+#### Gains
+
+1. **One-click trace-to-log navigation** — Click a trace in Tempo/Jaeger and immediately see the corresponding log lines in Loki, filtered by `trace_id`.
+2. **Reverse lookup (log-to-trace)** — Loki derived fields make `trace_id` values clickable links back to Tempo.
+3. **Unified observability** — All three pillars (traces, metrics, logs) flow through the same OTel Collector pipeline and are visible in a single Grafana instance.
+4. **Zero new dependencies in xrpld** — Uses existing OTel SDK headers (`RuntimeContext`, `SpanContext`) already linked in Phase 1.
+5. **Negligible overhead** — The implementation checks the thread-local context value directly, avoiding heap allocation on the no-span path (~15-20ns). On the active-span path, total cost is ~50ns per log call. At typical logging rates, overhead is negligible.
+
+#### Losses / Risks
+
+1. **Log format change** — Existing log parsers that rely on a fixed format will need updating to handle the optional `trace_id=... span_id=...` fields.
+2. **Loki resource usage** — Log ingestion adds storage and memory overhead to the observability stack (mitigated by retention policies).
+3. **Filelog receiver complexity** — The regex parser must be kept in sync with the log format; a format change in `Logs::format()` could break parsing.
+
+#### Decision
+
+The correlation value far outweighs the risks. The log format change is backward-compatible (fields are appended only when a sampled span is active), and the file_log receiver regex is straightforward to maintain.
+
+### Architecture
+
+Phase 8 has two independent sub-phases that can be developed in parallel:
+
+- **Phase 8a (code change)**: Modify `Logs::format()` in `src/libxrpl/basics/Log.cpp` to append `trace_id=<hex32> span_id=<hex16>` when the current thread has an active OTel span. Guarded by `#ifdef XRPL_ENABLE_TELEMETRY`.
+- **Phase 8b (infra only)**: Add Loki to the Docker Compose stack, configure the OTel Collector's `file_log` receiver to tail xrpld's log file, parse out structured fields (timestamp, partition, severity, trace_id, span_id, message), and export to Loki via OTLP. Configure Grafana Tempo↔Loki bidirectional linking.
+
+#### Trace ID Injection Flow
+
+```mermaid
+flowchart LR
+    subgraph xrpld["xrpld process"]
+        JLOG["`**JLOG(j.info())**
+        a log call on some thread`"]
+        Format["`**Logs::format()**
+        builds the log line`"]
+        OTelCtx["`**OTel thread-local context**
+        RuntimeContext::GetCurrent()
+        GetValue(kSpanKey)`"]
+        JLOG --> Format
+        OTelCtx -.->|"`GetContext()
+        if IsValid and IsSampled`"| Format
+    end
+
+    subgraph output["Log output"]
+        LogLine["`2026-Jan-15 10:30:45.123456789 UTC
+        LedgerMaster:NFO
+        trace_id=abc123... span_id=def456...
+        Validated ledger 42`"]
+    end
+
+    Format --> LogLine
+
+    subgraph legend["Reading the diagram"]
+        direction LR
+        L1["`**Solid arrow**
+        happens on every log call`"]
+        L2["`**Dotted arrow**
+        only adds ids when a sampled span is active on this thread`"]
+        L3["`**kSpanKey lookup**
+        reads the context value directly, so the no-span path allocates nothing`"]
+    end
+
+    L1 ~~~ L2 ~~~ L3
+    output ~~~ legend
+
+    style xrpld fill:#1a237e,stroke:#0d1642,color:#fff
+    style output fill:#1b5e20,stroke:#0d3d14,color:#fff
+    style JLOG fill:#283593,stroke:#1a237e,color:#fff
+    style Format fill:#283593,stroke:#1a237e,color:#fff
+    style OTelCtx fill:#283593,stroke:#1a237e,color:#fff
+    style LogLine fill:#2e7d32,stroke:#1b5e20,color:#fff
+```
+
+#### Loki Ingestion Pipeline
+
+```mermaid
+flowchart LR
+    subgraph collector["OTel Collector"]
+        FR["`**file_log receiver**
+        tails debug.log`"]
+        RP["`**regex_parser**
+        extracts timestamp, partition,
+        severity, trace_id, span_id`"]
+        BP["`**batch processor**`"]
+        LE["`**otlp_http/loki exporter**`"]
+        FR --> RP --> BP --> LE
+    end
+
+    LogFile["`**xrpld**
+    debug.log`"] --> FR
+    LE --> Loki["`**Grafana Loki**
+    :3100`"]
+    Loki <-->|"`derivedFields
+    tracesToLogs`"| Tempo["`**Grafana Tempo**`"]
+
+    subgraph legend["Reading the diagram"]
+        direction LR
+        L1["`**Solid arrow**
+        the path every log line takes`"]
+        L2["`**Double arrow**
+        Grafana links the two backends both ways: a trace jumps to its logs, a trace_id in a log jumps back to the trace`"]
+        L3["`**otlp_http, not otlp**
+        Loki is reached over OTLP/HTTP; the old dedicated loki exporter was removed upstream`"]
+    end
+
+    L1 ~~~ L2 ~~~ L3
+    collector ~~~ legend
+
+    style collector fill:#e65100,stroke:#bf360c,color:#fff
+    style FR fill:#f57c00,stroke:#e65100,color:#fff
+    style RP fill:#f57c00,stroke:#e65100,color:#fff
+    style BP fill:#f57c00,stroke:#e65100,color:#fff
+    style LE fill:#f57c00,stroke:#e65100,color:#fff
+    style LogFile fill:#1a237e,stroke:#0d1642,color:#fff
+    style Loki fill:#4a148c,stroke:#2e0d57,color:#fff
+    style Tempo fill:#4a148c,stroke:#2e0d57,color:#fff
+```
+
+### Tasks
+
+| Task | Description                                    |
+| ---- | ---------------------------------------------- |
+| 8.1  | Inject trace_id into Logs::format()            |
+| 8.2  | Add Loki to Docker Compose stack               |
+| 8.3  | Add file_log receiver to OTel Collector        |
+| 8.4  | Configure Grafana trace-to-log correlation     |
+| 8.5  | Update integration tests                       |
+| 8.6  | Update documentation (runbook, reference docs) |
+
+**Parallel work**: Task 8.2 (Loki infra) can run in parallel with Task 8.1 (code change). Tasks 8.3–8.6 are sequential.
+
+### Exit Criteria
+
+- [ ] Log lines within active spans contain `trace_id=<hex> span_id=<hex>`
+- [ ] Log lines outside spans have no trace context (no empty fields)
+- [ ] Loki ingests xrpld logs via OTel Collector file_log receiver
+- [ ] Grafana Tempo → Loki one-click correlation works
+- [ ] Grafana Loki → Tempo reverse lookup works via derived field
+- [ ] Integration test verifies trace_id presence in logs
+- [ ] No performance regression from trace_id injection (< 0.1% overhead)
+
+---
+
 ## 6.9 Risk Assessment
 
 ```mermaid
@@ -839,6 +996,7 @@ Clear, measurable criteria for each phase.
 | Phase 5 | Production deployment        | Operators trained           | End of Week 9  |
 | Phase 6 | StatsD metrics in Prometheus | 3 dashboards operational    | End of Week 10 |
 | Phase 7 | All metrics via OTLP         | No StatsD dependency        | End of Week 12 |
+| Phase 8 | trace_id in logs + Loki      | Tempo↔Loki correlation      | End of Week 13 |
 
 ---
 

OpenTelemetryPlan/08-appendix.md

@@ -193,6 +193,7 @@ flowchart TB
 | [Phase5_taskList.md](./Phase5_taskList.md)                                 | Ledger processing & advanced tracing  |
 | [Phase5_IntegrationTest_taskList.md](./Phase5_IntegrationTest_taskList.md) | Observability stack integration tests |
 | [Phase7_taskList.md](./Phase7_taskList.md)                                 | Native OTel metrics migration         |
+| [Phase8_taskList.md](./Phase8_taskList.md)                                 | Log-trace correlation                 |
 
 ---
 

OpenTelemetryPlan/09-data-collection-reference.md

@@ -940,6 +940,79 @@ state_accounting_full_duration
 
 ---
 
+## 5a. Log-Trace Correlation (Phase 8)
+
+> **Plan details**: [06-implementation-phases.md §6.8.1](./06-implementation-phases.md) — motivation, architecture, Mermaid diagrams
+> **Task breakdown**: [Phase8_taskList.md](./Phase8_taskList.md) — per-task implementation details
+
+Phase 8 injects OTel trace context into xrpld's `Logs::format()` output, enabling log-trace correlation. When a log line is emitted within an active, sampled OTel span, the trace and span identifiers are automatically appended after the severity field:
+
+### Log Format
+
+```
+<timestamp> <partition>:<severity> trace_id=<32hex> span_id=<16hex> <message>
+```
+
+Example:
+
+```
+2024-Jan-15 10:30:45.123456789 UTC LedgerMaster:NFO trace_id=abc123def456789012345678abcdef01 span_id=0123456789abcdef Validated ledger 42
+```
+
+- **`trace_id=<hex32>`** — 32-character lowercase hex trace identifier. Links to the distributed trace in Tempo/Jaeger.
+- **`span_id=<hex16>`** — 16-character lowercase hex span identifier. Identifies the specific span within the trace.
+- **Only present** when the log is emitted within an active OTel span whose context is sampled. Log lines outside of traced code paths, and lines inside a span the sampler dropped, have no trace context fields. A dropped span still carries its parent's identifiers, so emitting them would point at a trace that was never exported.
+
+### Implementation
+
+The trace context injection is implemented in `Logs::format()` (`src/libxrpl/basics/Log.cpp`), guarded by `#ifdef XRPL_ENABLE_TELEMETRY`. It checks the thread-local runtime context value directly (via `RuntimeContext::GetCurrent().GetValue(kSpanKey)`) to avoid the heap allocation that `GetSpan()` performs on the no-span path. On threads without an active span, the cost is a thread-local read + variant type check (~15-20ns). On the active-span path, total cost is ~50ns per log call.
+
+### Log Ingestion Pipeline
+
+```
+xrpld debug.log -> OTel Collector file_log receiver -> regex_parser -> Loki exporter -> Grafana Loki
+```
+
+The OTel Collector's `file_log` receiver tails `debug.log` files and uses a `regex_parser` operator to extract structured fields:
+
+| Field       | Type     | Description                                              |
+| ----------- | -------- | -------------------------------------------------------- |
+| `timestamp` | datetime | Log timestamp                                            |
+| `partition` | string   | Log partition (e.g., `LedgerMaster`, `PeerImp`)          |
+| `severity`  | string   | Severity code (`TRC`, `DBG`, `NFO`, `WRN`, `ERR`, `FTL`) |
+| `trace_id`  | string   | 32-hex trace identifier (optional)                       |
+| `span_id`   | string   | 16-hex span identifier (optional)                        |
+| `message`   | string   | Log message body                                         |
+
+### Grafana Correlation
+
+Bidirectional linking between logs and traces is configured via Grafana datasource provisioning:
+
+- **Tempo -> Loki** (`tracesToLogs`): Clicking "Logs for this trace" on a Tempo trace view filters Loki logs by `trace_id`, showing all log lines from that trace.
+- **Loki -> Tempo** (`derivedFields`): A regex-based derived field on the Loki datasource extracts `trace_id` from log lines and renders it as a clickable link to the corresponding trace in Tempo.
+
+### Loki Backend
+
+Grafana Loki (v3.4.2) serves as the log storage backend. It receives log entries from the OTel Collector's `otlp_http/loki` exporter via the native OTLP endpoint at `http://loki:3100/otlp`.
+
+### LogQL Query Examples
+
+```logql
+# Find all logs for a specific trace
+{service_name="xrpld"} |= "trace_id=abc123def456789012345678abcdef01"
+
+# Error logs with trace context
+{service_name="xrpld"} |= "ERR" |= "trace_id="
+
+# Logs from a specific partition with trace context
+{service_name="xrpld"} |= "LedgerMaster" | regexp `trace_id=(?P<trace_id>[a-f0-9]+)` | trace_id != ""
+
+# Count traced log lines over time
+count_over_time({service_name="xrpld"} |= "trace_id=" [5m])
+```
+
+---
+
 ## 6. Known Issues
 
 | Issue                                                              | Impact                                           | Status                                                               |

OpenTelemetryPlan/OpenTelemetryPlan.md

@@ -164,7 +164,7 @@ OpenTelemetry Collector configurations are provided for development and producti
 
 ## 6. Implementation Phases
 
-The implementation spans 12 weeks across 7 phases:
+The implementation spans 13 weeks across 8 phases:
 
 | Phase | Duration    | Focus                 | Key Deliverables                                            |
 | ----- | ----------- | --------------------- | ----------------------------------------------------------- |
@@ -175,8 +175,9 @@ The implementation spans 12 weeks across 7 phases:
 | 5     | Week 9      | Documentation         | Runbook, Dashboards, Training                               |
 | 6     | Week 10     | StatsD Metrics Bridge | OTel Collector StatsD receiver, 3 Grafana dashboards        |
 | 7     | Weeks 11-12 | Native OTel Metrics   | OTelCollector impl, OTLP metrics export, StatsD deprecation |
+| 8     | Week 13     | Log-Trace Correlation | trace_id in logs, Loki ingestion, Tempo↔Loki linking        |
 
-**Total Effort**: 60.6 developer-days with 2 developers
+**Total Effort**: 65.1 developer-days with 2 developers
 
 ➡️ **[View full Implementation Phases](./06-implementation-phases.md)**