sots-engine/docs/shim-trace.md

13 KiB
Raw Blame History

Shim trace / compare infrastructure (src/shim/trace/)

Hooks installed by the proxy binkw32.dll can run in one of four modes and write a JSON-Lines log that the harness in sots-re/verify/harness/compare/ (tracecmp.py) validates and diffs. The wire format is TRACE_FORMAT.md (v1) in that directory; the C++ emitter here is a byte-exact port of its reference emitter (mkfixture.py) and is tested against it.

file what
platform.h mutex (CRITICAL_SECTION / pthread), monotonic µs, thread id, UTC stamp, SHIM_CDECL/SHIM_STDCALL
sha256.{h,cpp} FIPS 180-4 SHA-256, no allocation
emitter.{h,cpp} typed values (Tv), Record, Meta, Buf, emit_record/emit_meta (spec §3–5)
tracer.{h,cpp} Config (shim.cfg keys), Tracer (locked writer, call ids, depth), Region/Snapshot/Scratch, diff_tv/diff_outputs (spec §6)
hook.h Hook<Descriptor>: the mode dispatch around a hooked C function
selftest.{h,cpp} worked example hook over the shim's own Fill(); run once per launch

Host tests: tests/shim_trace/ (ctest shim_trace_*). They build the same sources with -Wall -Wextra -Werror on Linux; the shim cross-build links the same static library.

Modes

mode what runs what is logged caller gets
off original nothing original's result
trace original args, ret, side (before/after of every declared region) original's result
compare original, then ours on a copy of the pre-call state trace fields + ours{ret,side}, diverged, diff original's result
replace ours args, ret, side (before/after around ours), coverage ours' result

compare never lets ours touch game memory: the declared regions are snapshotted before the original runs, those snapshots are copied into scratch buffers, the arguments are rebound onto the scratch buffers (rebind), and ours runs there. The diff compares the original's after with the scratch buffers' contents and both return values.

replace used to log nothing at all, which is why B3's replace-mode divergence could only be found by hashing the autosave. It now writes one record per call — the same regions, measured around ours instead of around the original — so a replace run is readable, --replay-able, and directly comparable with a compare log's guard findings (docs/harness-audit.md).

A throw from ours, or from any describe/regions/rebind callback, is caught inside the hook and becomes err on the record (which the harness counts as a divergence). The original is always invoked in off/trace/compare, whatever happened during capture. Nothing propagates across the hook boundary.

Configuration (shim.cfg, next to the DLL)

hooks=trace                     # default mode for every hook; off = install nothing at all
hook.Game::CfgVar_RegisterKey=compare   # per-hook override, keyed by the record's "hook" name
hook.Shim::SelfTest::Fill=off
trace.path=C:\SOTS\shim.trace.jsonl     # default: shim.trace.jsonl beside the DLL; overwritten per run
trace.inline_max=256                    # regions <= this many bytes are logged as hex, else sha256 + 32-byte head
trace.flush=always                      # always (default) | lazy (flush only on divergence / err / exit)

Unusable values are logged to shim.log (config: key=value rejected (...)) and ignored. hooks=off keeps M0 behaviour: no MinHook, no trace file. If the trace file cannot be opened, every template hook reports mode off (the game runs un-instrumented, never half-instrumented).

The M0 Mars::Application::Initialize hook is an asm stub, not a template hook: it is installed whenever hooks is not off, and it only logs to shim.log. See "thiscall" below.

Log

shim.trace.jsonl: line 1 is the meta record (build, exe_sha256 of the running exe, started, inline_max, and a hooks policy map with one entry per registered template hook); every later line is one call record. call_id is process-global and taken before the original runs, so nested hooks get higher ids and depth says who is inside whom. ts is microseconds since the tracer opened. The file is ASCII, LF-terminated; a crash mid-run leaves at most one truncated last line, which the harness reports as one invalid record (--skip-invalid drops it).

shim.log gets one trace: line at startup (path, default mode) and one selftest: line (the self-test hook's mode and checksum), and shutdown: trace records=N on detach.

Declaring a hook

A hook is a descriptor struct; Hook<D> generates the detour. Everything the template needs is static, so a descriptor is a header-only declaration plus a few small functions.

#include "shim/trace/hook.h"
using namespace shim::trace;

struct CfgVarRegisterKeyHook {
    static constexpr const char* name = "Game::CfgVar_RegisterKey";   // the record's "hook"
    static constexpr CallConv conv = CallConv::Cdecl;                 // Cdecl | Stdcall
    using Ret = bool;                                                 // void is allowed
    using Args = std::tuple<CfgTable*, const char*, int>;             // the parameter list

    // inputs, in declaration order (never compared by the harness; use .named("x"))
    static void describe_args(std::vector<Tv>& out, CfgTable* t, const char* key, int value) {
        out.push_back(tv::ptr(t).named("table"));
        out.push_back(tv::str(key).named("key"));      // raw cp1252 bytes; nullptr -> ptr 0x0
        out.push_back(tv::i32(value).named("value"));
    }
    static Tv describe_ret(bool r) { return tv::boolean(r); }          // omit when Ret is void

    // declared side-effect regions: name, address, size, optional structured describer
    static void regions(std::vector<Region>& out, CfgTable* t, const char*, int) {
        out.push_back(Region{"cfg_table", t, sizeof(CfgTable), &describe_table});
    }
    static Tv describe_table(const void* p, std::size_t, unsigned /*inline_max*/) {
        const CfgTable* t = static_cast<const CfgTable*>(p);   // a *copy* of the region
        Tv s = tv::struct_();
        s.add("count", tv::u32(t->count));
        return s;                                              // diffs then name the field
    }

    // the same call, aimed at the scratch copies (regions in declaration order)
    static Args rebind(Scratch& s, CfgTable*, const char* key, int value) {
        return Args(s.as<CfgTable>(0), key, value);
    }

    static bool ours(CfgTable* t, const char* key, int value);   // the reimplementation
    static HookPolicy policy() { return HookPolicy{}; }          // ftol / ftol_kind / ptr_exact / unordered

    // REQUIRED (compile error if missing): everything the original writes that no Result
    // region above covers. See docs/harness-audit.md.
    static void coverage(Coverage& c) {
        c.unmodelled("erases the consumed key from the caller's map", Risk::Medium,
                     "a red-black tree cannot be snapshotted before the call",
                     "guard:cfg_table");
        // ...or, when the regions really are everything:
        // c.complete("RegisterKey writes only the table slot declared above");
    }
};

Install (in InstallHooks, after Tracer::open):

using H = Hook<CfgVarRegisterKeyHook>;
H::register_policy(tracer);               // BEFORE tracer.open(): lands in meta.hooks
...
H::configure(tracer);                     // reads hook.<name> / hooks from the config
MH_CreateHook(target, reinterpret_cast<void*>(H::detour()), reinterpret_cast<void**>(&H::original));
MH_EnableHook(target);

Rules of the road:

  • Regions are copies. describe callbacks receive the snapshot buffer, not live memory; a region that contains pointers into other memory is only compared by the pointer values (ignored by default policy) unless you declare the pointed-to memory as another region.
  • Region sizes must be known at call time. A region whose length is only known after the call cannot be snapshotted "before"; declare an upper bound or split the hook.
  • A clean compare bounds only what you declared. Everything else the original writes is invisible to the diff. Two things exist so that is never silent: coverage(), which the compiler makes you fill in, and guard regions — Region::kind = Region::Kind::Guard, a coarse span (usually the whole object) that is watched around the original, never handed to ours and never diffed. Any byte in it that moved and that no Result region covers is reported as an undeclared write. Guards are cheap; declare one over every object the hook can reach.
  • Push guards LAST. Scratch holds Result regions only, so a descriptor that remembers a region index as out.size() at push time must not interleave guards. Hook<> checks the order on every call and turns a violation into an err rather than a shifted mapping.
  • Prefer struct describers over raw bytes for anything with fields: the harness then points at side.cfg_table.after.v.count instead of a byte offset.
  • Floats: tv::f32 stores at float32 width and prints %.9g; the diff rounds both sides to float32 first (spec §6). Never describe a float as f64.
  • Big ints: i64/u64 at or beyond 2^53 in magnitude are emitted as decimal strings.
  • json values are your own canonical text (spec §7); the shim compares them as text.
  • Policies only affect the shim's advisory diff/diverged; tracecmp.py recomputes from the meta policy plus CLI flags and warns when the shim's verdict disagrees.
  • Re-entrancy: a hook calling into another hooked function is fine (depth, ids). A hook calling itself through ours in compare mode would recurse into the tracer; do not do that.
  • Cost: trace/compare allocate (Tv trees, snapshots). Fine for M1-scale hooks; do not put a per-frame hot path in trace without thinking about trace.flush=lazy.

thiscall / unverified prototypes

The template's detour is a real C++ function with a fixed prototype. That is only safe when the prototype is known. M0 proved that a C++ wrapper around an [unverified] thiscall corrupts the game (docs/M0.md, gotcha 1). So:

  • __thiscall hooks and any hook whose entry in sots_addresses.h is [unverified] stay asm stubs: pushfl/pushal, call a C logger with ECX, popal/popfl, jmp trampoline. They are trace-only and cannot capture the return value. Their logger may still build a Record and hand it to Tracer::write (mode trace, ret null, regions snapshotted by hand).
  • Once a prototype is verified, thiscall can be adapted to the template by declaring the detour as a Stdcall hook that takes this as its first explicit parameter behind a tiny asm thunk (push ecx then jump) — not provided here; do it only with a verified prototype.
  • cdecl/stdcall with verified prototypes use the template directly (CallConv::Cdecl, CallConv::Stdcall).

Running a report

# on the game VM: play; then copy C:\SOTS\shim.trace.jsonl to verify/traces/<run-tag>.jsonl
python3 verify/harness/compare/tracecmp.py verify/traces/m1-cfgvar-20260907.jsonl \
        --json-out verify/results/compare/m1-cfgvar-20260907.json
#   exit 0 clean, 1 divergences, 2 invalid record(s)   (--skip-invalid tolerates a truncated tail)
#   --hook NAME            one hook only
#   --tolerance NAME=abs:1e-6 / rel:1e-5 / ulp:2       float policy (overrides meta.hooks)
#   --ptr exact            compare pointer values too
#   --replay IMPL.jsonl    offline: a golden trace vs a host implementation's {call_id, ret, side} lines

Host tests

cmake -S . -B build-host -G Ninja -DCMAKE_BUILD_TYPE=Debug   # or: cmake --preset host
cmake --build build-host && ctest --test-dir build-host
  • shim_trace_sha256 — FIPS vectors, chunked updates, padding edges.
  • shim_trace_emitter — golden strings for §4 escaping, number forms, bytes inline/head, records, meta; writes out/emitter_oracle.jsonl, then tests/shim_trace/oracle_emit.py rebuilds the same records with mkfixture.emit_record and compares byte for byte, and tracecmp.py must read it back (exit 1: it carries one injected divergence).
  • shim_trace_diff — every §6 rule (type, ptr, nan/inf, f32 rounding, abs/rel/ulp, bytes offset, set vs list, unordered policy, struct missing/extra, side names), snapshots, config.
  • shim_trace_hook — the self-test hook through every mode: clean log → tracecmp exit 0, wrong/throwing ours → exit 1 (and exit 0 with --hook on the clean hook), truncated file → exit 2 / 0 with --skip-invalid, plus a second thread and the startup run_once path.

The Python steps use /usr/bin/python3 and the harness dir from -DSOTS_TRACECMP_DIR (default $HOME/sots-re/verify/harness/compare) or the SOTS_TRACECMP_DIR environment variable; when tracecmp.py is not there they print SKIP and the test still passes.