Summarize joined GPS route results

docs/compaction-handoff.md

@@ -4,12 +4,12 @@ Current date/time context: 2026-06-20/21, local timezone America/Chicago.
 
 ## Current Installed State
 
-- Latest commit: `64ddf7a Trace GPS provider filters`.
+- Latest installed probe commit: `54f014b Trace full GPS query results`.
 - Installed RED4ext plugin:
   `Cyberpunk 2077/red4ext/plugins/EdgeWeightGPS/EdgeWeightGPS.dll`.
 - Installed build is read-only. It should not alter route behavior.
-- Plugin log is cleared and empty before the next test:
+- Latest archived test log:
-  `Cyberpunk 2077/red4ext/plugins/EdgeWeightGPS/EdgeWeightGPS.log`.
+  `logs/EdgeWeightGPS_query_route_probe_2308.log`.
 - Game is cold as of the latest user message.
 
 ## New Toolbox Tools
@@ -32,6 +32,7 @@ In `red4ext/EdgeWeightGPS/src/Main.cpp`:
 - `kEnableGpsTraceHooks = true`
 - `kEnableGpsQueryLifecycleHooks = true`
 - `kEnableGpsRouteJobLifecycleHooks = false`
+- `kEnableGpsRouteJobStartTrace = false`
 - `kEnableGpsLocalSearchHooks = true`
 - `kEnableRouteUiTraceHooks = false`
 
@@ -113,37 +114,81 @@ Route result records:
 - `h00` in those records matches `worldTrafficLanePersistent.nodeRefHash`.
 - Route records can be joined to `work/raw-segment-json/all.traffic_persistent.json`.
 - The low byte of route-record `u08` is not the same as the search point class.
+- The log's human wall timestamp has a millisecond rollover bug around second
+  boundaries. Use the `+Nms` elapsed field for ordering and durations.
 
-## Next User Test
+## Latest 23:08 Test Result
 
-Ask the user to run the usual routine:
+The user clicked:
 
-1. Launch game.
+- 23:08 continue on main menu
-2. Hit Continue on main menu.
+- 23:30 space to continue
-3. Hit Space to Continue.
+- 23:46 map open
-4. Wait for minimap/GPS to settle.
+- 23:56 side job
-5. Open map.
+- 24:06 Sinnerman
-6. Plot the usual three routes plus one custom highway-ish target.
+- 24:14 Claire
-7. Close game.
+- 24:21 custom
+- 24:30 Aldecaldo camp
+- 24:47 far gig east
+- 25:03 Violence
+- 25:10 cyberpsycho unfinished highway
 
-Ask for timestamps for:
+Use:
 
-- Space-to-Continue
+```bash
-- map open
+python3 tools/summarize_gps_route_records.py \
-- each route click
+  --traffic-json work/raw-segment-json/all.traffic_persistent.json \
-- game cold
+  logs/EdgeWeightGPS_query_route_probe_2308.log
+```
 
-After the run:
+Important result table:
 
-1. Archive the log to `logs/EdgeWeightGPS_provider_filter_probe_<time>.log`.
+- qid 1: startup/minimap route, 18 records, 50 ms, 1216.5 pavement length.
-2. Inspect `GPSQuerySubmit`/`GPSQueryResultFetch` lines for tracked route IDs
+- qid 2: side job, 12 records, 32 ms, 578.6 pavement length.
-   from submit return RVA `0x8d20d4`, especially successful `0x7094b8`
+- qid 3: Sinnerman, 23 records, 45 ms, 897.4 pavement, 160.4 highway,
-   records with `gpsResult_ptr28_rec40`.
+  89.8 road.
-3. Inspect `GPSSearch result` lines for `filterPassClasses`,
+- qid 4: Claire, 18 records, 34 ms, 1216.5 pavement.
-   `filterFailClasses`, `filterPassMaskBits`, and `filterFailMaskBits`.
+- qid 5: custom, 17 records, 44 ms, 1006.3 pavement, 241.0 highway,
-4. Compare filter pass/fail classes to `edgeSrcClasses` and route output
+  38.0 road.
-   records. The key question is whether the class/mask filter is selecting the
+- qid 6: Aldecaldo camp, 80 records, 325 ms, 5853.5 road, 1492.9 highway,
-   graph subset before cost weighting can matter.
+  1111.5 pavement, 24.6 gpsonly.
+- qid 7: far east gig, 81 records, 144 ms, 5086.2 road, 1523.0 highway,
+  1111.5 pavement, 24.6 gpsonly.
+- qid 8: Violence, 55 records, 97 ms, 1991.5 pavement, 358.5 highway,
+  86.1 road.
+- qid 9: cyberpsycho unfinished highway, 58 records, 147 ms, 2657.4 pavement,
+  519.0 highway, 113.2 road, 56.7 gpsonly.
+
+All 362 route-record handles matched traffic lane hashes in the extracted
+resource.
+
+Local search/provider aggregate from this run:
+
+- 159 searches, 4036 provider filter calls, only 3 filter failures.
+- Filter pass classes: `3:3114`, `5:451`, `15:310`, `1:116`, `4:42`.
+- Edge source classes: `3:3244`, `5:487`, `15:318`, `1:117`, `4:58`.
+- Edge return RVAs: `0x44f457:4033`, `0x44f629:151`,
+  `0x8d74d3:30`, `0x8d76b0:10`.
+
+Inference:
+
+- Provider vtable slot `+0x08` filtering is almost not pruning these route
+  searches, so it is not the dominant reason class-cost patches failed to
+  visibly steer GPS.
+- Search-side edge classes are only `{1,3,4,5,15}` in this run. Final emitted
+  route-record classes include `{0,1,2,3,4,5,7,8,9}` and class 7/8/9 are
+  highway-heavy. Therefore final route-record `u08` low byte and search point
+  `point+0x13` class are different domains.
+
+## Next Work
+
+- Static disassembly around result-drain/producer RVAs `0x520783`,
+  `0x41be2c`, `0x41be94`, `0x70a42c`, and `0x8d20d4`.
+- The plausible patch point is upstream of result copy: find where search
+  output is converted to 0x28 route records or where candidate lanes are ranked
+  with enough lane-hash/resource context to prefer highway/major-road lanes.
+- Post-`0x7094b8` rewriting would likely only change displayed path records and
+  risks desynchronizing instructions from the real planner.
 
 ## Useful Commands
 

docs/red4ext-logging-shim.md

@@ -264,6 +264,37 @@ Route-record/resource correlation:
   provider initialization site or a way to join search-side route points back to
   `nodeRefHash`/lane flags before the edge cost is returned.
 
+Latest full-route join:
+
+- `logs/EdgeWeightGPS_query_route_probe_2308.log` contains nine solved route
+  results from the 23:08 user test. All 362 emitted route records matched
+  `worldTrafficLanePersistent.nodeRefHash` in
+  `work/raw-segment-json/all.traffic_persistent.json`.
+- The log's wall timestamp currently wraps milliseconds without incrementing
+  the displayed second. Use the `+Nms` elapsed field when comparing submit and
+  result times.
+- Representative solved route composition:
+  - side job: 12 records, 32 ms, 578.6 pavement length.
+  - Sinnerman: 23 records, 45 ms, 897.4 pavement, 160.4 highway, 89.8 road.
+  - Claire: 18 records, 34 ms, 1216.5 pavement.
+  - custom highway-ish pin: 17 records, 44 ms, 1006.3 pavement,
+    241.0 highway, 38.0 road.
+  - Aldecaldo camp: 80 records, 325 ms, 5853.5 road, 1492.9 highway,
+    1111.5 pavement, 24.6 gpsonly.
+  - far east gig: 81 records, 144 ms, 5086.2 road, 1523.0 highway,
+    1111.5 pavement, 24.6 gpsonly.
+  - Violence: 55 records, 97 ms, 1991.5 pavement, 358.5 highway,
+    86.1 road.
+  - cyberpsycho unfinished highway: 58 records, 147 ms, 2657.4 pavement,
+    519.0 highway, 113.2 road, 56.7 gpsonly.
+- Search/provider aggregate in the same log: 159 searches, 4036 provider
+  filter calls, only 3 filter failures. Filter slot `+0x08` is therefore
+  almost never pruning this test graph.
+- Search-side point classes observed by `0x44f838` are `{1,3,4,5,15}`. Final
+  route-record low-byte classes are `{0,1,2,3,4,5,7,8,9}`, and route-record
+  classes 7/8/9 are highway-heavy. These are different domains, which explains
+  why provider point-class tuning did not map cleanly to highway preference.
+
 Current static producer lead:
 
 - `0x70a908` packages the route endpoints and query settings, then calls

tools/summarize_gps_route_records.py

@@ -5,15 +5,21 @@ from __future__ import annotations
 
 import argparse
 import collections
+import dataclasses
 import json
 import re
 from pathlib import Path
 from typing import Any
 
 
+RE_TIMESTAMP = re.compile(r"^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\.\d{3})")
+RE_ELAPSED_MS = re.compile(r" \+(\d+)ms ")
 RE_RECORD_BLOCK = re.compile(r"gpsResult_ptr28_rec40=\[(.*?)\]")
 RE_RECORD = re.compile(r"(\d+):([0-9a-f]+),0x([0-9a-f]{8}),([^;\]]+)")
 RE_JOB_COUNT = re.compile(r"GPSRouteJobBuild result call=(\d+).*?job_count50=(\d+)/0x([0-9a-f]+)")
+RE_FIELD_DEC_HEX = re.compile(r"([A-Za-z0-9_]+)=(-?\d+)/0x([0-9a-fA-F]+)")
+RE_FIELD_HEX = re.compile(r"([A-Za-z0-9_]+)=0x([0-9a-fA-F]+)")
+RE_FIELD_DEC = re.compile(r"([A-Za-z0-9_]+)=(-?\d+)(?= |$)")
 
 FLAGS = {
     "FromRoadSpline": 1,
@@ -35,6 +41,39 @@ FLAGS = {
 }
 
 
+@dataclasses.dataclass
+class SubmitInfo:
+    line_no: int
+    timestamp: str
+    elapsed_ms: int | None
+    call: int
+    fields: dict[str, int]
+
+
+@dataclasses.dataclass
+class RouteRecord:
+    index: int
+    handle: int
+    packed: int
+    parts: list[str]
+
+    @property
+    def low_class(self) -> int:
+        return self.packed & 0xFF
+
+
+@dataclasses.dataclass
+class RouteResult:
+    line_no: int
+    timestamp: str
+    elapsed_ms: int | None
+    query_id: int | None
+    submit_call: int | None
+    submit_ret_rva: int | None
+    fields: dict[str, int]
+    records: list[RouteRecord]
+
+
 def bytes_le(value: int) -> tuple[int, int, int, int]:
     return tuple((value >> (8 * index)) & 0xFF for index in range(4))
 
@@ -57,6 +96,27 @@ def lane_category(flags: int) -> str:
     return "other"
 
 
+def parse_timestamp(line: str) -> str:
+    match = RE_TIMESTAMP.search(line)
+    return match.group(1) if match else "<unknown>"
+
+
+def parse_elapsed_ms(line: str) -> int | None:
+    match = RE_ELAPSED_MS.search(line)
+    return int(match.group(1)) if match else None
+
+
+def parse_fields(line: str) -> dict[str, int]:
+    fields: dict[str, int] = {}
+    for match in RE_FIELD_DEC_HEX.finditer(line):
+        fields[match.group(1)] = int(match.group(2))
+    for match in RE_FIELD_HEX.finditer(line):
+        fields.setdefault(match.group(1), int(match.group(2), 16))
+    for match in RE_FIELD_DEC.finditer(line):
+        fields.setdefault(match.group(1), int(match.group(2)))
+    return fields
+
+
 def load_lane_lookup(path: Path | None) -> dict[int, dict[str, Any]]:
     if not path:
         return {}
@@ -79,7 +139,158 @@ def load_lane_lookup(path: Path | None) -> dict[int, dict[str, Any]]:
     return lookup
 
 
+def parse_route_records(block: str) -> list[RouteRecord]:
+    records: list[RouteRecord] = []
+    for record_match in RE_RECORD.finditer(block):
+        pieces = record_match.group(4).split(",")
+        if len(pieces) < 4:
+            continue
+        records.append(
+            RouteRecord(
+                index=int(record_match.group(1)),
+                handle=int(record_match.group(2), 16),
+                packed=int(record_match.group(3), 16),
+                parts=pieces,
+            )
+        )
+    return records
+
+
+def iter_route_results(path: Path) -> tuple[dict[int, SubmitInfo], list[RouteResult], list[int]]:
+    submits: dict[int, SubmitInfo] = {}
+    results: list[RouteResult] = []
+    job_counts: list[int] = []
+
+    for line_no, line in enumerate(path.read_text(encoding="utf-8", errors="replace").splitlines(), start=1):
+        fields = parse_fields(line)
+        if "hook GPSQuerySubmit 0x70a42c" in line:
+            call = fields.get("call")
+            if call is not None:
+                submits[call] = SubmitInfo(
+                    line_no=line_no,
+                    timestamp=parse_timestamp(line),
+                    elapsed_ms=parse_elapsed_ms(line),
+                    call=call,
+                    fields=fields,
+                )
+
+        job_match = RE_JOB_COUNT.search(line)
+        if job_match:
+            job_counts.append(int(job_match.group(2)))
+
+        block_match = RE_RECORD_BLOCK.search(line)
+        if not block_match:
+            continue
+
+        records = parse_route_records(block_match.group(1))
+        if not records:
+            continue
+
+        results.append(
+            RouteResult(
+                line_no=line_no,
+                timestamp=parse_timestamp(line),
+                elapsed_ms=parse_elapsed_ms(line),
+                query_id=fields.get("queryId"),
+                submit_call=fields.get("submitCall"),
+                submit_ret_rva=fields.get("submitRetRva"),
+                fields=fields,
+                records=records,
+            )
+        )
+
+    return submits, results, job_counts
+
+
+def summarize_route_result(route: RouteResult, lane_lookup: dict[int, dict[str, Any]]) -> tuple[dict[str, Any], int]:
+    class_counts = collections.Counter(record.low_class for record in route.records)
+    category_counts: collections.Counter[str] = collections.Counter()
+    category_lengths: collections.Counter[str] = collections.Counter()
+    speed_lengths: collections.Counter[int] = collections.Counter()
+    unmatched = 0
+
+    for record in route.records:
+        lane = lane_lookup.get(record.handle)
+        if not lane:
+            unmatched += 1
+            continue
+        category = lane["category"]
+        length = float(lane.get("length") or 0.0)
+        category_counts[category] += 1
+        category_lengths[category] += length
+        speed_lengths[int(lane["speed"])] += length
+
+    total_length = sum(category_lengths.values())
+    summary = {
+        "class_counts": class_counts,
+        "category_counts": category_counts,
+        "category_lengths": category_lengths,
+        "speed_lengths": speed_lengths,
+        "total_length": total_length,
+        "unmatched": unmatched,
+    }
+    return summary, len(route.records) - unmatched
+
+
+def format_counter(counter: collections.Counter[Any], limit: int | None = None, digits: int | None = None) -> str:
+    items = counter.most_common(limit)
+    parts = []
+    for key, value in items:
+        if digits is None:
+            parts.append(f"{key}:{value}")
+        else:
+            parts.append(f"{key}:{value:.{digits}f}")
+    return "{" + ", ".join(parts) + "}"
+
+
+def print_per_route(
+    path: Path,
+    submits: dict[int, SubmitInfo],
+    route_results: list[RouteResult],
+    lane_lookup: dict[int, dict[str, Any]],
+) -> None:
+    print("  per-route results:")
+    for ordinal, route in enumerate(route_results, start=1):
+        submit = submits.get(route.submit_call) if route.submit_call is not None else None
+        summary, matched = summarize_route_result(route, lane_lookup)
+        span = route.fields.get("gpsResult_u20")
+        submit_fields = submit.fields if submit else {}
+        ret_rva = route.submit_ret_rva
+        ret_text = f"0x{ret_rva:x}" if ret_rva is not None else "?"
+        submit_ms = submit.elapsed_ms if submit else None
+        result_ms = route.elapsed_ms
+        duration_ms = result_ms - submit_ms if submit_ms is not None and result_ms is not None else None
+        submit_marker = f"+{submit_ms}ms" if submit_ms is not None else "?"
+        result_marker = f"+{result_ms}ms" if result_ms is not None else "?"
+        duration_marker = f"{duration_ms}ms" if duration_ms is not None else "?"
+        print(
+            f"    route#{ordinal} qid={route.query_id} submitCall={route.submit_call} "
+            f"submit={submit_marker} result={result_marker} duration={duration_marker} line={route.line_no} "
+            f"ret={ret_text} records={len(route.records)} spanU20={span} matched={matched}"
+        )
+        if submit_fields:
+            print(
+                "      query "
+                f"f08=0x{submit_fields.get('query_f08', 0):x} "
+                f"f0c={submit_fields.get('query_f0c')} "
+                f"fcc={submit_fields.get('query_fcc')}"
+            )
+        if lane_lookup:
+            category_lengths = summary["category_lengths"]
+            total = summary["total_length"]
+            print(
+                "      resource "
+                f"segments={format_counter(summary['category_counts'])} "
+                f"length={format_counter(category_lengths, digits=1)} "
+                f"total={total:.1f} "
+                f"speedLength={format_counter(summary['speed_lengths'], limit=6, digits=1)} "
+                f"unmatched={summary['unmatched']}"
+            )
+        print(f"      routeClasses={format_counter(summary['class_counts'])}")
+
+
 def summarize(path: Path, lane_lookup: dict[int, dict[str, Any]]) -> None:
+    submits, route_results, job_counts = iter_route_results(path)
     routes = 0
     records = 0
     first_byte = collections.Counter()
@@ -91,37 +302,22 @@ def summarize(path: Path, lane_lookup: dict[int, dict[str, Any]]) -> None:
     class_speed: dict[int, collections.Counter[int]] = collections.defaultdict(collections.Counter)
     matched_handles = 0
     unmatched_handles = 0
-    job_counts: list[int] = []
-
-    for line in path.read_text(encoding="utf-8", errors="replace").splitlines():
-        job_match = RE_JOB_COUNT.search(line)
-        if job_match:
-            job_counts.append(int(job_match.group(2)))
-
-        block_match = RE_RECORD_BLOCK.search(line)
-        if not block_match:
-            continue
 
+    for route in route_results:
         route_records = 0
-        for record_match in RE_RECORD.finditer(block_match.group(1)):
+        for record in route.records:
-            handle = record_match.group(2)
-            packed = int(record_match.group(3), 16)
-            pieces = record_match.group(4).split(",")
-            if len(pieces) < 4:
-                continue
-
             route_records += 1
             records += 1
-            bytes_tuple = bytes_le(packed)
+            bytes_tuple = bytes_le(record.packed)
             class_id = bytes_tuple[0]
             patterns[bytes_tuple] += 1
             first_byte[class_id] += 1
             for index, byte in enumerate(bytes_tuple):
                 byte_positions[index][byte] += 1
-            segments[(handle, class_id)] += 1
+            segments[(record.handle, class_id)] += 1
 
             if lane_lookup:
-                lane = lane_lookup.get(int(handle, 16))
+                lane = lane_lookup.get(record.handle)
                 if lane:
                     matched_handles += 1
                     class_categories[class_id][lane["category"]] += 1
@@ -155,6 +351,7 @@ def summarize(path: Path, lane_lookup: dict[int, dict[str, Any]]) -> None:
             speeds = dict(class_speed[class_id].most_common(8))
             flags = dict(class_flags[class_id].most_common(8))
             print(f"    {class_id}: categories={categories} speeds={speeds} flags={flags}")
+        print_per_route(path, submits, route_results, lane_lookup)
     for index, counter in enumerate(byte_positions):
         print(f"  byte{index} counts:", dict(counter.most_common(12)))
     print("  packed metadata patterns:")