245 lines
15 KiB
Markdown
245 lines
15 KiB
Markdown
# Trace / compare log format (v1)
|
||
|
||
Wire format between the shim (`sots-engine/src/shim/`, C++, no JSON library) and the
|
||
harness in this directory (`tracecmp.py`, stdlib Python). One file per shim run; golden
|
||
traces live in `verify/traces/`, harness reports in `verify/results/compare/`.
|
||
|
||
Design goals, in order: (1) trivially emittable from C++ with `fprintf`; (2) every value
|
||
carries its C type so the harness can apply the right equality rule; (3) big memory
|
||
regions never blow up the log (hash, summarize, cap); (4) the same record shape serves
|
||
online `compare` (shim runs original + ours) and offline `replay` (harness diffs a golden
|
||
`trace` log against a host-side implementation's output).
|
||
|
||
## 1. Container: JSON Lines
|
||
|
||
- UTF-8, no BOM. One JSON object per line, terminated by `\n` (LF only). No blank lines,
|
||
no comments, no trailing commas. A line that does not parse is an **invalid record**.
|
||
- The first line SHOULD be a `meta` record (section 5). Everything else is a **call
|
||
record** (section 2).
|
||
- Records are appended in emission order; `call_id` (not line order) is the identity.
|
||
- Log files are named `<run-tag>.jsonl` (e.g. `verify/traces/m1-cfgvar-20260907.jsonl`).
|
||
|
||
## 2. Call record
|
||
|
||
```json
|
||
{"ts":123456,"hook":"CfgVar_RegisterKey","mode":"trace","call_id":17,"thread":4120,
|
||
"args":[{"t":"str","v":"ForceSingleCore"},{"t":"i32","v":1}],
|
||
"ret":{"t":"bool","v":true},
|
||
"side":{"cfg_table":{"before":{"t":"bytes","n":4096,"sha256":"…"},
|
||
"after":{"t":"bytes","n":4096,"sha256":"…"}}}}
|
||
```
|
||
|
||
| field | type | required | meaning |
|
||
|---|---|---|---|
|
||
| `ts` | int | yes | microseconds since shim init (QPC-based). Informational; never compared. |
|
||
| `hook` | string | yes | hook name — the function's recovered name (`Game::…` / `Mars::…` or `FUN_xxxxxxxx`). |
|
||
| `mode` | `"trace"` \| `"compare"` \| `"replace"` | yes | which mode the hook ran in for this call. |
|
||
| `call_id` | int ≥ 0 | yes | process-global, monotonically increasing, atomic. Unique within a log. |
|
||
| `thread` | int | yes | OS thread id. Informational. |
|
||
| `depth` | int | no | re-entrancy depth (0 = outermost). Informational. |
|
||
| `args` | array of typed values | yes | inputs, in declaration order. `n` names them when known. Never compared (they are the snapshot both sides ran on). |
|
||
| `ret` | typed value or `null` | yes | return value of the **original** (trace/compare) or of **ours** (replace). `null` = void. |
|
||
| `side` | object | yes (may be `{}`) | declared side effects: `name -> {"before": tv|null, "after": tv}`. `after` is compared; `before` is informational (a mismatch in `before` between original and ours would be a snapshot bug and is reported as a warning, not a divergence). |
|
||
| `ours` | object | compare only | `{"ret": tv|null, "side": {name: {"after": tv}}}` — the reimplementation's outputs on the same snapshot. |
|
||
| `diverged` | bool | compare only | the shim's own verdict. The harness recomputes and reports disagreements as warnings. |
|
||
| `diff` | array of diff entries | compare only | the shim's own diff (may be `[]` or truncated). Advisory. |
|
||
| `coverage` | object | no | guard findings for this call (section 8). Present **iff** the hook declared at least one guard region, so `"undeclared":[]` means "watched, nothing moved" — which is not the same as the key being absent. |
|
||
| `err` | string | no | the hook could not capture (exception in ours, snapshot failure…). Counts as a divergence in `compare`. |
|
||
| `note` | string | no | free text. Ignored. |
|
||
|
||
Unknown top-level keys are a validation **warning** (not an error) so the shim can add
|
||
fields without breaking older harnesses.
|
||
|
||
`replace` records have no `ours`; `ret`/`side` are the reimplementation's. They are
|
||
counted and validated but never diffed (there is nothing to diff against). They are
|
||
emitted all the same: a replace run that writes no records can only be judged by the
|
||
save-file oracle, which is how B3's missing event went unnoticed for a milestone.
|
||
|
||
## 3. Typed values (`tv`)
|
||
|
||
Every value is an object `{"t": TYPE, "v": VALUE}` plus optional `"n": "name"`.
|
||
TYPEs and their equality rule:
|
||
|
||
| `t` | `v` | equality |
|
||
|---|---|---|
|
||
| `bool` | `true`/`false` | exact |
|
||
| `i8 i16 i32 i64 u8 u16 u32 u64` | JSON integer. i64/u64 above 2^53 MUST be a decimal **string** (`"v":"18446744073709551615"`) — the harness accepts both int and string. | exact |
|
||
| `f32`, `f64` | JSON number, or the string `"nan"`, `"inf"`, `"-inf"`. Emit with `%.9g` (f32) / `%.17g` (f64). | tolerant (section 6) |
|
||
| `str` | JSON string carrying **raw bytes** of a `char*`/`std::string` (cp1252 in this engine). Each byte maps to one code point U+0000–U+00FF (see escaping, section 4). | exact |
|
||
| `wstr` | JSON string of a `wchar_t*` (UTF-16 code units → `\uXXXX`). | exact |
|
||
| `ptr` | hex string `"0x00a36fd0"` | **ignored** by default (ours allocates elsewhere). A hook policy may set `"ptr":"exact"`. |
|
||
| `enum` | integer, optional `"name"` sibling with the symbolic name | exact on the integer |
|
||
| `null` | `null` | exact (only equals `null`) |
|
||
| `bytes` | see below | exact on `sha256` (and on `hex` when both inline) |
|
||
| `list` | JSON array of tv | same length, element-wise, ordered |
|
||
| `set` | JSON array of tv | unordered multiset: sort both by canonical text, then element-wise |
|
||
| `struct` | JSON object `{field: tv}` | same key set, field-wise (recursion) |
|
||
| `json` | any canonical-JSON value (section 7) — used by the oracle bridge and host-side tests | structural exact, with the hook's float tolerance applied to JSON numbers that are floats on **both** sides |
|
||
|
||
A type mismatch between the two sides (`i32` vs `u32`, `str` vs `wstr`) is a divergence
|
||
(`why: "type"`). Type mismatch does not apply inside `json` values, where int vs float
|
||
is a divergence unless both are numbers and the tolerance policy is `"numeric"`.
|
||
|
||
### `bytes` — binary blobs and memory regions
|
||
|
||
```json
|
||
{"t":"bytes","n":4096,"sha256":"<64 hex>","hex":"<2n hex>"}
|
||
{"t":"bytes","n":1048576,"sha256":"<64 hex>","head":"<first 32 bytes hex>"}
|
||
```
|
||
|
||
- `n` (length in bytes) and `sha256` (lowercase hex of the SHA-256 of the raw bytes) are
|
||
**always** present, even for `n = 0` (sha256 of the empty string).
|
||
- `hex` (lowercase, no separators) is present when `n <= inline_max`. `inline_max` is a
|
||
shim setting recorded in `meta` (default **256**). `hex` is the only inline encoding;
|
||
base64 is not used (harder to eyeball, no size win worth a second decoder).
|
||
- Larger blobs carry `head` (first 32 bytes, hex) for eyeballing only.
|
||
- When both sides are inline and differ, the harness reports the first differing byte
|
||
offset; when hashed, only that the hash differs.
|
||
- A **memory region** is just a `bytes` value captured at a declared `(address, length)`;
|
||
the region's name is the key in `side`. Structured regions should be captured as
|
||
`struct` of typed values instead so diffs point at the field, not a byte offset.
|
||
|
||
## 4. Emitter rules (C++ without a JSON library)
|
||
|
||
The emitter is a set of `fprintf`s. What it must guarantee:
|
||
|
||
1. **Key order is fixed**: `ts, hook, mode, call_id, thread, depth, args, ret, side, ours,
|
||
diverged, diff, coverage, err, note`. (The harness does not care, but fixed order makes
|
||
logs `diff`-able by eye and grep-able.)
|
||
2. **Strings** (`hook`, `str`/`wstr` `v`, `n`, `err`, `note`, struct field names, side
|
||
names): write `"`, then for each unit:
|
||
- `"` → `\"`, `\` → `\\`
|
||
- `\n` → `\n`, `\r` → `\r`, `\t` → `\t` (literal backslash-letter)
|
||
- any other unit `< 0x20`, and for `str` any byte `>= 0x7f` → `\u00XX` (lowercase hex of
|
||
the byte), for `wstr` any unit `>= 0x7f` → `\uXXXX`
|
||
- everything else verbatim. Close with `"`.
|
||
This is exactly what Python's `json.dumps(ensure_ascii=True)` produces for a
|
||
latin-1-decoded byte string (except Python also short-forms `\b` and `\f`; the harness
|
||
accepts both). No raw bytes ≥ 0x80 ever appear in the log, so the file is ASCII-only.
|
||
3. **Numbers**: integers with `%lld`/`%llu`; floats with `%.9g` / `%.17g`; non-finite floats
|
||
as the strings `"nan"`, `"inf"`, `"-inf"`. Never emit `nan`/`inf` bare (invalid JSON).
|
||
4. **Booleans** `true`/`false`; **void** `null`.
|
||
5. **No trailing commas.** Build arrays/objects with a "first element" flag.
|
||
6. **One `fprintf` chain per record, ending in `"}\n"` and a `fflush`** at least on
|
||
`compare` divergences and on shim teardown, so a crash mid-run leaves a usable log
|
||
(the harness tolerates a truncated last line: it is reported as one invalid record).
|
||
7. **Thread safety**: take a lock around the whole record; `call_id` is
|
||
`InterlockedIncrement`-ed *before* the original is called, so nested hooks get
|
||
increasing ids and `depth` says who is inside whom.
|
||
8. `sha256`: any tiny public-domain SHA-256; hex lowercase.
|
||
|
||
## 5. `meta` record (first line)
|
||
|
||
```json
|
||
{"meta":{"format":1,"build":"sots-engine 0.0.3 g1a2b3c4","exe_sha256":"…",
|
||
"started":"2026-09-07T18:00:00Z","inline_max":256,
|
||
"hooks":{"CfgVar_RegisterKey":{"ftol":0,"ptr":"ignore",
|
||
"coverage":{"state":"complete","why":"the declared regions are every word "
|
||
"the original writes","unmodelled":[]}},
|
||
"Mars::ParseBlock":{"ftol":1e-6,"ftol_kind":"rel","unordered":["ret.v.items"],
|
||
"coverage":{"state":"partial","why":"","unmodelled":[
|
||
{"what":"appends EVENT_RESEARCH_OVERBUDGET to the owner's event list",
|
||
"risk":"high","why":"the message text is composed from the tech name",
|
||
"mitigation":"guard:player"}]}}}}}
|
||
```
|
||
|
||
- `format`: this spec's version (1). The harness refuses other versions.
|
||
- `hooks`: per-hook **policy**, the same keys `tracecmp.py --tolerance` accepts. CLI flags
|
||
override the log's policy; the log's policy overrides harness defaults.
|
||
- `hooks.<H>.coverage`: the descriptor's own statement of what its declared regions do **not**
|
||
cover (section 8). `state` ∈ `complete | partial | unstated`; `unmodelled` is a list of
|
||
`{what, risk, why, mitigation}` with `risk` ∈ `low | medium | high`. A hook with no
|
||
`coverage` key reads as `unstated`, which the harness warns about: a clean compare for such
|
||
a hook does not say what it did not check.
|
||
- Everything else is informational and copied into the report.
|
||
|
||
## 6. Divergence rules
|
||
|
||
A call **diverges** when any of: `err` is set; `ret` differs; any `side[name].after`
|
||
differs from `ours.side[name].after`; a `side` name exists on one side only (`why:
|
||
"missing"`). Comparison is by the typed-value table above, recursively. Paths in diff
|
||
entries: `ret`, `side.<name>.after`, then `.v[<index>]` for list/set elements,
|
||
`.v.<field>` for struct fields, `.<key>`/`[<i>]` inside `json` values.
|
||
|
||
```json
|
||
{"path":"side.cfg_table.after.v.ForceSingleCore","why":"exact","orig":{"t":"i32","v":1},"ours":{"t":"i32","v":0}}
|
||
```
|
||
|
||
`why` ∈ `exact | ftol | type | len | missing | extra | hash | err`.
|
||
|
||
**Float tolerance policy** (per hook; default `ftol = 0`, i.e. exact by value with
|
||
`nan == nan`):
|
||
- `ftol`: number ≥ 0.
|
||
- `ftol_kind`: `"abs"` (default) — `|a-b| <= ftol`; `"rel"` — `|a-b| <= ftol * max(|a|,|b|)`;
|
||
`"ulp"` — within `ftol` units-in-last-place of the value's own width (f32/f64).
|
||
- `nan`, `inf`, `-inf`: equal only to themselves, whatever the tolerance.
|
||
- `f32` values are rounded to float32 on both sides before comparing: `%.9g` round-trips
|
||
the float32 exactly but not the double it was widened to. `f64` compares as-is.
|
||
- `f32` compared to `f64` is a type divergence; do not mix.
|
||
|
||
**Unordered fields**: `set` values are always unordered. A policy may additionally list
|
||
`unordered: [<path>, …]` to treat specific `list` paths as sets (path syntax as above,
|
||
without the `.v[i]` tail). Multiset semantics: element multiplicity matters.
|
||
|
||
**Pointers**: `ptr` is ignored unless the policy says `"ptr":"exact"`. Two `ptr` values
|
||
where exactly one is `"0x0"` is always a divergence (`null` vs non-null is semantic).
|
||
|
||
## 7. Canonical JSON (for `json` values and the oracle bridge)
|
||
|
||
The form a host-side C++ test dump must reproduce byte-for-byte so a plain `diff` (or
|
||
`tracecmp.py --replay`) works. It is Python's
|
||
`json.dumps(obj, sort_keys=True, ensure_ascii=True, separators=(",", ":"))` after
|
||
normalization by `oracle_parsers.canonical()`:
|
||
|
||
- objects: keys sorted by code point, no whitespace anywhere (`{"a":1,"b":[1,2]}`);
|
||
- strings: byte-preserving — the parsers decode cp1252, the canonicalizer re-encodes to
|
||
cp1252 and maps each byte to U+00XX, so the escaping in section 4 applies verbatim
|
||
(a C++ dump escapes raw bytes, no charset table needed);
|
||
- integers: decimal, no leading `+`/zeros;
|
||
- floats: rounded to **float32**, printed with `%.9g`, then `.0` appended when the text has
|
||
no `.`, `e` or `n` (so `1.0` stays distinguishable from the int `1`, and `-0` → `-0.0`);
|
||
non-finite → the strings `"nan"`, `"inf"`, `"-inf"`;
|
||
- booleans `true`/`false`; `null` for None; tuples become arrays; dataclasses become
|
||
objects of their fields;
|
||
- the file ends with a single `\n`.
|
||
|
||
## 8. Coverage: guard regions and the `coverage` block
|
||
|
||
A declared region is a **check**. Everything else the hooked function writes is invisible to
|
||
the diff, and a clean compare says nothing about it — B3 shipped a "13/15 zero-divergence"
|
||
result while replace mode wrote a save that was missing an event, because the event landed
|
||
outside every declared region. Two fields exist so that can never again be silent.
|
||
|
||
**Static** — `meta.hooks.<H>.coverage` (section 5): what the descriptor admits it does not
|
||
model. The shim requires it at compile time; the harness prints it under every report,
|
||
clean or not.
|
||
|
||
**Per call** — the record's `coverage`:
|
||
|
||
```json
|
||
"coverage":{"guards":["player","tree_header"],
|
||
"undeclared":[{"region":"player","off":688,"len":4}],"n":3}
|
||
```
|
||
|
||
- `guards`: the names of the coarse spans watched around this call. A *guard region* is
|
||
snapshotted before and after the original (or, in `replace`, around `ours`), is never handed
|
||
to the reimplementation and is never diffed.
|
||
- `undeclared`: byte runs inside a guard that moved and that **no declared region covers** —
|
||
writes the descriptor forgot. Capped (the shim emits at most 16); `n` is the true count.
|
||
- The key is present iff at least one guard was declared, so `"undeclared":[]` is a positive
|
||
statement ("watched, nothing moved outside the checks"), not an absence of information.
|
||
|
||
`tracecmp.py` folds these into a `coverage` section per hook: what was compared, what was
|
||
guarded, what the guards caught, and what the descriptor admits. Exit codes are unchanged, and
|
||
a guard finding on a hook that admits it is *not* a failure. One case is: a hook whose
|
||
`coverage.state` is `complete` while a guard caught an undeclared write has been proved wrong
|
||
about its own model, and that counts as a divergence (exit 1). `--strict-coverage` widens
|
||
that to any undeclared write or any `unstated` hook.
|
||
|
||
## 9. Replay (offline) input
|
||
|
||
`tracecmp.py --replay GOLDEN.jsonl IMPL.jsonl`: `GOLDEN` is a normal log (any mode; usually
|
||
`trace`). `IMPL` is JSONL whose records need only `call_id`, `ret`, `side` (`side` may be
|
||
`{name: tv}` or `{name: {"after": tv}}`; `hook` optional but checked when present). Each
|
||
golden call_id must appear in `IMPL` (`why: "missing"` otherwise); extra call_ids in
|
||
`IMPL` are warnings. The diff rules are those of section 6, with `IMPL` playing `ours`.
|