stall_probe.cpp 10 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273
  1. /**
  2. * Names the code a silent freeze blocks on.
  3. * Some freezes stop the game's own watchdog with the rest of the game, so no hitch snapshot
  4. * ever names the blocked code. This watcher polls the pump call count from its own thread;
  5. * when the count stops moving it captures every thread's rip and in-image return addresses.
  6. */
  7. #include "stall_probe.h"
  8. #include <Windows.h>
  9. #include <TlHelp32.h>
  10. #include <array>
  11. #include <atomic>
  12. #include <cstddef>
  13. #include <cstdint>
  14. #include <cstdio>
  15. #include <cstring>
  16. #include "../../../core/logging/log.h"
  17. #include "../../../steam/runtime/runtime.h"
  18. #include "../../diagnostics/module_range.h"
  19. #include "../../memory/current_process_memory.h"
  20. namespace sunrise::client::hooks::stall_probe {
  21. namespace {
  22. /** Poll cadence, and how long the count must sit still before a dump. */
  23. constexpr DWORD kPollMs = 500;
  24. constexpr std::uint64_t kStallMs = 6'000;
  25. /** Repeat dumps of one long stall, spaced and capped: rip movement separates spin from wait. */
  26. constexpr std::uint64_t kRedumpMs = 15'000;
  27. constexpr unsigned kMaxDumps = 8;
  28. /** Bytes of stack copied per thread, halved until a read succeeds. */
  29. constexpr std::size_t kStackWindowBytes = 2048;
  30. /** Module-relative return addresses kept from that window, and how many share one line. */
  31. constexpr std::size_t kFrameLimit = 16;
  32. constexpr std::size_t kFramesPerLine = 8;
  33. /** Time the stopping side waits for the watcher to leave its loop. */
  34. constexpr DWORD kJoinMs = 2'000;
  35. HANDLE g_thread{};
  36. HANDLE g_stop{};
  37. std::atomic_bool g_installed{false};
  38. diagnostics::ModuleRange g_gameRange{};
  39. diagnostics::ModuleRange g_ownRange{};
  40. /** Resolves the game image range and this DLL's own range once. */
  41. void resolve_module_ranges() noexcept {
  42. (void)diagnostics::module_range(GetModuleHandleW(nullptr), g_gameRange);
  43. HMODULE own = nullptr;
  44. GetModuleHandleExW(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS
  45. | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT,
  46. reinterpret_cast<LPCWSTR>(&resolve_module_ranges),
  47. &own);
  48. (void)diagnostics::module_range(own, g_ownRange);
  49. }
  50. /** Formats one code address as a module-relative token, or raw hex outside both images. */
  51. void format_address(std::uint64_t value, char* out, std::size_t size) noexcept {
  52. if (diagnostics::contains(g_gameRange, value)) {
  53. std::snprintf(
  54. out, size, "exe+0x%llX", static_cast<unsigned long long>(value - g_gameRange.base));
  55. return;
  56. }
  57. if (diagnostics::contains(g_ownRange, value)) {
  58. std::snprintf(
  59. out, size, "own+0x%llX", static_cast<unsigned long long>(value - g_ownRange.base));
  60. return;
  61. }
  62. std::snprintf(out, size, "0x%llX", static_cast<unsigned long long>(value));
  63. }
  64. /**
  65. * Suspends one thread, copies its control registers and a stack window, then resumes it.
  66. * Only memory is taken while the thread is suspended; all logging happens after the resume.
  67. * @return True when the context was captured. A short or absent stack window is still success.
  68. */
  69. [[nodiscard]] bool capture_thread(std::uint32_t tid,
  70. CONTEXT& context,
  71. std::byte* stack,
  72. std::size_t& stackBytes) noexcept {
  73. stackBytes = 0;
  74. const HANDLE thread = OpenThread(
  75. THREAD_SUSPEND_RESUME | THREAD_GET_CONTEXT | THREAD_QUERY_LIMITED_INFORMATION, FALSE, tid);
  76. if (thread == nullptr) {
  77. return false;
  78. }
  79. bool captured = false;
  80. if (SuspendThread(thread) != static_cast<DWORD>(-1)) {
  81. context.ContextFlags = CONTEXT_CONTROL;
  82. captured = GetThreadContext(thread, &context) != 0;
  83. if (captured) {
  84. for (std::size_t size = kStackWindowBytes; size >= 256; size /= 2) {
  85. if (memory::read_current_process(nullptr, context.Rsp, std::span(stack, size))) {
  86. stackBytes = size;
  87. break;
  88. }
  89. }
  90. }
  91. ResumeThread(thread);
  92. }
  93. CloseHandle(thread);
  94. return captured;
  95. }
  96. /** Logs one thread's rip, rsp and every in-image return address on its stack. */
  97. void report_thread(std::uint32_t tid) noexcept {
  98. alignas(16) CONTEXT context{};
  99. std::array<std::byte, kStackWindowBytes> stack{};
  100. std::size_t stackBytes = 0;
  101. if (!capture_thread(tid, context, stack.data(), stackBytes)) {
  102. return;
  103. }
  104. std::array<char, 32> ripText{};
  105. format_address(context.Rip, ripText.data(), ripText.size());
  106. std::array<char, core::log::kLineCapacity> line{};
  107. int written = std::snprintf(line.data(),
  108. line.size(),
  109. "ev=probe stage=stall set=stack tid=0x%08X rip=%s rsp=0x%llX "
  110. "window=%zu",
  111. tid,
  112. ripText.data(),
  113. static_cast<unsigned long long>(context.Rsp),
  114. stackBytes);
  115. if (written > 0) {
  116. core::log::write(core::log::Channel::client,
  117. core::log::Level::info,
  118. {line.data(), static_cast<std::size_t>(written)});
  119. }
  120. std::size_t frames = 0;
  121. std::size_t onLine = 0;
  122. std::size_t offset = 0;
  123. for (std::size_t index = 0; index * 8 + 8 <= stackBytes && frames < kFrameLimit; ++index) {
  124. std::uint64_t value = 0;
  125. std::memcpy(&value, stack.data() + index * 8, sizeof value);
  126. if (!diagnostics::contains(g_gameRange, value)
  127. && !diagnostics::contains(g_ownRange, value)) {
  128. continue;
  129. }
  130. if (onLine == 0) {
  131. const int prefix = std::snprintf(
  132. line.data(), line.size(), "ev=probe stage=stall set=frames tid=0x%08X", tid);
  133. offset = prefix > 0 ? static_cast<std::size_t>(prefix) : 0;
  134. }
  135. std::array<char, 32> text{};
  136. format_address(value, text.data(), text.size());
  137. const int piece = std::snprintf(
  138. line.data() + offset, line.size() - offset, " f%zu=%s", frames, text.data());
  139. if (piece > 0) {
  140. offset += static_cast<std::size_t>(piece);
  141. }
  142. ++frames;
  143. ++onLine;
  144. if (onLine == kFramesPerLine || frames == kFrameLimit) {
  145. core::log::write(
  146. core::log::Channel::client, core::log::Level::info, {line.data(), offset});
  147. onLine = 0;
  148. }
  149. }
  150. if (onLine != 0) {
  151. core::log::write(core::log::Channel::client, core::log::Level::info, {line.data(), offset});
  152. }
  153. }
  154. /** Captures every other thread in the process, one at a time. */
  155. void dump_all_threads() noexcept {
  156. const HANDLE snapshot = CreateToolhelp32Snapshot(TH32CS_SNAPTHREAD, 0);
  157. if (snapshot == INVALID_HANDLE_VALUE) {
  158. return;
  159. }
  160. THREADENTRY32 entry{};
  161. entry.dwSize = sizeof(entry);
  162. const DWORD processId = GetCurrentProcessId();
  163. const DWORD currentThreadId = GetCurrentThreadId();
  164. for (BOOL available = Thread32First(snapshot, &entry); available != FALSE;
  165. available = Thread32Next(snapshot, &entry)) {
  166. if (entry.th32OwnerProcessID == processId && entry.th32ThreadID != currentThreadId) {
  167. report_thread(entry.th32ThreadID);
  168. }
  169. }
  170. CloseHandle(snapshot);
  171. }
  172. /** Writes the one-line stall marker. @param result "detected" or "recovered". */
  173. void report_marker(const char* result, std::uint64_t idleMs, std::uint64_t count) noexcept {
  174. std::array<char, core::log::kLineCapacity> line{};
  175. const int written = std::snprintf(line.data(),
  176. line.size(),
  177. "ev=probe stage=stall result=%s idle=%llu count=%llu",
  178. result,
  179. static_cast<unsigned long long>(idleMs),
  180. static_cast<unsigned long long>(count));
  181. if (written > 0) {
  182. core::log::write(core::log::Channel::client,
  183. core::log::Level::warn,
  184. {line.data(), static_cast<std::size_t>(written)});
  185. }
  186. }
  187. /** The watcher loop: poll the pump count, dump when it sits still. */
  188. DWORD WINAPI watch(LPVOID) noexcept {
  189. std::uint64_t lastCount = steam::callback_count();
  190. std::uint64_t lastMoveMs = GetTickCount64();
  191. std::uint64_t nextDumpMs = 0;
  192. unsigned dumps = 0;
  193. bool stalled = false;
  194. while (WaitForSingleObject(g_stop, kPollMs) == WAIT_TIMEOUT) {
  195. const std::uint64_t count = steam::callback_count();
  196. const std::uint64_t now = GetTickCount64();
  197. if (count != lastCount) {
  198. if (stalled) {
  199. report_marker("recovered", now - lastMoveMs, count);
  200. stalled = false;
  201. }
  202. lastCount = count;
  203. lastMoveMs = now;
  204. continue;
  205. }
  206. // The count only moves once the game starts pumping, so boot does not read as a stall.
  207. if (count == 0 || now - lastMoveMs < kStallMs || now < nextDumpMs || dumps >= kMaxDumps) {
  208. continue;
  209. }
  210. report_marker("detected", now - lastMoveMs, count);
  211. stalled = true;
  212. dump_all_threads();
  213. ++dumps;
  214. nextDumpMs = now + kRedumpMs;
  215. }
  216. return 0;
  217. }
  218. } // namespace
  219. /** Starts the stall watcher thread. */
  220. bool install() noexcept {
  221. if (g_installed.load(std::memory_order_acquire)) {
  222. return true;
  223. }
  224. resolve_module_ranges();
  225. g_stop = CreateEventW(nullptr, TRUE, FALSE, nullptr);
  226. if (g_stop == nullptr) {
  227. return false;
  228. }
  229. g_thread = CreateThread(nullptr, 0, &watch, nullptr, 0, nullptr);
  230. if (g_thread == nullptr) {
  231. CloseHandle(g_stop);
  232. g_stop = nullptr;
  233. return false;
  234. }
  235. g_installed.store(true, std::memory_order_release);
  236. core::log::write(core::log::Channel::client,
  237. core::log::Level::info,
  238. "ev=probe stage=stall result=installed");
  239. return true;
  240. }
  241. /** Stops the watcher thread. */
  242. bool uninstall() noexcept {
  243. if (!g_installed.load(std::memory_order_acquire)) {
  244. return true;
  245. }
  246. SetEvent(g_stop);
  247. (void)WaitForSingleObject(g_thread, kJoinMs);
  248. CloseHandle(g_thread);
  249. CloseHandle(g_stop);
  250. g_thread = nullptr;
  251. g_stop = nullptr;
  252. g_installed.store(false, std::memory_order_release);
  253. return true;
  254. }
  255. } // namespace sunrise::client::hooks::stall_probe