Files
LithosAnanake/src/starkernel/doe_log.c
T
Robert Allan JamesandClaude Sonnet 5 59458a0a16 Cursor indicator + HB-ON/HB-OFF runtime DoE instrumentation toggle
Cursor (Captain Bob: "the only thing we need is a cursor"):
vt100_draw_cursor() draws a solid block at the terminal's current
position, called from repl.c after the prompt prints and after every
keystroke/backspace. vt100_erase_cursor() cleans up the one gap a static
cursor has -- Enter/newline moves away from the cursor cell without a
character draw ever overwriting it, which left a stray block behind
until this fix.

HB-ON/HB-OFF (Captain Bob: run a program with or without instrumentation
without rebuilding):
Converted per-tick DoE logging from a build-time flag (HEARTBEAT_DOE_LOG)
to a runtime one. doe_log_tick_row() now self-gates on g_doe_log_enabled
(default 1, matching the old default) instead of being compiled out
entirely; the call site in vm_runtime.c is unconditional. Two new FORTH
words, HB-ON and HB-OFF, flip the flag live. Removed the now-dead
HEARTBEAT_DOE_LOG plumbing: the Kconfig symbol, and the -D forwarding in
both LOADER_CFLAGS and KERNEL_CFLAGS.

Verified: three-arch clean QEMU boot + logs; dictionary word count 466
(463 baseline + ALT+TAB + HB-ON + HB-OFF, exactly the three words added
across this session); amd64 screendump confirms the cursor renders
correctly after real interactive typing.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
2026-08-12 16:22:09 -04:00

169 lines
6.8 KiB
C
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
/*
StarForth — Steady-State Virtual Machine Runtime
Copyright (c) 20232025 Robert A. James
All rights reserved.
Licensed under the StarForth License, Version 1.0
*/
/**
* doe_log.c — DoE CSV logger for the LithosAnanke kernel
*
* Emits 18-column CSV rows to the serial log once per heartbeat tick.
* Each row is prefixed with a cyan [HADES][DOE ] tag so it can be
* extracted cleanly:
*
* grep -aP '\[HADES\]\[DOE \]' qemu-amd64-*.log
*
* Columns (in order):
* 1. tick_number uint32 — monotonic heartbeat counter
* 2. elapsed_ns uint64 — ns since run start
* 3. tick_interval_ns uint64 — actual interval from prior tick
* 4. cache_hits_delta uint32 — hot-words cache hits this tick (TODO: 0)
* 5. bucket_hits_delta uint32 — bucket hits this tick (TODO: 0)
* 6. word_executions_delta uint32 — words executed this tick (TODO: 0)
* 7. hot_word_count uint64 — words with heat >= threshold
* 8. avg_word_heat_q48 uint64 — mean execution heat as raw Q48.16 integer
* 9. window_width uint32 — rolling window effective size
* 10. actual_window_size uint32 — true analysis width: min(total_executions, effective_window_size)
* 11. predicted_label_hits uint32 — ANOVA early-exit confirmations per tick (L8 validation signal)
* 12. jitter_bits uint64 — estimated_jitter_ns IEEE 754 raw bits (union-punned)
* 13. apic_ticks uint64 — APIC timer monotonic tick count
* 14. time_trust_q48 uint64 — TIME-TRUST in Q48.16 format
* 15. variance_q48 uint64 — timing variance in Q48.16 format
* 16. hera_heat_q48 uint64 — VM fleet physics: Hera's execution_heat_q48
* 17. hermes_heat_q48 uint64 — VM fleet physics: Hermes's execution_heat_q48
* 18. artemis_heat_q48 uint64 — VM fleet physics: Artemis's execution_heat_q48
*
* Note: avg_word_heat and estimated_jitter_ns are stored as double in the
* snapshot but the freestanding snprintf has no %%f support. avg_word_heat
* is emitted as raw Q48.16 (multiply by 65536); jitter is union-punned to its
* IEEE 754 uint64 bit pattern to avoid UB from out-of-range cast.
*
* Columns 16-18 (VM-FLEET-ATTRACTOR-DESIGN-20260705.md, Phase 3): looked up
* by name each tick rather than by a fixed vm_id, since kill/rebirth (e.g.
* TRIPOD-TEST's K-soak) assigns a fresh vm_id on every rebirth. Fixed to the
* three known Tripod VMs, not a dynamic per-VM column set -- this is a
* logging schema for a specific known fleet, not the physics mechanism
* itself (which stays genuinely VM-count-agnostic). Reads 0 for any VM not
* currently found in the registry (e.g. Hermes momentarily during its
* kill/rebirth window), which is a legitimate observation, not an error.
*/
#include "starkernel/doe_log.h"
#include "starkernel/console.h"
#include "starkernel/timer.h"
#include "starkernel/capsule_birth.h"
#include "starkernel/capsule_vm_physics.h"
#include "freestanding/stdio.h"
#include "word_registry.h"
int g_doe_log_enabled = 1;
#define DOE_PREFIX "\x1b[36m[HADES][DOE ]\x1b[0m "
#define DOE_BUF_SIZE 512
static const char *doe_header =
DOE_PREFIX
"tick_number,elapsed_ns,tick_interval_ns,"
"cache_hits_delta,bucket_hits_delta,word_executions_delta,"
"hot_word_count,avg_word_heat_q48,"
"window_width,actual_window_size,predicted_label_hits,jitter_bits,"
"apic_ticks,time_trust_q48,variance_q48,vm_call_depth_max,"
"hera_heat_q48,hermes_heat_q48,artemis_heat_q48";
/* Looks up a Tripod VM's fleet heat by name; 0 if not currently registered
* (e.g. between KILL and rebirth). */
static uint64_t doe_log_heat_by_name(const char *name)
{
VMRegistryEntry entry;
if (capsule_vm_find_by_name_nocase(name, &entry) != 0) return 0;
return vm_physics_heat_of(entry.vm_id);
}
void doe_log_tick_row(VM *vm, const HeartbeatTickSnapshot *snap)
{
if (!g_doe_log_enabled)
return;
if (!snap)
return;
/* Print header once before the first data row */
static int header_printed = 0;
if (!header_printed) {
console_puts(doe_header);
console_puts("\r\n");
header_printed = 1;
}
/* Pull APIC timer trust state */
const TimeTrustState *ts = heartbeat_state();
uint64_t apic_ticks = ts ? ts->ticks : 0;
uint64_t time_trust_q48 = ts ? (uint64_t)ts->trust : 0;
uint64_t variance_q48 = ts ? (uint64_t)ts->variance : 0;
/* Convert doubles to integer-safe representations (freestanding snprintf has no %f).
* Use union punning for jitter to avoid UB from out-of-range double→int64 cast. */
uint64_t avg_heat_q48 = (uint64_t)(snap->avg_word_heat * 65536.0);
union { double d; uint64_t u; } jitter_bits;
jitter_bits.d = snap->estimated_jitter_ns;
uint64_t jitter_raw = jitter_bits.u;
/* Format the 18-column CSV row into a local buffer.
* Use %llu (unsigned long long) for all uint64_t fields — %lu is unreliable
* for values > 2^32 on aarch64 due to mixed-width varargs ABI behaviour. */
unsigned vm_call_depth_max = (vm && vm->call_stack_max > 0) ? (unsigned)vm->call_stack_max : 0;
uint64_t hera_heat_q48 = doe_log_heat_by_name("Hera");
uint64_t hermes_heat_q48 = doe_log_heat_by_name("Hermes");
uint64_t artemis_heat_q48 = doe_log_heat_by_name("Artemis");
char buf[DOE_BUF_SIZE];
snprintf(buf, sizeof(buf),
"%u,%llu,%llu,%u,%u,%u,%llu,%llu,%u,%u,%u,%llu,%llu,%llu,%llu,%u,%llu,%llu,%llu",
snap->tick_number,
(unsigned long long)snap->elapsed_ns,
(unsigned long long)snap->tick_interval_ns,
snap->cache_hits_delta,
snap->bucket_hits_delta,
snap->word_executions_delta,
(unsigned long long)snap->hot_word_count,
(unsigned long long)avg_heat_q48,
snap->window_width,
snap->actual_window_size,
snap->predicted_label_hits,
(unsigned long long)jitter_raw,
(unsigned long long)apic_ticks,
(unsigned long long)time_trust_q48,
(unsigned long long)variance_q48,
vm_call_depth_max,
(unsigned long long)hera_heat_q48,
(unsigned long long)hermes_heat_q48,
(unsigned long long)artemis_heat_q48);
console_puts(DOE_PREFIX);
console_puts(buf);
console_puts("\r\n");
}
/* HB-ON ( -- ): enable per-tick DoE instrumentation (g_doe_log_enabled=1). */
static void doe_word_hb_on(VM *vm)
{
(void)vm;
g_doe_log_enabled = 1;
}
/* HB-OFF ( -- ): disable per-tick DoE instrumentation (g_doe_log_enabled=0). */
static void doe_word_hb_off(VM *vm)
{
(void)vm;
g_doe_log_enabled = 0;
}
void register_doe_log_words(VM *vm)
{
register_word(vm, "HB-ON", doe_word_hb_on);
register_word(vm, "HB-OFF", doe_word_hb_off);
}