diff --git a/docs/red4ext-logging-shim.md b/docs/red4ext-logging-shim.md index c224188..8796f85 100644 --- a/docs/red4ext-logging-shim.md +++ b/docs/red4ext-logging-shim.md @@ -29,9 +29,15 @@ Current behavior: - Hooks the route handoff found from the journal listener bridge: `0x598250`, `0x13763d8`, `0xaa62d0`, `0xaa6330`, `0x27abd7c`, and `0x5625a4`. -- Logs mappin route-event fields, active/deactive route refs, the mappin +- Logs mappin route-event fields, active/deactive route keys, the mappin active-route map at `system + 0x1a0`, and the route observer list at `system + 0x280`. +- Hooks the route observer callbacks reached by route activation/deactivation: + `0xaa6610`, `0xaa6628`, `0xaa63e0`, `0x27b10c0`, `0x295d4a0`, and + `0x286a85c`. +- Logs the route entry pointer and route object pointer passed to those + observers, including route object vtable slots and common fields such as the + active byte at offset `0x84`. - Resolves the native mappin system when one of those paths fires, logs relevant vtable slot addresses, and temporarily hooks the route-adjacent slots. @@ -48,6 +54,8 @@ Current route-probe focus: - mappin route-event enqueue: `0x13763d8` - mappin route-event handler: `0xaa62d0` - mappin route activate/deactivate: `0xaa6330`, `0x27abd7c` +- mappin route observer callbacks: `0xaa6610`, `0xaa6628`, `0xaa63e0`, + `0x27b10c0`, `0x295d4a0`, `0x286a85c` - route-build candidate called by the bridge: `0x5625a4` Quest/objective pins did not fire the mappin tracking hooks in live tests. The @@ -66,6 +74,22 @@ Most recent controlled test: dispatch to no-op `0x14a700`; the non-default callbacks above are the current drill-down targets. +Newest controlled test: + +- User clock `01:05`: Continue on the main menu. The log saw + `GPSSystem/Tick`. +- User clock `01:27`: Space to continue. The log saw automatic + `JournalManager.TrackEntry`, a dense `JournalRouteBridge` burst, and thirty + `RouteBuildCandidate 0x5625a4` calls. About 5.5 seconds later the mappin route + activation/deactivation functions fired. +- User clock `01:52`: map open. Hovering icons produced the expected + `SetSelectedMappin` bursts. +- Deliberate quest route clicks produced `JournalManager.TrackEntry`, route + event enqueue calls for old-route-off/new-route-on, and route event handler + calls roughly 11-18 ms later. +- Custom pin routing used the separate custom-position mappin path, then the + shared route activate/deactivate helper. + Build and install from the Fedora toolbox: ```bash diff --git a/docs/traffic-system-debrief.md b/docs/traffic-system-debrief.md index b1991a8..c09e5bf 100644 --- a/docs/traffic-system-debrief.md +++ b/docs/traffic-system-debrief.md @@ -302,13 +302,49 @@ deactivates an old route ref and activates a new route ref. That is likely the common mappin state transition path for both journal/objective routes and custom/player pins. +The newest controlled run confirms the queued route event timing: + +```text +quest route click + -> JournalManager.TrackEntry from wrapper return RVA 0x26ac34e + -> MappinSystem route-event enqueue old route active=0 + -> MappinSystem route-event enqueue new route active=1 + -> 11-18 ms later: MappinRouteEvent::Handle + -> MappinSystem::RouteDeactivate(old route key) + -> MappinSystem::RouteActivate(new route key) + -> route observers at system + 0x280 +``` + +The click-to-event delay matched the in-game behavior: the old GPS path +disappears for a few frames, then the new path appears. That makes the route +observer fanout the next most useful runtime layer to inspect. + +The activation/deactivation argument is not an object pointer. It is a 64-bit +route key. Static disassembly of `0xaa6330` and `0x27abd7c` shows that key being +looked up in the active-route map at `mappinSystem + 0x1a0`; the resulting map +entry's `+0x08` field points at the actual route object/smart pointer passed to +route observers. + +The first observer callback set seen at runtime is: + +```text +observer vtable 0x14310e760: slot 0x48 -> 0xaa6610, slot 0x50 -> 0x27b10c0 +observer vtable 0x143136050: slot 0x48 -> 0xaa6628, slot 0x50 -> 0x295d4a0 +observer vtable 0x143121458: slot 0x48 -> 0xaa63e0, slot 0x50 -> 0x286a85c +``` + +The installed probe now hooks those callbacks directly and logs the route entry, +route object, route object vtable slots, and the route object's active byte at +offset `0x84`. + The most route-building-looking static candidate currently in this chain is `0x5625a4`, called once from the bridge at `0x5984ec`. The bridge resolves journal route ids through virtual journal-manager calls, collects several route -descriptor/data pointers, and passes them to `0x5625a4`. The current RED4ext -probe hooks this function with a 12-argument inferred signature to determine -whether it builds GPS/path display data or merely updates UI-facing route -metadata. +descriptor/data pointers, and passes them to `0x5625a4`. Runtime evidence now +shows this function firing in a dense load-time/minimap setup burst, not during +later deliberate map-click route plotting. It may build cached route descriptors +or GPS display metadata, but it is probably not the direct click-time solver +entry point. ## Native False Positives diff --git a/red4ext/EdgeWeightGPS/src/Main.cpp b/red4ext/EdgeWeightGPS/src/Main.cpp index 13ae5c6..e68bba6 100644 --- a/red4ext/EdgeWeightGPS/src/Main.cpp +++ b/red4ext/EdgeWeightGPS/src/Main.cpp @@ -131,6 +131,12 @@ constexpr uintptr_t kMappinRouteEventHandlerRva = 0x0AA62D0; constexpr uintptr_t kMappinRouteActivateRva = 0x0AA6330; constexpr uintptr_t kMappinRouteDeactivateRva = 0x27ABD7C; constexpr uintptr_t kRouteBuildCandidateRva = 0x05625A4; +constexpr uintptr_t kRouteObserver0ActivateRva = 0x0AA6610; +constexpr uintptr_t kRouteObserver1ActivateRva = 0x0AA6628; +constexpr uintptr_t kRouteObserver23ActivateRva = 0x0AA63E0; +constexpr uintptr_t kRouteObserver0DeactivateRva = 0x27B10C0; +constexpr uintptr_t kRouteObserver1DeactivateRva = 0x295D4A0; +constexpr uintptr_t kRouteObserver23DeactivateRva = 0x286A85C; HMODULE gModule = nullptr; std::mutex gLogMutex; @@ -177,6 +183,12 @@ uint32_t gMappinRouteEventHandlerLogCount = 0; uint32_t gMappinRouteActivateLogCount = 0; uint32_t gMappinRouteDeactivateLogCount = 0; uint32_t gRouteBuildCandidateLogCount = 0; +uint32_t gRouteObserver0ActivateLogCount = 0; +uint32_t gRouteObserver1ActivateLogCount = 0; +uint32_t gRouteObserver23ActivateLogCount = 0; +uint32_t gRouteObserver0DeactivateLogCount = 0; +uint32_t gRouteObserver1DeactivateLogCount = 0; +uint32_t gRouteObserver23DeactivateLogCount = 0; uint64_t gLogStartTick = 0; uint64_t gLogFrequency = 0; void* gMappinSetTrackedTarget = nullptr; @@ -209,12 +221,13 @@ using JournalListenerCallbackFunc = void (*)(void* aListener, void* aEvent); using JournalRouteBridgeFunc = bool (*)(void* aThis, void* aEntryHandle); using MappinRouteEventEnqueueFunc = void (*)(void* aSystem, uint32_t aRouteId, uint8_t aActive); using MappinRouteEventHandlerFunc = void (*)(void* aEvent, void* aRouteHandle); -using MappinRouteToggleFunc = void (*)(void* aSystem, void* aRouteRef); +using MappinRouteToggleFunc = void (*)(void* aSystem, uint64_t aRouteKey); using RouteBuildCandidateFunc = void (*)(void* aThis, uint32_t aRouteId, uint32_t aAltRouteId, uint32_t aPreviousRouteId, void* aRoutePositionData, void* aPrimaryDescriptor, void* aSecondaryDescriptor, void* aRouteData88, void* aRouteData108, void* aRouteData114, uint8_t aFlag, uint32_t aMode); +using RouteObserverCallbackFunc = void (*)(void* aObserver, void* aRouteEntry); ProbeFunc gOriginalGpsSystemTick = nullptr; JournalTrackEntryFunc gOriginalJournalTrackEntry = nullptr; ScriptNativeVoidFunc gOriginalFrameMappinPathWrapper = nullptr; @@ -252,6 +265,12 @@ MappinRouteEventHandlerFunc gOriginalMappinRouteEventHandler = nullptr; MappinRouteToggleFunc gOriginalMappinRouteActivate = nullptr; MappinRouteToggleFunc gOriginalMappinRouteDeactivate = nullptr; RouteBuildCandidateFunc gOriginalRouteBuildCandidate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver0Activate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver1Activate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver23Activate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver0Deactivate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver1Deactivate = nullptr; +RouteObserverCallbackFunc gOriginalRouteObserver23Deactivate = nullptr; std::filesystem::path GetLogPath() { @@ -361,6 +380,11 @@ void AppendReturnRva(std::ostringstream& aLine, const void* aReturnAddress) } } +void AppendHexValue(std::ostringstream& aLine, const char* aLabel, uint64_t aValue) +{ + aLine << " " << aLabel << "=0x" << std::hex << aValue << std::dec; +} + void LogHookCall(const char* aName, uint32_t aCount, void* aThis, void* a2, void* a3, void* a4) { std::ostringstream line; @@ -645,11 +669,53 @@ void LogMappinRouteCollections(const char* aName, uint32_t aCount, void* aSystem std::ostringstream observerLine; observerLine << "mappin-route-observer " << aName << " call=" << aCount << " index=" << index; AppendPointerWithRva(observerLine, "observer", observer); - AppendObjectVtableSlots(observerLine, observer, {0x48, 0x50, 0x210, 0x260}); + AppendObjectVtableSlots(observerLine, observer, {0x48, 0x50}); LogRed4ext(observerLine.str()); } } +void LogRouteObserverContext(const char* aName, uint32_t aCount, void* aObserver, void* aRouteEntry) +{ + auto* observerInner = ReadPointerField(aObserver, 0x08); + auto* routeObject = ReadPointerField(aRouteEntry, 0x00); + + std::ostringstream line; + line << "hook " << aName << " call=" << aCount; + AppendPointerWithRva(line, "observer", aObserver); + AppendPointerWithRva(line, "observerInner", observerInner); + AppendPointerWithRva(line, "routeEntry", aRouteEntry); + AppendPointerWithRva(line, "routeObject", routeObject); + AppendPointerField(line, "routeEntry_f08", aRouteEntry, 0x08); + AppendPointerField(line, "routeEntry_f10", aRouteEntry, 0x10); + AppendReturnRva(line, __builtin_return_address(0)); + LogRed4ext(line.str()); + + std::ostringstream observerLine; + observerLine << "route-observer-object " << aName << " call=" << aCount; + AppendPointerWithRva(observerLine, "observer", aObserver); + AppendObjectVtableSlots(observerLine, aObserver, {0x48, 0x50}); + LogRed4ext(observerLine.str()); + + if (!routeObject) + { + return; + } + + std::ostringstream routeLine; + routeLine << "route-observer-route-object " << aName << " call=" << aCount; + AppendPointerWithRva(routeLine, "routeObject", routeObject); + AppendObjectVtableSlots(routeLine, routeObject, {0x140, 0x188, 0x198, 0x1A8}); + AppendPointerField(routeLine, "field40", routeObject, 0x40); + AppendPointerField(routeLine, "field48", routeObject, 0x48); + AppendPointerField(routeLine, "field78", routeObject, 0x78); + AppendUint32Field(routeLine, "field80", routeObject, 0x80); + AppendByteField(routeLine, "active84", routeObject, 0x84); + AppendPointerField(routeLine, "field88", routeObject, 0x88); + AppendPointerField(routeLine, "fieldF8", routeObject, 0xF8); + AppendPointerField(routeLine, "field120", routeObject, 0x120); + LogRed4ext(routeLine.str()); +} + void LogRouteEventFields(const char* aName, uint32_t aCount, void* aEvent) { uint32_t routeId = 0; @@ -1087,14 +1153,14 @@ void DetourMappinRouteEventHandler(void* aEvent, void* aRouteHandle) { const auto callCount = gMappinRouteEventHandlerLogCount; void* routeOwner = ReadPointerField(aRouteHandle, 0); - void* routeRef = ReadPointerField(routeOwner, 0x40); + const auto routeKey = reinterpret_cast(ReadPointerField(routeOwner, 0x40)); std::ostringstream line; line << "hook MappinRouteEvent::Handle call=" << callCount; AppendPointerWithRva(line, "event", aEvent); AppendPointerWithRva(line, "routeHandle", aRouteHandle); AppendPointerWithRva(line, "routeOwner", routeOwner); - AppendRouteRefFields(line, "routeRef", routeRef); + AppendHexValue(line, "routeKey", routeKey); AppendReturnRva(line, __builtin_return_address(0)); LogRed4ext(line.str()); LogRouteEventFields("handler-before", callCount, aEvent); @@ -1107,7 +1173,7 @@ void DetourMappinRouteEventHandler(void* aEvent, void* aRouteHandle) } } -void DetourMappinRouteActivate(void* aSystem, void* aRouteRef) +void DetourMappinRouteActivate(void* aSystem, uint64_t aRouteKey) { constexpr uint32_t kMaxCalls = 64; @@ -1117,7 +1183,7 @@ void DetourMappinRouteActivate(void* aSystem, void* aRouteRef) std::ostringstream line; line << "hook MappinSystem::RouteActivate call=" << callCount; AppendPointerWithRva(line, "system", aSystem); - AppendRouteRefFields(line, "routeRef", aRouteRef); + AppendHexValue(line, "routeKey", aRouteKey); AppendReturnRva(line, __builtin_return_address(0)); LogRed4ext(line.str()); LogMappinRouteCollections("activate-before", callCount, aSystem); @@ -1126,11 +1192,11 @@ void DetourMappinRouteActivate(void* aSystem, void* aRouteRef) if (gOriginalMappinRouteActivate) { - gOriginalMappinRouteActivate(aSystem, aRouteRef); + gOriginalMappinRouteActivate(aSystem, aRouteKey); } } -void DetourMappinRouteDeactivate(void* aSystem, void* aRouteRef) +void DetourMappinRouteDeactivate(void* aSystem, uint64_t aRouteKey) { constexpr uint32_t kMaxCalls = 64; @@ -1140,7 +1206,7 @@ void DetourMappinRouteDeactivate(void* aSystem, void* aRouteRef) std::ostringstream line; line << "hook MappinSystem::RouteDeactivate call=" << callCount; AppendPointerWithRva(line, "system", aSystem); - AppendRouteRefFields(line, "routeRef", aRouteRef); + AppendHexValue(line, "routeKey", aRouteKey); AppendReturnRva(line, __builtin_return_address(0)); LogRed4ext(line.str()); LogMappinRouteCollections("deactivate-before", callCount, aSystem); @@ -1149,7 +1215,7 @@ void DetourMappinRouteDeactivate(void* aSystem, void* aRouteRef) if (gOriginalMappinRouteDeactivate) { - gOriginalMappinRouteDeactivate(aSystem, aRouteRef); + gOriginalMappinRouteDeactivate(aSystem, aRouteKey); } } @@ -1187,6 +1253,59 @@ void DetourRouteBuildCandidate(void* aThis, uint32_t aRouteId, uint32_t aAltRout } } +void DispatchRouteObserverCallback(const char* aName, uint32_t& aCounter, RouteObserverCallbackFunc aOriginal, + void* aObserver, void* aRouteEntry) +{ + constexpr uint32_t kMaxCalls = 96; + + if (aCounter < kMaxCalls) + { + LogRouteObserverContext(aName, aCounter, aObserver, aRouteEntry); + ++aCounter; + } + + if (aOriginal) + { + aOriginal(aObserver, aRouteEntry); + } +} + +void DetourRouteObserver0Activate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver0::Activate slot48", gRouteObserver0ActivateLogCount, + gOriginalRouteObserver0Activate, aObserver, aRouteEntry); +} + +void DetourRouteObserver1Activate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver1::Activate slot48", gRouteObserver1ActivateLogCount, + gOriginalRouteObserver1Activate, aObserver, aRouteEntry); +} + +void DetourRouteObserver23Activate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver23::Activate slot48", gRouteObserver23ActivateLogCount, + gOriginalRouteObserver23Activate, aObserver, aRouteEntry); +} + +void DetourRouteObserver0Deactivate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver0::Deactivate slot50", gRouteObserver0DeactivateLogCount, + gOriginalRouteObserver0Deactivate, aObserver, aRouteEntry); +} + +void DetourRouteObserver1Deactivate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver1::Deactivate slot50", gRouteObserver1DeactivateLogCount, + gOriginalRouteObserver1Deactivate, aObserver, aRouteEntry); +} + +void DetourRouteObserver23Deactivate(void* aObserver, void* aRouteEntry) +{ + DispatchRouteObserverCallback("RouteObserver23::Deactivate slot50", gRouteObserver23DeactivateLogCount, + gOriginalRouteObserver23Deactivate, aObserver, aRouteEntry); +} + void DetourFrameMappinPathWrapper(void* aThis, void* aStack, void* aResult) { if (gFrameMappinPathWrapperLogCount < 64) @@ -1829,6 +1948,24 @@ RED4EXT_C_EXPORT bool RED4EXT_CALL Main(RED4ext::v1::PluginHandle aHandle, RED4e AttachProbeHook("RouteBuildCandidate 0x5625a4", kRouteBuildCandidateRva, reinterpret_cast(&DetourRouteBuildCandidate), reinterpret_cast(&gOriginalRouteBuildCandidate)); + AttachProbeHook("RouteObserver0::Activate slot48", kRouteObserver0ActivateRva, + reinterpret_cast(&DetourRouteObserver0Activate), + reinterpret_cast(&gOriginalRouteObserver0Activate)); + AttachProbeHook("RouteObserver1::Activate slot48", kRouteObserver1ActivateRva, + reinterpret_cast(&DetourRouteObserver1Activate), + reinterpret_cast(&gOriginalRouteObserver1Activate)); + AttachProbeHook("RouteObserver23::Activate slot48", kRouteObserver23ActivateRva, + reinterpret_cast(&DetourRouteObserver23Activate), + reinterpret_cast(&gOriginalRouteObserver23Activate)); + AttachProbeHook("RouteObserver0::Deactivate slot50", kRouteObserver0DeactivateRva, + reinterpret_cast(&DetourRouteObserver0Deactivate), + reinterpret_cast(&gOriginalRouteObserver0Deactivate)); + AttachProbeHook("RouteObserver1::Deactivate slot50", kRouteObserver1DeactivateRva, + reinterpret_cast(&DetourRouteObserver1Deactivate), + reinterpret_cast(&gOriginalRouteObserver1Deactivate)); + AttachProbeHook("RouteObserver23::Deactivate slot50", kRouteObserver23DeactivateRva, + reinterpret_cast(&DetourRouteObserver23Deactivate), + reinterpret_cast(&gOriginalRouteObserver23Deactivate)); AttachProbeHook("FrameMappinPathWrapper", kFrameMappinPathWrapperRva, reinterpret_cast(&DetourFrameMappinPathWrapper), reinterpret_cast(&gOriginalFrameMappinPathWrapper)); @@ -1885,6 +2022,12 @@ RED4EXT_C_EXPORT bool RED4EXT_CALL Main(RED4ext::v1::PluginHandle aHandle, RED4e DetachProbeHook("MappinSystem::RouteActivate", kMappinRouteActivateRva); DetachProbeHook("MappinSystem::RouteDeactivate", kMappinRouteDeactivateRva); DetachProbeHook("RouteBuildCandidate 0x5625a4", kRouteBuildCandidateRva); + DetachProbeHook("RouteObserver0::Activate slot48", kRouteObserver0ActivateRva); + DetachProbeHook("RouteObserver1::Activate slot48", kRouteObserver1ActivateRva); + DetachProbeHook("RouteObserver23::Activate slot48", kRouteObserver23ActivateRva); + DetachProbeHook("RouteObserver0::Deactivate slot50", kRouteObserver0DeactivateRva); + DetachProbeHook("RouteObserver1::Deactivate slot50", kRouteObserver1DeactivateRva); + DetachProbeHook("RouteObserver23::Deactivate slot50", kRouteObserver23DeactivateRva); DetachProbeHook("FrameMappinPathWrapper", kFrameMappinPathWrapperRva); DetachProbeHook("FrameMappinPathCore", kFrameMappinPathCoreRva); DetachProbeHook("SetSelectedMappinWrapper", kSetSelectedMappinWrapperRva);