From 17f3a03aa0b2a3ad2c1dd2a682b2466f3651131c Mon Sep 17 00:00:00 2001 From: Jacobwasbeast Date: Fri, 6 Mar 2026 19:19:33 -0600 Subject: [PATCH] Add crash handler, game debug capture, timestamped logging, and logs/ directory - Add vectored exception handler (CrashHandler) installed from DllMain to reliably catch crashes before game CRT/SEH can override it, with x64 stack walking via RtlVirtualUnwind and re-entrancy protection - Hook OutputDebugStringA to capture game debug output into game_debug.log - Move all log files into a logs/ subdirectory (legacyforge.log, game_debug.log, crash.log) - Add millisecond-precision timestamps to all log entries - Replace all raw printf calls with LogUtil::Log across every source file for consistent timestamped, file-persisted logging --- LegacyForgeRuntime/CMakeLists.txt | 1 + LegacyForgeRuntime/src/CrashHandler.cpp | 231 +++++++++++++++++++ LegacyForgeRuntime/src/CrashHandler.h | 8 + LegacyForgeRuntime/src/CreativeInventory.cpp | 34 +-- LegacyForgeRuntime/src/DotNetHost.cpp | 25 +- LegacyForgeRuntime/src/GameHooks.cpp | 31 ++- LegacyForgeRuntime/src/GameHooks.h | 4 + LegacyForgeRuntime/src/HookManager.cpp | 61 +++-- LegacyForgeRuntime/src/IdRegistry.cpp | 7 +- LegacyForgeRuntime/src/LogUtil.cpp | 66 +++++- LegacyForgeRuntime/src/LogUtil.h | 15 +- LegacyForgeRuntime/src/NativeExports.cpp | 32 +-- LegacyForgeRuntime/src/dllmain.cpp | 16 +- 13 files changed, 437 insertions(+), 94 deletions(-) create mode 100644 LegacyForgeRuntime/src/CrashHandler.cpp create mode 100644 LegacyForgeRuntime/src/CrashHandler.h diff --git a/LegacyForgeRuntime/CMakeLists.txt b/LegacyForgeRuntime/CMakeLists.txt index 9e4dcdd..7d3d8e1 100644 --- a/LegacyForgeRuntime/CMakeLists.txt +++ b/LegacyForgeRuntime/CMakeLists.txt @@ -70,6 +70,7 @@ endif() add_library(LegacyForgeRuntime SHARED src/dllmain.cpp src/LogUtil.cpp + src/CrashHandler.cpp src/PdbParser.cpp src/SymbolResolver.cpp src/HookManager.cpp diff --git a/LegacyForgeRuntime/src/CrashHandler.cpp b/LegacyForgeRuntime/src/CrashHandler.cpp new file mode 100644 index 0000000..4a959f4 --- /dev/null +++ b/LegacyForgeRuntime/src/CrashHandler.cpp @@ -0,0 +1,231 @@ +#include "CrashHandler.h" +#include "LogUtil.h" +#include +#include +#include +#include +#include + +static HMODULE s_runtimeModule = nullptr; +static volatile LONG s_handling = 0; + +static const char* ExceptionCodeToString(DWORD code) +{ + switch (code) + { + case EXCEPTION_ACCESS_VIOLATION: return "EXCEPTION_ACCESS_VIOLATION"; + case EXCEPTION_ARRAY_BOUNDS_EXCEEDED: return "EXCEPTION_ARRAY_BOUNDS_EXCEEDED"; + case EXCEPTION_BREAKPOINT: return "EXCEPTION_BREAKPOINT"; + case EXCEPTION_DATATYPE_MISALIGNMENT: return "EXCEPTION_DATATYPE_MISALIGNMENT"; + case EXCEPTION_FLT_DENORMAL_OPERAND: return "EXCEPTION_FLT_DENORMAL_OPERAND"; + case EXCEPTION_FLT_DIVIDE_BY_ZERO: return "EXCEPTION_FLT_DIVIDE_BY_ZERO"; + case EXCEPTION_FLT_INEXACT_RESULT: return "EXCEPTION_FLT_INEXACT_RESULT"; + case EXCEPTION_FLT_INVALID_OPERATION: return "EXCEPTION_FLT_INVALID_OPERATION"; + case EXCEPTION_FLT_OVERFLOW: return "EXCEPTION_FLT_OVERFLOW"; + case EXCEPTION_FLT_STACK_CHECK: return "EXCEPTION_FLT_STACK_CHECK"; + case EXCEPTION_FLT_UNDERFLOW: return "EXCEPTION_FLT_UNDERFLOW"; + case EXCEPTION_GUARD_PAGE: return "EXCEPTION_GUARD_PAGE"; + case EXCEPTION_ILLEGAL_INSTRUCTION: return "EXCEPTION_ILLEGAL_INSTRUCTION"; + case EXCEPTION_IN_PAGE_ERROR: return "EXCEPTION_IN_PAGE_ERROR"; + case EXCEPTION_INT_DIVIDE_BY_ZERO: return "EXCEPTION_INT_DIVIDE_BY_ZERO"; + case EXCEPTION_INT_OVERFLOW: return "EXCEPTION_INT_OVERFLOW"; + case EXCEPTION_INVALID_DISPOSITION: return "EXCEPTION_INVALID_DISPOSITION"; + case EXCEPTION_NONCONTINUABLE_EXCEPTION: return "EXCEPTION_NONCONTINUABLE_EXCEPTION"; + case EXCEPTION_PRIV_INSTRUCTION: return "EXCEPTION_PRIV_INSTRUCTION"; + case EXCEPTION_SINGLE_STEP: return "EXCEPTION_SINGLE_STEP"; + case EXCEPTION_STACK_OVERFLOW: return "EXCEPTION_STACK_OVERFLOW"; + default: return "UNKNOWN_EXCEPTION"; + } +} + +static bool IsFatalException(DWORD code) +{ + switch (code) + { + case EXCEPTION_ACCESS_VIOLATION: + case EXCEPTION_ARRAY_BOUNDS_EXCEEDED: + case EXCEPTION_FLT_DIVIDE_BY_ZERO: + case EXCEPTION_FLT_INVALID_OPERATION: + case EXCEPTION_FLT_OVERFLOW: + case EXCEPTION_FLT_STACK_CHECK: + case EXCEPTION_FLT_UNDERFLOW: + case EXCEPTION_GUARD_PAGE: + case EXCEPTION_ILLEGAL_INSTRUCTION: + case EXCEPTION_IN_PAGE_ERROR: + case EXCEPTION_INT_DIVIDE_BY_ZERO: + case EXCEPTION_INT_OVERFLOW: + case EXCEPTION_INVALID_DISPOSITION: + case EXCEPTION_NONCONTINUABLE_EXCEPTION: + case EXCEPTION_PRIV_INSTRUCTION: + case EXCEPTION_STACK_OVERFLOW: + return true; + default: + return false; + } +} + +static void GetModuleForAddr(DWORD64 addr, char* nameBuf, size_t nameBufSize, DWORD64* outBase) +{ + *outBase = 0; + nameBuf[0] = '\0'; + + HMODULE hMod = nullptr; + if (GetModuleHandleExA(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT, + reinterpret_cast(addr), &hMod)) + { + GetModuleFileNameA(hMod, nameBuf, (DWORD)nameBufSize); + *outBase = reinterpret_cast(hMod); + } +} + +static void WalkStack(CONTEXT* ctx) +{ + LogUtil::LogCrash("Stack trace (from exception context):"); + + CONTEXT localCtx = *ctx; + int frame = 0; + const int maxFrames = 64; + + while (frame < maxFrames) + { + DWORD64 rip = localCtx.Rip; + if (rip == 0) break; + + char modPath[MAX_PATH] = {0}; + DWORD64 modBase = 0; + GetModuleForAddr(rip, modPath, sizeof(modPath), &modBase); + + const char* modName = "???"; + if (modPath[0]) + { + char* slash = strrchr(modPath, '\\'); + modName = slash ? slash + 1 : modPath; + } + + LogUtil::LogCrash(" [%2d] 0x%016llX %s+0x%llX", frame, rip, modName, rip - modBase); + frame++; + + // Use RtlLookupFunctionEntry + RtlVirtualUnwind for x64 stack walking + DWORD64 imageBase = 0; + PRUNTIME_FUNCTION pFunc = RtlLookupFunctionEntry(rip, &imageBase, nullptr); + if (!pFunc) + break; + + void* handlerData = nullptr; + DWORD64 establisherFrame = 0; + KNONVOLATILE_CONTEXT_POINTERS nvCtx = {}; + RtlVirtualUnwind(UNW_FLAG_NHANDLER, imageBase, rip, pFunc, + &localCtx, &handlerData, &establisherFrame, &nvCtx); + + if (localCtx.Rip == 0) break; + } +} + +static LONG WINAPI VectoredHandler(EXCEPTION_POINTERS* ep) +{ + if (!ep || !ep->ExceptionRecord || !ep->ContextRecord) + return EXCEPTION_CONTINUE_SEARCH; + + DWORD code = ep->ExceptionRecord->ExceptionCode; + + if (!IsFatalException(code)) + return EXCEPTION_CONTINUE_SEARCH; + + // Prevent re-entrancy if the crash handler itself crashes + if (InterlockedCompareExchange(&s_handling, 1, 0) != 0) + return EXCEPTION_CONTINUE_SEARCH; + + EXCEPTION_RECORD* er = ep->ExceptionRecord; + CONTEXT* ctx = ep->ContextRecord; + + SYSTEMTIME st; + GetLocalTime(&st); + char timeBuf[64]; + snprintf(timeBuf, sizeof(timeBuf), "%04d-%02d-%02d %02d:%02d:%02d.%03d", + st.wYear, st.wMonth, st.wDay, + st.wHour, st.wMinute, st.wSecond, st.wMilliseconds); + + LogUtil::LogCrash("========================================"); + LogUtil::LogCrash(" LegacyForge Crash Report"); + LogUtil::LogCrash(" %s", timeBuf); + LogUtil::LogCrash("========================================"); + LogUtil::LogCrash(""); + LogUtil::LogCrash("Exception: %s (0x%08X)", ExceptionCodeToString(code), code); + LogUtil::LogCrash("Address: 0x%016llX", reinterpret_cast(er->ExceptionAddress)); + LogUtil::LogCrash("Thread: %lu", GetCurrentThreadId()); + + if (code == EXCEPTION_ACCESS_VIOLATION && er->NumberParameters >= 2) + { + const char* op = er->ExceptionInformation[0] == 0 ? "read" + : er->ExceptionInformation[0] == 1 ? "write" + : "execute"; + LogUtil::LogCrash("Fault: %s of address 0x%016llX", op, er->ExceptionInformation[1]); + } + + // Module containing the faulting address + { + char modPath[MAX_PATH] = {0}; + DWORD64 modBase = 0; + GetModuleForAddr(reinterpret_cast(er->ExceptionAddress), modPath, sizeof(modPath), &modBase); + if (modPath[0]) + LogUtil::LogCrash("Module: %s (base: 0x%016llX, offset: +0x%llX)", + modPath, modBase, reinterpret_cast(er->ExceptionAddress) - modBase); + } + + LogUtil::LogCrash(""); + LogUtil::LogCrash("Registers:"); + LogUtil::LogCrash(" RAX = 0x%016llX RBX = 0x%016llX", ctx->Rax, ctx->Rbx); + LogUtil::LogCrash(" RCX = 0x%016llX RDX = 0x%016llX", ctx->Rcx, ctx->Rdx); + LogUtil::LogCrash(" RSI = 0x%016llX RDI = 0x%016llX", ctx->Rsi, ctx->Rdi); + LogUtil::LogCrash(" RSP = 0x%016llX RBP = 0x%016llX", ctx->Rsp, ctx->Rbp); + LogUtil::LogCrash(" R8 = 0x%016llX R9 = 0x%016llX", ctx->R8, ctx->R9); + LogUtil::LogCrash(" R10 = 0x%016llX R11 = 0x%016llX", ctx->R10, ctx->R11); + LogUtil::LogCrash(" R12 = 0x%016llX R13 = 0x%016llX", ctx->R12, ctx->R13); + LogUtil::LogCrash(" R14 = 0x%016llX R15 = 0x%016llX", ctx->R14, ctx->R15); + LogUtil::LogCrash(" RIP = 0x%016llX EFLAGS = 0x%08X", ctx->Rip, ctx->EFlags); + + LogUtil::LogCrash(""); + WalkStack(ctx); + + // Loaded modules + LogUtil::LogCrash(""); + LogUtil::LogCrash("Loaded modules:"); + HANDLE hSnap = CreateToolhelp32Snapshot(TH32CS_SNAPMODULE, GetCurrentProcessId()); + if (hSnap != INVALID_HANDLE_VALUE) + { + MODULEENTRY32 me; + me.dwSize = sizeof(me); + if (Module32First(hSnap, &me)) + { + do { + LogUtil::LogCrash(" 0x%016llX - 0x%016llX %s", + reinterpret_cast(me.modBaseAddr), + reinterpret_cast(me.modBaseAddr) + me.modBaseSize, + me.szModule); + } while (Module32Next(hSnap, &me)); + } + CloseHandle(hSnap); + } + + LogUtil::LogCrash(""); + LogUtil::LogCrash("========================================"); + LogUtil::LogCrash(" End of crash report"); + LogUtil::LogCrash("========================================"); + LogUtil::LogCrash(""); + + LogUtil::Log("[LegacyForge] CRASH DETECTED - see logs/crash.log for details"); + + InterlockedExchange(&s_handling, 0); + return EXCEPTION_CONTINUE_SEARCH; +} + +namespace CrashHandler +{ + +void Install(HMODULE runtimeModule) +{ + s_runtimeModule = runtimeModule; + AddVectoredExceptionHandler(1, VectoredHandler); +} + +} // namespace CrashHandler diff --git a/LegacyForgeRuntime/src/CrashHandler.h b/LegacyForgeRuntime/src/CrashHandler.h new file mode 100644 index 0000000..e51068a --- /dev/null +++ b/LegacyForgeRuntime/src/CrashHandler.h @@ -0,0 +1,8 @@ +#pragma once +#include + +namespace CrashHandler +{ + // Installs the vectored exception handler. Safe to call from DllMain. + void Install(HMODULE runtimeModule); +} diff --git a/LegacyForgeRuntime/src/CreativeInventory.cpp b/LegacyForgeRuntime/src/CreativeInventory.cpp index 8d2ec62..a6cbae8 100644 --- a/LegacyForgeRuntime/src/CreativeInventory.cpp +++ b/LegacyForgeRuntime/src/CreativeInventory.cpp @@ -1,6 +1,6 @@ #include "CreativeInventory.h" #include "SymbolResolver.h" -#include +#include "LogUtil.h" #include namespace CreativeInventory @@ -25,7 +25,7 @@ typedef void (__fastcall *VectorPushBackMove_fn)(void* vectorThis, void* sharedP void AddPending(int itemId, int count, int auxValue, int groupIndex) { s_pendingItems.push_back({ itemId, count, auxValue, groupIndex }); - printf("[LegacyForge] Queued creative item: id=%d group=%d\n", itemId, groupIndex); + LogUtil::Log("[LegacyForge] Queued creative item: id=%d group=%d", itemId, groupIndex); } bool ResolveSymbols(SymbolResolver& resolver) @@ -43,17 +43,17 @@ bool ResolveSymbols(SymbolResolver& resolver) "?push_back@?$vector@V?$shared_ptr@VItemInstance@@@std@@V?$allocator@V?$shared_ptr@VItemInstance@@@std@@@2@@std@@" "QEAAX$$QEAV?$shared_ptr@VItemInstance@@@2@@Z"); - if (pCategoryGroups) printf("[LegacyForge] categoryGroups @ %p\n", pCategoryGroups); - else printf("[LegacyForge] MISSING: categoryGroups\n"); + if (pCategoryGroups) LogUtil::Log("[LegacyForge] categoryGroups @ %p", pCategoryGroups); + else LogUtil::Log("[LegacyForge] MISSING: categoryGroups"); - if (pItemInstanceCtor) printf("[LegacyForge] ItemInstance ctor @ %p\n", pItemInstanceCtor); - else printf("[LegacyForge] MISSING: ItemInstance(int,int,int)\n"); + if (pItemInstanceCtor) LogUtil::Log("[LegacyForge] ItemInstance ctor @ %p", pItemInstanceCtor); + else LogUtil::Log("[LegacyForge] MISSING: ItemInstance(int,int,int)"); - if (pSharedPtrCtor) printf("[LegacyForge] shared_ptr ctor @ %p\n", pSharedPtrCtor); - else printf("[LegacyForge] MISSING: shared_ptr(ItemInstance*)\n"); + if (pSharedPtrCtor) LogUtil::Log("[LegacyForge] shared_ptr ctor @ %p", pSharedPtrCtor); + else LogUtil::Log("[LegacyForge] MISSING: shared_ptr(ItemInstance*)"); - if (pVectorPushBack) printf("[LegacyForge] vector::push_back @ %p\n", pVectorPushBack); - else printf("[LegacyForge] MISSING: vector>::push_back\n"); + if (pVectorPushBack) LogUtil::Log("[LegacyForge] vector::push_back @ %p", pVectorPushBack); + else LogUtil::Log("[LegacyForge] MISSING: vector>::push_back"); return pCategoryGroups && pItemInstanceCtor && pSharedPtrCtor && pVectorPushBack; } @@ -62,13 +62,13 @@ void InjectItems() { if (!pCategoryGroups || !pItemInstanceCtor || !pSharedPtrCtor || !pVectorPushBack) { - printf("[LegacyForge] Cannot inject creative items: missing symbols\n"); + LogUtil::Log("[LegacyForge] Cannot inject creative items: missing symbols"); return; } if (s_pendingItems.empty()) { - printf("[LegacyForge] No creative items to inject\n"); + LogUtil::Log("[LegacyForge] No creative items to inject"); return; } @@ -82,8 +82,8 @@ void InjectItems() { if (item.groupIndex < 0 || item.groupIndex >= CREATIVE_GROUP_COUNT) { - printf("[LegacyForge] Skipping creative item id=%d: invalid group %d\n", - item.itemId, item.groupIndex); + LogUtil::Log("[LegacyForge] Skipping creative item id=%d: invalid group %d", + item.itemId, item.groupIndex); continue; } @@ -98,11 +98,11 @@ void InjectItems() char* vec = groups + item.groupIndex * SIZEOF_MSVC_VECTOR; pushFn(vec, spBuf); - printf("[LegacyForge] Injected item id=%d into creative group %d\n", - item.itemId, item.groupIndex); + LogUtil::Log("[LegacyForge] Injected item id=%d into creative group %d", + item.itemId, item.groupIndex); } - printf("[LegacyForge] Injected %zu items into creative inventory\n", s_pendingItems.size()); + LogUtil::Log("[LegacyForge] Injected %zu items into creative inventory", s_pendingItems.size()); s_pendingItems.clear(); } diff --git a/LegacyForgeRuntime/src/DotNetHost.cpp b/LegacyForgeRuntime/src/DotNetHost.cpp index 8a2f141..b802684 100644 --- a/LegacyForgeRuntime/src/DotNetHost.cpp +++ b/LegacyForgeRuntime/src/DotNetHost.cpp @@ -1,19 +1,18 @@ #include "DotNetHost.h" +#include "LogUtil.h" #include #include #include #include -#include +#include #include -// hostfxr function pointers static hostfxr_initialize_for_runtime_config_fn init_fptr = nullptr; static hostfxr_get_runtime_delegate_fn get_delegate_fptr = nullptr; static hostfxr_close_fn close_fptr = nullptr; -// Managed entry points (component_entry_point_fn signature) typedef int (CORECLR_DELEGATE_CALLTYPE *managed_entry_fn)(void* args, int sizeBytes); static managed_entry_fn fn_Initialize = nullptr; @@ -32,14 +31,14 @@ static bool LoadHostfxr() int rc = get_hostfxr_path(buffer, &buffer_size, nullptr); if (rc != 0) { - printf("[LegacyForge] get_hostfxr_path failed: 0x%x\n", rc); + LogUtil::Log("[LegacyForge] get_hostfxr_path failed: 0x%x", rc); return false; } HMODULE lib = LoadLibraryW(buffer); if (!lib) { - printf("[LegacyForge] Failed to load hostfxr\n"); + LogUtil::Log("[LegacyForge] Failed to load hostfxr"); return false; } @@ -59,7 +58,7 @@ static load_assembly_and_get_function_pointer_fn GetDotNetLoadAssembly(const wch int rc = init_fptr(configPath, nullptr, &cxt); if (rc != 0 || cxt == nullptr) { - printf("[LegacyForge] hostfxr_initialize failed: 0x%x\n", rc); + LogUtil::Log("[LegacyForge] hostfxr_initialize failed: 0x%x", rc); if (cxt) close_fptr(cxt); return nullptr; } @@ -68,7 +67,7 @@ static load_assembly_and_get_function_pointer_fn GetDotNetLoadAssembly(const wch rc = get_delegate_fptr(cxt, hdt_load_assembly_and_get_function_pointer, &load_fn); if (rc != 0 || load_fn == nullptr) { - printf("[LegacyForge] hostfxr_get_runtime_delegate failed: 0x%x\n", rc); + LogUtil::Log("[LegacyForge] hostfxr_get_runtime_delegate failed: 0x%x", rc); } close_fptr(cxt); @@ -85,7 +84,7 @@ static bool ResolveManagedMethod( assemblyPath, L"LegacyForge.Core.LegacyForgeCore, LegacyForge.Core", methodName, - nullptr, // delegate_type_name (null = default component_entry_point_fn) + nullptr, nullptr, reinterpret_cast(outFn)); @@ -96,11 +95,10 @@ bool DotNetHost::Initialize() { if (!LoadHostfxr()) { - printf("[LegacyForge] Failed to load hostfxr library\n"); + LogUtil::Log("[LegacyForge] Failed to load hostfxr library"); return false; } - // Paths relative to the runtime DLL (which is in the same dir as LegacyForge.Core.dll) wchar_t modulePath[MAX_PATH]; GetModuleFileNameW(nullptr, modulePath, MAX_PATH); @@ -111,7 +109,6 @@ bool DotNetHost::Initialize() else exeDir = L".\\"; - // Look for LegacyForge files next to the runtime DLL, not the game exe HMODULE hSelf = nullptr; GetModuleHandleExW(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT, @@ -132,7 +129,7 @@ bool DotNetHost::Initialize() auto load_fn = GetDotNetLoadAssembly(configPath.c_str()); if (!load_fn) { - printf("[LegacyForge] Failed to get load_assembly_and_get_function_pointer\n"); + LogUtil::Log("[LegacyForge] Failed to get load_assembly_and_get_function_pointer"); return false; } @@ -147,11 +144,11 @@ bool DotNetHost::Initialize() if (!ok) { - printf("[LegacyForge] Failed to resolve one or more managed entry points\n"); + LogUtil::Log("[LegacyForge] Failed to resolve one or more managed entry points"); return false; } - printf("[LegacyForge] All managed entry points resolved\n"); + LogUtil::Log("[LegacyForge] All managed entry points resolved"); return true; } diff --git a/LegacyForgeRuntime/src/GameHooks.cpp b/LegacyForgeRuntime/src/GameHooks.cpp index 1a47424..03cef1b 100644 --- a/LegacyForgeRuntime/src/GameHooks.cpp +++ b/LegacyForgeRuntime/src/GameHooks.cpp @@ -2,7 +2,9 @@ #include "DotNetHost.h" #include "CreativeInventory.h" #include "MainMenuOverlay.h" +#include "LogUtil.h" #include +#include namespace GameHooks { @@ -13,15 +15,16 @@ namespace GameHooks CreativeStaticCtor_fn Original_CreativeStaticCtor = nullptr; MainMenuCustomDraw_fn Original_MainMenuCustomDraw = nullptr; Present_fn Original_Present = nullptr; + OutputDebugStringA_fn Original_OutputDebugStringA = nullptr; void Hooked_RunStaticCtors() { - printf("[LegacyForge] Hook: RunStaticCtors -- calling PreInit\n"); + LogUtil::Log("[LegacyForge] Hook: RunStaticCtors -- calling PreInit"); DotNetHost::CallPreInit(); Original_RunStaticCtors(); - printf("[LegacyForge] Hook: RunStaticCtors complete -- calling Init\n"); + LogUtil::Log("[LegacyForge] Hook: RunStaticCtors complete -- calling Init"); DotNetHost::CallInit(); } @@ -39,13 +42,13 @@ namespace GameHooks { Original_MinecraftInit(thisPtr); - printf("[LegacyForge] Hook: Minecraft::init complete -- calling PostInit\n"); + LogUtil::Log("[LegacyForge] Hook: Minecraft::init complete -- calling PostInit"); DotNetHost::CallPostInit(); } void __fastcall Hooked_ExitGame(void* thisPtr) { - printf("[LegacyForge] Hook: ExitGame -- calling Shutdown\n"); + LogUtil::Log("[LegacyForge] Hook: ExitGame -- calling Shutdown"); DotNetHost::CallShutdown(); Original_ExitGame(thisPtr); @@ -53,10 +56,10 @@ namespace GameHooks void Hooked_CreativeStaticCtor() { - printf("[LegacyForge] Hook: CreativeStaticCtor -- building vanilla creative lists\n"); + LogUtil::Log("[LegacyForge] Hook: CreativeStaticCtor -- building vanilla creative lists"); Original_CreativeStaticCtor(); - printf("[LegacyForge] Hook: CreativeStaticCtor -- injecting modded items\n"); + LogUtil::Log("[LegacyForge] Hook: CreativeStaticCtor -- injecting modded items"); CreativeInventory::InjectItems(); } @@ -71,4 +74,20 @@ namespace GameHooks MainMenuOverlay::RenderBranding(); Original_Present(thisPtr); } + + void WINAPI Hooked_OutputDebugStringA(const char* lpOutputString) + { + if (lpOutputString && lpOutputString[0] != '\0') + { + // Strip trailing newlines/carriage returns for clean log output + size_t len = strlen(lpOutputString); + while (len > 0 && (lpOutputString[len - 1] == '\n' || lpOutputString[len - 1] == '\r')) + len--; + + if (len > 0) + LogUtil::LogGameOutput(lpOutputString, len); + } + + Original_OutputDebugStringA(lpOutputString); + } } diff --git a/LegacyForgeRuntime/src/GameHooks.h b/LegacyForgeRuntime/src/GameHooks.h index e38808f..a5f482f 100644 --- a/LegacyForgeRuntime/src/GameHooks.h +++ b/LegacyForgeRuntime/src/GameHooks.h @@ -1,4 +1,5 @@ #pragma once +#include #include /// Function pointer typedefs matching the game's actual function signatures. @@ -11,6 +12,7 @@ typedef void (__fastcall *ExitGame_fn)(void* thisPtr); typedef void (*CreativeStaticCtor_fn)(); typedef void (__fastcall *MainMenuCustomDraw_fn)(void* thisPtr, void* region); typedef void (__fastcall *Present_fn)(void* thisPtr); +typedef void (WINAPI *OutputDebugStringA_fn)(const char* lpOutputString); namespace GameHooks { @@ -21,6 +23,7 @@ namespace GameHooks extern CreativeStaticCtor_fn Original_CreativeStaticCtor; extern MainMenuCustomDraw_fn Original_MainMenuCustomDraw; extern Present_fn Original_Present; + extern OutputDebugStringA_fn Original_OutputDebugStringA; void Hooked_RunStaticCtors(); void __fastcall Hooked_MinecraftTick(void* thisPtr, bool bFirst, bool bUpdateTextures); @@ -29,4 +32,5 @@ namespace GameHooks void Hooked_CreativeStaticCtor(); void __fastcall Hooked_MainMenuCustomDraw(void* thisPtr, void* region); void __fastcall Hooked_Present(void* thisPtr); + void WINAPI Hooked_OutputDebugStringA(const char* lpOutputString); } diff --git a/LegacyForgeRuntime/src/HookManager.cpp b/LegacyForgeRuntime/src/HookManager.cpp index 8d0a795..147f6e4 100644 --- a/LegacyForgeRuntime/src/HookManager.cpp +++ b/LegacyForgeRuntime/src/HookManager.cpp @@ -3,72 +3,67 @@ #include "SymbolResolver.h" #include "CreativeInventory.h" #include "MainMenuOverlay.h" +#include "LogUtil.h" #include -#include bool HookManager::Install(const SymbolResolver& symbols) { if (MH_Initialize() != MH_OK) { - printf("[LegacyForge] MH_Initialize failed\n"); + LogUtil::Log("[LegacyForge] MH_Initialize failed"); return false; } - // Hook MinecraftWorld_RunStaticCtors if (symbols.pRunStaticCtors) { if (MH_CreateHook(symbols.pRunStaticCtors, reinterpret_cast(&GameHooks::Hooked_RunStaticCtors), reinterpret_cast(&GameHooks::Original_RunStaticCtors)) != MH_OK) { - printf("[LegacyForge] Failed to hook RunStaticCtors\n"); + LogUtil::Log("[LegacyForge] Failed to hook RunStaticCtors"); return false; } - printf("[LegacyForge] Hooked RunStaticCtors\n"); + LogUtil::Log("[LegacyForge] Hooked RunStaticCtors"); } - // Hook Minecraft::tick if (symbols.pMinecraftTick) { if (MH_CreateHook(symbols.pMinecraftTick, reinterpret_cast(&GameHooks::Hooked_MinecraftTick), reinterpret_cast(&GameHooks::Original_MinecraftTick)) != MH_OK) { - printf("[LegacyForge] Failed to hook Minecraft::tick\n"); + LogUtil::Log("[LegacyForge] Failed to hook Minecraft::tick"); return false; } - printf("[LegacyForge] Hooked Minecraft::tick\n"); + LogUtil::Log("[LegacyForge] Hooked Minecraft::tick"); } - // Hook Minecraft::init if (symbols.pMinecraftInit) { if (MH_CreateHook(symbols.pMinecraftInit, reinterpret_cast(&GameHooks::Hooked_MinecraftInit), reinterpret_cast(&GameHooks::Original_MinecraftInit)) != MH_OK) { - printf("[LegacyForge] Failed to hook Minecraft::init\n"); + LogUtil::Log("[LegacyForge] Failed to hook Minecraft::init"); return false; } - printf("[LegacyForge] Hooked Minecraft::init\n"); + LogUtil::Log("[LegacyForge] Hooked Minecraft::init"); } - // Hook CConsoleMinecraftApp::ExitGame if (symbols.pExitGame) { if (MH_CreateHook(symbols.pExitGame, reinterpret_cast(&GameHooks::Hooked_ExitGame), reinterpret_cast(&GameHooks::Original_ExitGame)) != MH_OK) { - printf("[LegacyForge] Warning: Failed to hook ExitGame (shutdown hook unavailable)\n"); + LogUtil::Log("[LegacyForge] Warning: Failed to hook ExitGame (shutdown hook unavailable)"); } else { - printf("[LegacyForge] Hooked ExitGame\n"); + LogUtil::Log("[LegacyForge] Hooked ExitGame"); } } - // Hook IUIScene_CreativeMenu::staticCtor if (symbols.pCreativeStaticCtor) { CreativeInventory::ResolveSymbols(const_cast(symbols)); @@ -77,30 +72,28 @@ bool HookManager::Install(const SymbolResolver& symbols) reinterpret_cast(&GameHooks::Hooked_CreativeStaticCtor), reinterpret_cast(&GameHooks::Original_CreativeStaticCtor)) != MH_OK) { - printf("[LegacyForge] Warning: Failed to hook CreativeStaticCtor\n"); + LogUtil::Log("[LegacyForge] Warning: Failed to hook CreativeStaticCtor"); } else { - printf("[LegacyForge] Hooked CreativeStaticCtor\n"); + LogUtil::Log("[LegacyForge] Hooked CreativeStaticCtor"); } } - // Hook UIScene_MainMenu::customDraw (sets main-menu detection flag) if (symbols.pMainMenuCustomDraw) { if (MH_CreateHook(symbols.pMainMenuCustomDraw, reinterpret_cast(&GameHooks::Hooked_MainMenuCustomDraw), reinterpret_cast(&GameHooks::Original_MainMenuCustomDraw)) != MH_OK) { - printf("[LegacyForge] Warning: Failed to hook MainMenuCustomDraw\n"); + LogUtil::Log("[LegacyForge] Warning: Failed to hook MainMenuCustomDraw"); } else { - printf("[LegacyForge] Hooked MainMenuCustomDraw\n"); + LogUtil::Log("[LegacyForge] Hooked MainMenuCustomDraw"); } } - // Hook C4JRender::Present (draws branding overlay just before frame present) if (symbols.pPresent) { MainMenuOverlay::ResolveSymbols(const_cast(symbols)); @@ -109,21 +102,39 @@ bool HookManager::Install(const SymbolResolver& symbols) reinterpret_cast(&GameHooks::Hooked_Present), reinterpret_cast(&GameHooks::Original_Present)) != MH_OK) { - printf("[LegacyForge] Warning: Failed to hook C4JRender::Present\n"); + LogUtil::Log("[LegacyForge] Warning: Failed to hook C4JRender::Present"); } else { - printf("[LegacyForge] Hooked C4JRender::Present\n"); + LogUtil::Log("[LegacyForge] Hooked C4JRender::Present"); + } + } + + { + void* pOutputDbgStr = reinterpret_cast( + GetProcAddress(GetModuleHandleA("kernel32.dll"), "OutputDebugStringA")); + if (pOutputDbgStr) + { + if (MH_CreateHook(pOutputDbgStr, + reinterpret_cast(&GameHooks::Hooked_OutputDebugStringA), + reinterpret_cast(&GameHooks::Original_OutputDebugStringA)) != MH_OK) + { + LogUtil::Log("[LegacyForge] Warning: Failed to hook OutputDebugStringA"); + } + else + { + LogUtil::Log("[LegacyForge] Hooked OutputDebugStringA (game log capture)"); + } } } if (MH_EnableHook(MH_ALL_HOOKS) != MH_OK) { - printf("[LegacyForge] MH_EnableHook(MH_ALL_HOOKS) failed\n"); + LogUtil::Log("[LegacyForge] MH_EnableHook(MH_ALL_HOOKS) failed"); return false; } - printf("[LegacyForge] All hooks installed and enabled\n"); + LogUtil::Log("[LegacyForge] All hooks installed and enabled"); return true; } diff --git a/LegacyForgeRuntime/src/IdRegistry.cpp b/LegacyForgeRuntime/src/IdRegistry.cpp index 0213589..13c8e9b 100644 --- a/LegacyForgeRuntime/src/IdRegistry.cpp +++ b/LegacyForgeRuntime/src/IdRegistry.cpp @@ -1,5 +1,5 @@ #include "IdRegistry.h" -#include +#include "LogUtil.h" IdRegistry& IdRegistry::Instance() { @@ -34,14 +34,13 @@ int IdRegistry::Register(Type type, const std::string& namespacedId) if (reg.nextFreeId > maxId) { - printf("[LegacyForge] IdRegistry: No free IDs for type %d (max %d)\n", - static_cast(type), maxId); + LogUtil::Log("[LegacyForge] IdRegistry: No free IDs for type %d (max %d)", + static_cast(type), maxId); return -1; } int id = reg.nextFreeId++; - // Skip IDs that are already taken by vanilla entries while (reg.numToString.count(id) && id <= maxId) id = reg.nextFreeId++; diff --git a/LegacyForgeRuntime/src/LogUtil.cpp b/LegacyForgeRuntime/src/LogUtil.cpp index 1ac9de1..7350aff 100644 --- a/LegacyForgeRuntime/src/LogUtil.cpp +++ b/LegacyForgeRuntime/src/LogUtil.cpp @@ -1,21 +1,47 @@ #include "LogUtil.h" +#include #include #include +#include #include +static std::string s_logsDir; static std::string s_logPath; +static std::string s_gameLogPath; +static std::string s_crashLogPath; + +static void GetTimestamp(char* buf, size_t bufSize) +{ + SYSTEMTIME st; + GetLocalTime(&st); + snprintf(buf, bufSize, "%04d-%02d-%02d %02d:%02d:%02d.%03d", + st.wYear, st.wMonth, st.wDay, + st.wHour, st.wMinute, st.wSecond, st.wMilliseconds); +} namespace LogUtil { void SetBaseDir(const char* baseDir) { - s_logPath = std::string(baseDir) + "legacyforge.log"; + s_logsDir = std::string(baseDir) + "logs\\"; + CreateDirectoryA(s_logsDir.c_str(), nullptr); + s_logPath = s_logsDir + "legacyforge.log"; + s_gameLogPath = s_logsDir + "game_debug.log"; + s_crashLogPath = s_logsDir + "crash.log"; +} + +const char* GetLogsDir() +{ + return s_logsDir.c_str(); } void Log(const char* fmt, ...) { - // Also print to stdout for console visibility + char ts[32]; + GetTimestamp(ts, sizeof(ts)); + + printf("[%s] ", ts); va_list args; va_start(args, fmt); vprintf(fmt, args); @@ -28,6 +54,7 @@ void Log(const char* fmt, ...) fopen_s(&f, s_logPath.c_str(), "a"); if (f) { + fprintf(f, "[%s] ", ts); va_list args2; va_start(args2, fmt); vfprintf(f, fmt, args2); @@ -37,4 +64,39 @@ void Log(const char* fmt, ...) } } +void LogGameOutput(const char* str, size_t len) +{ + if (s_gameLogPath.empty() || !str || len == 0) return; + + char ts[32]; + GetTimestamp(ts, sizeof(ts)); + + FILE* f = nullptr; + fopen_s(&f, s_gameLogPath.c_str(), "a"); + if (f) + { + fprintf(f, "[%s] ", ts); + fwrite(str, 1, len, f); + fprintf(f, "\n"); + fclose(f); + } +} + +void LogCrash(const char* fmt, ...) +{ + if (s_crashLogPath.empty()) return; + + FILE* f = nullptr; + fopen_s(&f, s_crashLogPath.c_str(), "a"); + if (f) + { + va_list args; + va_start(args, fmt); + vfprintf(f, fmt, args); + va_end(args); + fprintf(f, "\n"); + fclose(f); + } +} + } // namespace LogUtil diff --git a/LegacyForgeRuntime/src/LogUtil.h b/LegacyForgeRuntime/src/LogUtil.h index 5d915c3..12b18d7 100644 --- a/LegacyForgeRuntime/src/LogUtil.h +++ b/LegacyForgeRuntime/src/LogUtil.h @@ -1,10 +1,21 @@ #pragma once +#include namespace LogUtil { - // Must be called once at startup with the runtime DLL's directory (with trailing backslash) + // Must be called once at startup with the runtime DLL's directory (with trailing backslash). + // Creates a logs/ subdirectory and sets up all log file paths. void SetBaseDir(const char* baseDir); - // Appends a line to legacyforge.log in the base directory + // Returns the logs directory path (with trailing backslash) + const char* GetLogsDir(); + + // Appends a timestamped line to legacyforge.log and prints to stdout void Log(const char* fmt, ...); + + // Writes game debug output to game_debug.log with a timestamp + void LogGameOutput(const char* str, size_t len); + + // Writes crash information to crash.log (no timestamp prefix -- caller manages formatting) + void LogCrash(const char* fmt, ...); } diff --git a/LegacyForgeRuntime/src/NativeExports.cpp b/LegacyForgeRuntime/src/NativeExports.cpp index b4a65e6..0cd8ddf 100644 --- a/LegacyForgeRuntime/src/NativeExports.cpp +++ b/LegacyForgeRuntime/src/NativeExports.cpp @@ -2,7 +2,6 @@ #include "IdRegistry.h" #include "CreativeInventory.h" #include "LogUtil.h" -#include #include extern "C" @@ -23,14 +22,12 @@ int native_register_block( int id = IdRegistry::Instance().Register(IdRegistry::Type::Block, namespacedId); if (id < 0) { - printf("[LegacyForge] Failed to allocate block ID for '%s'\n", namespacedId); + LogUtil::Log("[LegacyForge] Failed to allocate block ID for '%s'", namespacedId); return -1; } - // TODO: Once we have access to game headers, create a GenericTile instance - // and insert it into Tile::tiles[id]. For now we just allocate the ID. - printf("[LegacyForge] Registered block '%s' -> ID %d (hardness=%.1f, resistance=%.1f)\n", - namespacedId, id, hardness, resistance); + LogUtil::Log("[LegacyForge] Registered block '%s' -> ID %d (hardness=%.1f, resistance=%.1f)", + namespacedId, id, hardness, resistance); return id; } @@ -45,13 +42,12 @@ int native_register_item( int id = IdRegistry::Instance().Register(IdRegistry::Type::Item, namespacedId); if (id < 0) { - printf("[LegacyForge] Failed to allocate item ID for '%s'\n", namespacedId); + LogUtil::Log("[LegacyForge] Failed to allocate item ID for '%s'", namespacedId); return -1; } - // TODO: Create GenericItem and insert into Item::items[256 + id] - printf("[LegacyForge] Registered item '%s' -> ID %d (stack=%d, durability=%d)\n", - namespacedId, id, maxStackSize, maxDamage); + LogUtil::Log("[LegacyForge] Registered item '%s' -> ID %d (stack=%d, durability=%d)", + namespacedId, id, maxStackSize, maxDamage); return id; } @@ -67,13 +63,12 @@ int native_register_entity( int id = IdRegistry::Instance().Register(IdRegistry::Type::Entity, namespacedId); if (id < 0) { - printf("[LegacyForge] Failed to allocate entity ID for '%s'\n", namespacedId); + LogUtil::Log("[LegacyForge] Failed to allocate entity ID for '%s'", namespacedId); return -1; } - // TODO: Register with EntityIO via resolved PDB symbols - printf("[LegacyForge] Registered entity '%s' -> ID %d (%.1fx%.1f)\n", - namespacedId, id, width, height); + LogUtil::Log("[LegacyForge] Registered entity '%s' -> ID %d (%.1fx%.1f)", + namespacedId, id, width, height); return id; } @@ -84,8 +79,7 @@ void native_add_shaped_recipe( const char* pattern, const char* ingredientIds) { - // TODO: Parse pattern and ingredients, call game's recipe registration - printf("[LegacyForge] Added shaped recipe: %dx %s\n", resultCount, resultId); + LogUtil::Log("[LegacyForge] Added shaped recipe: %dx %s", resultCount, resultId); } void native_add_furnace_recipe( @@ -93,8 +87,7 @@ void native_add_furnace_recipe( const char* outputId, float xp) { - // TODO: Call game's FurnaceRecipes::addRecipe via resolved symbols - printf("[LegacyForge] Added furnace recipe: %s -> %s (%.1f xp)\n", inputId, outputId, xp); + LogUtil::Log("[LegacyForge] Added furnace recipe: %s -> %s (%.1f xp)", inputId, outputId, xp); } void native_log(const char* message, int level) @@ -123,8 +116,7 @@ int native_get_entity_id(const char* namespacedId) void native_subscribe_event(const char* eventName, void* managedFnPtr) { - // TODO: Store managed callback pointers and invoke from game hooks - printf("[LegacyForge] Event subscription: %s\n", eventName ? eventName : "(null)"); + LogUtil::Log("[LegacyForge] Event subscription: %s", eventName ? eventName : "(null)"); } void native_add_to_creative(int numericId, int count, int auxValue, int groupIndex) diff --git a/LegacyForgeRuntime/src/dllmain.cpp b/LegacyForgeRuntime/src/dllmain.cpp index 3f6e8a5..5181dd8 100644 --- a/LegacyForgeRuntime/src/dllmain.cpp +++ b/LegacyForgeRuntime/src/dllmain.cpp @@ -2,6 +2,7 @@ #include #include #include "LogUtil.h" +#include "CrashHandler.h" #include "SymbolResolver.h" #include "HookManager.h" #include "DotNetHost.h" @@ -22,10 +23,9 @@ static std::string GetDllDirectory(HMODULE hModule) DWORD WINAPI InitThread(LPVOID lpParam) { - std::string baseDir = GetDllDirectory(g_hModule); - LogUtil::SetBaseDir(baseDir.c_str()); - LogUtil::Log("[LegacyForge] InitThread started (module=%p)", g_hModule); + + std::string baseDir = GetDllDirectory(g_hModule); LogUtil::Log("[LegacyForge] Runtime DLL directory: %s", baseDir.c_str()); char cwd[MAX_PATH] = {0}; @@ -59,7 +59,6 @@ DWORD WINAPI InitThread(LPVOID lpParam) } LogUtil::Log("[LegacyForge] Hooks installed"); - // All symbol resolution is complete; release the PDB memory map symbols.Cleanup(); if (!DotNetHost::Initialize()) @@ -87,6 +86,15 @@ BOOL APIENTRY DllMain(HMODULE hModule, DWORD ul_reason_for_call, LPVOID lpReserv case DLL_PROCESS_ATTACH: g_hModule = hModule; DisableThreadLibraryCalls(hModule); + + // Set up logging and crash handler BEFORE anything else. + // These must work immediately so we catch crashes during init. + { + std::string baseDir = GetDllDirectory(hModule); + LogUtil::SetBaseDir(baseDir.c_str()); + CrashHandler::Install(hModule); + } + CreateThread(nullptr, 0, InitThread, nullptr, 0, nullptr); break;