- added benchmarking logs for delays in packet parsing and unit movem…

…ent updates
namreeb · Jan 7, 2016 · 6f4bc08 · 6f4bc08
1 parent 00f5fd9
commit 6f4bc08
Show file tree

Hide file tree

Showing 8 changed files with 180 additions and 9 deletions.
diff --git a/.gitignore b/.gitignore
@@ -6,3 +6,6 @@
 /*.sdf
 /*.opensdf
 /WowPacketSniff/*.aps
+/Release
+/WowPacketSniff/Release
+/loader/Release
diff --git a/WowPacketSniff/CMovement_C.hpp b/WowPacketSniff/CMovement_C.hpp
@@ -0,0 +1,75 @@
+#pragma once
+
+class CMovement_C
+{
+    private:
+        unsigned int Unk0;
+    public:
+        CMovement_C *Next;
+    private:
+        unsigned int Unk1[2];
+    public:
+        float ClientPosition[3];
+        float ClientOrientation;
+        float ClientPitch;
+
+        float MaybeGroundNormal[3];
+        unsigned int *Descriptors;
+    private:
+        unsigned int Unk34;
+    public:
+        unsigned __int64 TransportGuid;
+        unsigned int Flags;
+        unsigned int Flags2;
+        float LastServerPosition[3];
+        float LastServerOrientation;
+        float LastServerPitch;
+        unsigned int TimeSinceLastServerMove;
+        float JumpSinAngle1;
+        float JumpCosAngle1;
+        float JumpUnkAlwaysZero;
+        float Orientation2Cos;
+        float Orientation2Sin;
+        float Pitch2Cos;
+        float Pitch2Sin;
+        unsigned int FallTime;
+        float FallSpeed;
+        float SplineUnk1;
+        float JumpXYSpeed;
+        float WalkSpeed;
+        float RunSpeed;
+        float RunBackSpeed;
+        float SwimSpeed;
+        float SwimBackSpeed;
+        float FlightSpeed;
+        float FlightBackSpeed;
+        float TurnSpeed;
+        float JumpVelocity;
+    private:
+        void *Spline;
+    public:
+        unsigned int LocalTimeToApplyMovement;
+        unsigned int PreviousMoveServerTime;
+    private:
+        float UnknownFloat4;
+        float UnknownFloat5;
+        unsigned int UnkC4;
+        float m_collisionBoxHalfDepth;
+        float m_collisionBoxHeight;
+    public:
+        float StepUpHeight;
+    private:
+        unsigned int SomeArrayOfTimeHistory[32];
+        unsigned int SomeArrayNextIndex;
+        int MaxRecentHistoryValue;
+        unsigned int Unk15C;
+        float UnknownFloat8;
+        float Unk164;
+        float UnknownFloat9;
+        unsigned int Unk16C[2];
+        unsigned int MovementEventQueue[3];
+    public:
+        void *Owner;
+
+        void __thiscall ExecuteMovement(unsigned int timeNow, unsigned int lastUpdate);
+};
diff --git a/WowPacketSniff/PacketSniff.cpp b/WowPacketSniff/PacketSniff.cpp
@@ -60,7 +60,14 @@ void PacketSniff::SendHook(NetClient *netClient, CDataStore *packet) const
 
     LogPacket(packet, true);
 
+    auto const start = ::GetTickCount();
+
     (netClient->*trampoline)(packet);
+
+    auto const duration = ::GetTickCount() - start;
+
+    if (duration > 1000)
+        gLog << "# Last packet took " << duration << " ms to parse" << std::endl;
 }
 
 int PacketSniff::ReceiveHook(NetClient *netClient, int unknown, CDataStore *packet) const
@@ -69,7 +76,16 @@ int PacketSniff::ReceiveHook(NetClient *netClient, int unknown, CDataStore *pack
 
     LogPacket(packet, false);
 
-    return (netClient->*trampoline)(unknown, packet);
+    auto const start = ::GetTickCount();
+
+    auto const ret = (netClient->*trampoline)(unknown, packet);
+
+    auto const duration = ::GetTickCount() - start;
+
+    if (duration > 1000)
+        gLog << "# Last packet took " << duration << " ms to parse" << std::endl;
+
+    return ret;
 }
 
 void PacketSniff::LogPacket(CDataStore *packet, bool outgoing) const

diff --git a/WowPacketSniff/PerformanceMonitor.cpp b/WowPacketSniff/PerformanceMonitor.cpp
@@ -30,21 +30,29 @@
 #include "PerformanceMonitor.hpp"
 #include "offsets.hpp"
 #include "Log.hpp"
+#include "CMovement_C.hpp"
 
 #include <hadesmem/patcher.hpp>
 #include <hadesmem/process.hpp>
 #include <hadesmem/detail/alias_cast.hpp>
 
 #include <Windows.h>
+#include <cmath>
 
-PerformanceMonitor::PerformanceMonitor() : m_lastTick(0), m_process(::GetCurrentProcessId())
+PerformanceMonitor::PerformanceMonitor() : m_lastEndScene(0), m_process(::GetCurrentProcessId())
 {
     auto const endSceneCallerOrig = hadesmem::detail::AliasCast<EndSceneCallerT>(Offsets::CVideo__EndSceneCaller);
     auto const endSceneCallerWrap = [this](hadesmem::PatchDetourBase *detour, CVideo *pVid) { return this->EndSceneHook(pVid); };
 
     m_endSceneCaller = std::make_unique<hadesmem::PatchDetour<EndSceneCallerT>>(m_process, endSceneCallerOrig, endSceneCallerWrap);
     m_endSceneCaller->Apply();
 
+    auto const executeMovementOrig = hadesmem::detail::AliasCast<ExecuteMovementT>(Offsets::CMovement_C__ExecuteMovement);
+    auto const executeMovementWrap = [this](hadesmem::PatchDetourBase *detour, CMovement_C *movement, unsigned timeNow, unsigned lastUpdate) { this->ExecuteMovementHook(movement, timeNow, lastUpdate); };
+
+    m_executeMovement = std::make_unique<hadesmem::PatchDetour<ExecuteMovementT>>(m_process, executeMovementOrig, executeMovementWrap);
+    m_executeMovement->Apply();
+
     gLog << "# Log started at " << time(nullptr) << std::endl;
 }
 
@@ -58,12 +66,68 @@ HRESULT PerformanceMonitor::EndSceneHook(CVideo *pVid)
     auto const trampoline = m_endSceneCaller->GetTrampolineT<EndSceneCallerT>();
 
     auto const tickCount = ::GetTickCount();
-    auto const tickDiff = tickCount - m_lastTick;
+    auto const tickDiff = tickCount - m_lastEndScene;
 
-    if (!!m_lastTick && tickDiff >= 250)
+    if (!!m_lastEndScene && tickDiff >= 250)
         gLog << "# Potential freeze at " << time(nullptr) << ".  Tick delay: " << tickDiff << " ms" << std::endl;
 
-    m_lastTick = tickCount;
+    m_lastEndScene = tickCount;
 
     return (pVid->*trampoline)();
+}
+
+class CGUnit_C
+{
+    private:
+        unsigned int dword0[2];
+    public:
+        unsigned int *Descriptors;
+};
+
+void PerformanceMonitor::ExecuteMovementHook(CMovement_C *movement, unsigned int timeNow, unsigned int lastUpdate)
+{
+    auto const trampoline = m_executeMovement->GetTrampolineT<ExecuteMovementT>();
+
+    auto const start = ::GetTickCount();
+
+    auto const startX = movement->ClientPosition[0];
+    auto const startY = movement->ClientPosition[1];
+    auto const startZ = movement->ClientPosition[2];
+
+    auto const startFlags = movement->Flags;
+
+    (movement->*trampoline)(timeNow, lastUpdate);
+
+    auto const duration = ::GetTickCount() - start;
+
+    if (duration > 1000)
+    {
+        auto const unit = static_cast<CGUnit_C *>(movement->Owner);
+
+        gLog << "# CMovement_C::ExecuteMovement took " << duration << " ms.  From (" << startX << ", " << startY << ", " << startZ << ") to (";
+
+        if (isnan(movement->ClientPosition[0]))
+            gLog << "nan";
+        else
+            gLog << movement->ClientPosition[0];
+
+        gLog << ", ";
+
+        if (isnan(movement->ClientPosition[1]))
+            gLog << "nan";
+        else
+            gLog << movement->ClientPosition[1];
+
+        gLog << ", ";
+
+        if (isnan(movement->ClientPosition[2]))
+            gLog << "nan";
+        else
+            gLog << movement->ClientPosition[2];
+
+        unsigned __int64 guid = *reinterpret_cast<unsigned __int64 *>(unit->Descriptors);
+        gLog << ") GUID: 0x" << std::hex << std::uppercase << guid << std::dec;
+
+        gLog << " Flags from: 0x" << std::hex << std::uppercase << startFlags << " to 0x" << movement->Flags << std::dec << std::endl;
+    }
 }
diff --git a/WowPacketSniff/PerformanceMonitor.hpp b/WowPacketSniff/PerformanceMonitor.hpp
@@ -29,14 +29,19 @@
 
 #pragma once
 
-#include <memory>
+#include "CMovement_C.hpp"
 
 #include <hadesmem/patcher.hpp>
 #include <hadesmem/process.hpp>
 
+#include <memory>
+
 class PerformanceMonitor
 {
     private:
+        const hadesmem::Process m_process;
+        DWORD m_lastEndScene;
+
         // note that for the sake of simplicity, we hook the function
         // which calls endscene, rather than endscene itself
         struct CVideo
@@ -46,13 +51,16 @@ class PerformanceMonitor
 
         using EndSceneCallerT = decltype(&CVideo::EndSceneCaller);
 
-        const hadesmem::Process m_process;
-        DWORD m_lastTick;
-
         std::unique_ptr<hadesmem::PatchDetour<EndSceneCallerT>> m_endSceneCaller;
 
         HRESULT EndSceneHook(CVideo *pVid);
 
+        using ExecuteMovementT = decltype(&CMovement_C::ExecuteMovement);
+
+        std::unique_ptr<hadesmem::PatchDetour<ExecuteMovementT>> m_executeMovement;
+
+        void ExecuteMovementHook(CMovement_C *movement, unsigned int timeNow, unsigned int lastUpdate);
+
     public:
         PerformanceMonitor();
         ~PerformanceMonitor();

diff --git a/WowPacketSniff/WowPacketSniff.vcxproj b/WowPacketSniff/WowPacketSniff.vcxproj
@@ -26,6 +26,7 @@
   </ItemGroup>
   <ItemGroup>
     <ClInclude Include="CDataStore.hpp" />
+    <ClInclude Include="CMovement_C.hpp" />
     <ClInclude Include="Log.hpp" />
     <ClInclude Include="offsets.hpp" />
     <ClInclude Include="PacketSniff.hpp" />

diff --git a/WowPacketSniff/WowPacketSniff.vcxproj.filters b/WowPacketSniff/WowPacketSniff.vcxproj.filters
@@ -40,5 +40,8 @@
     <ClInclude Include="PacketSniff.hpp">
       <Filter>Header Files</Filter>
     </ClInclude>
+    <ClInclude Include="CMovement_C.hpp">
+      <Filter>Header Files</Filter>
+    </ClInclude>
   </ItemGroup>
 </Project>
diff --git a/WowPacketSniff/offsets.hpp b/WowPacketSniff/offsets.hpp
@@ -34,4 +34,5 @@ enum Offsets : DWORD
     NetClient__Send                 = 0x55F8A0,
     NetClient__ProcessMessage       = 0x55F440,
     CVideo__EndSceneCaller          = 0x5AB230,
+    CMovement_C__ExecuteMovement    = 0x5D2DC0,
 };