<!-- Moved from docs/heartbeat_csv_export.md to docs/working/architecture/heartbeat_csv_export.md on 2026-06-16 (docs reorg Phase 2) -->
# Heartbeat CSV Export - Real-Time VM Metrics

## Overview

The heartbeat subsystem now emits real-time multivariate VM metrics to stderr in CSV format, enabling external analysis of StarForth's adaptive runtime behavior. This provides a continuous stream of 11 performance indicators sampled every ~1ms during VM execution.

## Architecture

### Components

- **`src/heartbeat_export.c`** - Metrics capture and CSV emission functions
- **`include/heartbeat_export.h`** - Public API declarations
- **Integration point**: `vm_heartbeat_run_cycle()` in `src/vm.c:764-767`
- **Background thread**: `heartbeat_thread_main()` runs independently at ~1ms intervals

### Design Principles

1. **Zero-copy capture** - Metrics collected directly from VM state
2. **Unbuffered output** - Immediate `fflush()` after each row for real-time streaming
3. **No headers** - Raw data only (headers provided separately for analysis tools)
4. **Stderr isolation** - stdout reserved for test output, stderr for diagnostics/metrics
5. **Thread safety** - Background pthread decoupled from main VM execution

## CSV Format

### Header (for reference, not emitted by VM)

```csv
tick_number,elapsed_ns,tick_interval_ns,cache_hits_delta,bucket_hits_delta,word_executions_delta,hot_word_count,avg_word_heat,window_width,predicted_label_hits,estimated_jitter_ns
```

### Column Specifications

| Column | Type | Unit | Description | Status |
|--------|------|------|-------------|--------|
| `tick_number` | uint32_t | count | Monotonic heartbeat tick counter since VM start | ✅ Working |
| `elapsed_ns` | uint64_t | nanoseconds | Total time elapsed since VM initialization | ✅ Working |
| `tick_interval_ns` | uint64_t | nanoseconds | Time since previous heartbeat tick (actual vs nominal 1ms) | ✅ Working |
| `cache_hits_delta` | uint32_t | count | Hotwords cache lookup hits since last tick | ⚠️ TODO |
| `bucket_hits_delta` | uint32_t | count | Bucket-level cache hits since last tick | ⚠️ TODO |
| `word_executions_delta` | uint32_t | count | Total FORTH word executions since last tick | ⚠️ TODO |
| `hot_word_count` | uint64_t | count | Words currently above heat promotion threshold (>= 10) | ✅ Working |
| `avg_word_heat` | double | heat units | Average execution heat across all dictionary words (Q48.16 → double) | ✅ Working |
| `window_width` | uint32_t | entries | Current rolling window effective size (adaptive) | ✅ Working |
| `predicted_label_hits` | uint32_t | count | Successful pipelining speculation hits | ⚠️ TODO |
| `estimated_jitter_ns` | double | nanoseconds | Absolute deviation from nominal 1ms tick interval | ✅ Working |

### Status Legend

- ✅ **Working** - Fully implemented and emitting correct values
- ⚠️ **TODO** - Currently emits `0`, requires delta tracking implementation

## Usage

### Basic Capture

```bash
# Redirect stderr to file, discard stdout
./build/amd64/fastest/starforth --doe 2>heartbeat.csv 1>/dev/null

# Capture both streams separately
./build/amd64/fastest/starforth --doe 1>test_output.txt 2>heartbeat.csv
```

### Real-Time Monitoring

```bash
# Watch metrics in real-time (requires 'csvlook' from csvkit)
./build/amd64/fastest/starforth --doe 2>&1 1>/dev/null | csvlook --no-header-row

# Tail last 20 rows during long-running execution
tail -f heartbeat.csv | head -20
```

### Post-Processing

```bash
# Add header for analysis tools
echo "tick_number,elapsed_ns,tick_interval_ns,cache_hits_delta,bucket_hits_delta,word_executions_delta,hot_word_count,avg_word_heat,window_width,predicted_label_hits,estimated_jitter_ns" > analysis.csv
cat heartbeat.csv >> analysis.csv

# Import into R
# R> data <- read.csv("analysis.csv")
# R> summary(data)

# Import into Python/Pandas
# >>> import pandas as pd
# >>> df = pd.read_csv("analysis.csv")
# >>> df.describe()
```

## Analysis Use Cases

### 1. Multivariate Dynamics Modeling

The 11-dimensional time series enables:
- **Phase space reconstruction** - Identify attractor basins in adaptive parameter space
- **Lyapunov exponent estimation** - Quantify system stability/chaos
- **Mutual information analysis** - Discover coupling between metrics

### 2. Adaptive Tuning Validation

Track effectiveness of physics-driven optimization:
- **Window width adaptation** - Correlation with prediction accuracy
- **Heat decay dynamics** - Stale word accumulation vs. decay slope
- **Jitter characterization** - Thread scheduling impact on heartbeat regularity

### 3. Workload Profiling

Classify execution patterns:
- **Hot word churn rate** - Entry/exit from hot word set
- **Execution density** - `word_executions_delta` / `tick_interval_ns`
- **Cache efficiency** - Hit rates vs. working set size

## Implementation Details

### Function: `heartbeat_capture_tick_snapshot()`

**Location**: `src/heartbeat_export.c:35-115`

Collects VM state into `HeartbeatTickSnapshot` structure:

```c
void heartbeat_capture_tick_snapshot(VM* vm, HeartbeatTickSnapshot* snapshot);
```

**Key operations**:
1. Read monotonic tick counter from `vm->heartbeat.tick_count_total`
2. Calculate elapsed time via `sf_monotonic_ns()` - `vm->heartbeat.run_start_ns`
3. Track inter-tick interval using static `last_tick_ns` variable
4. Walk dictionary to count hot words (heat >= 10) and compute average
5. Sample rolling window effective size
6. Estimate jitter as `|actual_interval - HEARTBEAT_TICK_NS|`

**Time complexity**: O(n) where n = dictionary size (typically ~200 words)

### Function: `heartbeat_emit_tick_row()`

**Location**: `src/heartbeat_export.c:130-161`

Emits CSV row to stderr:

```c
void heartbeat_emit_tick_row(VM* vm, HeartbeatTickSnapshot* snapshot);
```

**Key operations**:
1. Format 11 values using `fprintf()` with `%u`, `%lu`, `%.6f` specifiers
2. Immediately flush with `fflush(stderr)` for real-time output
3. No null checks after initial validation (fail-fast on corruption)

**Performance**: ~5μs per emission (negligible vs. 1ms tick interval)

### Integration Point: `vm_heartbeat_run_cycle()`

**Location**: `src/vm.c:764-767`

```c
static void vm_heartbeat_run_cycle(VM *vm)
{
    /* ... existing heartbeat operations ... */

    /* Phase 2: Real-time heartbeat metrics emission */
    HeartbeatTickSnapshot tick_snapshot;
    heartbeat_capture_tick_snapshot(vm, &tick_snapshot);
    heartbeat_emit_tick_row(vm, &tick_snapshot);
}
```

Called from background thread (`heartbeat_thread_main()`) every ~1ms.

### Thread Startup Behavior

**Critical change** (src/vm.c:780-786):

The original 50ms startup delay was **removed** to enable immediate metrics emission:

```c
/* IMPORTANT: No startup delay to allow heartbeat to emit during short DoE runs.
 * Original 50ms delay avoided race conditions during word registration, but prevented
 * real-time metrics emission in fast-completing tests. */

while (!worker->stop_requested)
{
    vm_heartbeat_run_cycle(vm);
    /* ... */
}
```

**Trade-off**: May observe transient anomalies during first ~50ms of execution (word registration phase).

## Known Limitations & TODOs

### 1. Missing Delta Tracking

**Affected columns**: `cache_hits_delta`, `bucket_hits_delta`, `word_executions_delta`

**Root cause**: No per-tick baseline tracking in `vm_tick()` or heartbeat state.

**Solution**:
```c
// In HeartbeatState, add:
uint64_t last_cache_hits;
uint64_t last_bucket_hits;
uint64_t last_word_executions;

// In heartbeat_capture_tick_snapshot():
snapshot->cache_hits_delta = vm->cache_hits - hb->last_cache_hits;
hb->last_cache_hits = vm->cache_hits;
```

### 2. Uninitialized `run_start_ns`

**Symptom**: `elapsed_ns` values are astronomically large in first few ticks.

**Root cause**: `vm->heartbeat.run_start_ns` never initialized (defaults to 0).

**Solution**:
```c
// In vm_init() after heartbeat initialization:
vm->heartbeat.run_start_ns = sf_monotonic_ns();
```

### 3. Missing Pipelining Metrics

**Affected column**: `predicted_label_hits`

**Root cause**: No aggregation of per-word `transition_metrics->prefetch_hits`.

**Solution**: Accumulate hits in `vm->pipeline_metrics` or emit global counter.

## Performance Impact

- **CPU overhead**: < 0.5% (5μs emission / 1000μs interval)
- **Memory overhead**: 88 bytes per `HeartbeatTickSnapshot` (stack-allocated)
- **I/O impact**: ~150 bytes/tick × 1000 ticks/sec = ~150 KB/sec to stderr

## Future Enhancements

1. **Binary format option** - Reduce I/O overhead for high-frequency sampling
2. **Selective column emission** - Environment variable to specify subset of metrics
3. **Aggregated statistics** - Min/max/stddev over N ticks (reduce volume)
4. **Header injection** - `--heartbeat-header` flag to emit column names on startup
5. **Timestamp mode** - Option to use absolute wall-clock time instead of elapsed_ns

## References

- **Source code**: `src/heartbeat_export.c`, `src/vm.c:764-767`
- **Header**: `include/heartbeat_export.h`
- **Design doc**: `CLAUDE.md` (Build flags section)
- **Related**: `docs/physics_runtime.md` (L1-L7 physics layers)

---

*Last updated: 2025-12-08*
*Author: Robert A. James*