From 7dfef9c9c8ff0b679e26c674f2e5146996916cd1 Mon Sep 17 00:00:00 2001 From: Kawe Mazidjatari <48657826+Mauler125@users.noreply.github.com> Date: Tue, 27 Dec 2022 02:28:43 +0100 Subject: [PATCH] CCrashHandler and logging improvements * CCrashHandler now calls the crashmsg executable to display the error to the user. * Logs are now placed into directories named to the current time to avoid overwriting them or having 2 instances of the game writing to the same logs. --- r5dev/core/logdef.cpp | 19 ++-- r5dev/core/logdef.h | 2 + r5dev/public/utility/crashhandler.cpp | 123 ++++++++++++++++++-------- r5dev/public/utility/crashhandler.h | 28 +++++- r5dev/public/utility/utility.cpp | 21 +++++ r5dev/public/utility/utility.h | 2 + 6 files changed, 145 insertions(+), 50 deletions(-) diff --git a/r5dev/core/logdef.cpp b/r5dev/core/logdef.cpp index 4f651faf..6ed8ecd7 100644 --- a/r5dev/core/logdef.cpp +++ b/r5dev/core/logdef.cpp @@ -14,6 +14,7 @@ void SpdLog_Init(void) return; } + g_svLogSessionDirectory = fmt::format("platform\\logs\\{:s}\\", CreateTimedFileName()); /************************ * IMGUI LOGGER SETUP * ************************/ @@ -45,17 +46,17 @@ void SpdLog_Init(void) * ROTATE LOGGER SETUP * ************************/ { - spdlog::rotating_logger_mt("sqvm_warn" , "platform\\logs\\sqvm_warn.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("sqvm_info" , "platform\\logs\\sqvm_info.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("sdk_info" , "platform\\logs\\sdk_info.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("sdk_warn" , "platform\\logs\\sdk_warn.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("sdk_error" , "platform\\logs\\sdk_error.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("qhull_info", "platform\\logs\\qhull_info.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); - spdlog::rotating_logger_mt("net_trace" , "platform\\logs\\net_trace.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("sqvm_warn" , fmt::format("{:s}sqvm_warn.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("sqvm_info" , fmt::format("{:s}sqvm_info.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("sdk_info" , fmt::format("{:s}sdk_info.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("sdk_warn" , fmt::format("{:s}sdk_warn.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("sdk_error" , fmt::format("{:s}sdk_error.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("qhull_info", fmt::format("{:s}qhull_info.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("net_trace" , fmt::format("{:s}net_trace.log" , g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); #ifndef DEDICATED - spdlog::rotating_logger_mt("net_con" , "platform\\logs\\net_console.log", SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("net_con" , fmt::format("{:s}net_console.log", g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); #endif // !DEDICATED - spdlog::rotating_logger_mt("fs_warn" , "platform\\logs\\fs_warn.log" , SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); + spdlog::rotating_logger_mt("fs_warn" , fmt::format("{:s}fs_warn.log" ,g_svLogSessionDirectory), SPDLOG_MAX_SIZE, SPDLOG_NUM_FILE)->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v"); } spdlog::set_level(spdlog::level::trace); diff --git a/r5dev/core/logdef.h b/r5dev/core/logdef.h index 4020e847..7a40ba61 100644 --- a/r5dev/core/logdef.h +++ b/r5dev/core/logdef.h @@ -6,6 +6,8 @@ constexpr int SPDLOG_NUM_FILE = 0; // Sets number of files to rotate to. inline bool g_bSpdLog_UseAnsiClr = false; inline bool g_bSpdLog_PostInit = false; +inline string g_svLogSessionDirectory; + //------------------------------------------------------------------------- // IMGUI CONSOLE SINK | inline std::ostringstream g_spd_sys_w_oss; diff --git a/r5dev/public/utility/crashhandler.cpp b/r5dev/public/utility/crashhandler.cpp index 28ea1581..543de433 100644 --- a/r5dev/public/utility/crashhandler.cpp +++ b/r5dev/public/utility/crashhandler.cpp @@ -4,18 +4,10 @@ // //=============================================================================// #include "core/stdafx.h" +#include "core/logdef.h" +#include "tier0/cpu.h" #include "public/utility/binstream.h" - -#ifndef _DEBUG - -#include "crashhandler.h" -#include "engine/cmodel_bsp.h" -//#include "materialsystem/cmaterialglue.h" -//#include "materialsystem/cmaterialsystem.h" -#include "bsplib/bsplib.h" -#include - -CCrashHandler* g_CrashHandler = new CCrashHandler(); +#include "public/utility/crashhandler.h" //----------------------------------------------------------------------------- // Purpose: formats the crasher (module, address and exception) @@ -153,6 +145,7 @@ void CCrashHandler::FormatExceptionAddress(LPCSTR pExceptionAddress) if (!GetModuleHandleExA(GET_MODULE_HANDLE_EX_FLAG_FROM_ADDRESS | GET_MODULE_HANDLE_EX_FLAG_UNCHANGED_REFCOUNT, pExceptionAddress, &hCrashedModule)) { m_svBuffer.append(fmt::format("\t!!!unknown-module!!!: 0x{:016X}\n", reinterpret_cast(pExceptionAddress))); + m_nCrashMsgFlags = 0; // Display the "unknown DLL or EXE" message. return; } @@ -162,12 +155,19 @@ void CCrashHandler::FormatExceptionAddress(LPCSTR pExceptionAddress) if (GetModuleFileNameExA(GetCurrentProcess(), hCrashedModule, szCrashedModuleFullName, sizeof(szCrashedModuleFullName)) - 1 > 0x1FE) { m_svBuffer.append(fmt::format("\tmodule@{:016X}: 0x{:016X}\n", (void*)hCrashedModule, reinterpret_cast(pModuleBase))); + m_nCrashMsgFlags = 0; // Display the "Apex crashed" message without additional information regarding the module. return; } // TODO: REMOVE EXT. const char* szCrashedModuleName = strrchr(szCrashedModuleFullName, '\\') + 1; - m_svBuffer.append(fmt::format("\t{:s}: 0x{:016X}\n", szCrashedModuleName, reinterpret_cast(pModuleBase))); + m_svBuffer.append(fmt::format("\t{:15s}: 0x{:016X}\n", szCrashedModuleName, reinterpret_cast(pModuleBase))); + m_nCrashMsgFlags = 1; // Display the "Apex crashed in " message. + + if (m_svCrashMsgInfo.empty()) // Only set it once to the crashing module. + { + m_svCrashMsgInfo = szCrashedModuleName; + } } //----------------------------------------------------------------------------- @@ -288,9 +288,9 @@ void CCrashHandler::FormatFPU(const char* pszRegister, M128A* pxContent) //----------------------------------------------------------------------------- // Purpose: returns the current exception code as string //----------------------------------------------------------------------------- -const char* CCrashHandler::ExceptionToString() const +const char* CCrashHandler::ExceptionToString(DWORD nExceptionCode) const { - switch (m_pExceptionPointers->ExceptionRecord->ExceptionCode) + switch (nExceptionCode) { case EXCEPTION_GUARD_PAGE: { return "\tEXCEPTION_GUARD_PAGE" ": 0x{:08X}\n"; }; case EXCEPTION_BREAKPOINT: { return "\tEXCEPTION_BREAKPOINT" ": 0x{:08X}\n"; }; @@ -318,6 +318,14 @@ const char* CCrashHandler::ExceptionToString() const } } +//----------------------------------------------------------------------------- +// Purpose: returns the current exception code as string +//----------------------------------------------------------------------------- +const char* CCrashHandler::ExceptionToString() const +{ + return ExceptionToString(m_pExceptionPointers->ExceptionRecord->ExceptionCode); +} + //----------------------------------------------------------------------------- // Purpose: tests if memory page is accessible //----------------------------------------------------------------------------- @@ -352,13 +360,50 @@ void CCrashHandler::GetCallStack() //----------------------------------------------------------------------------- void CCrashHandler::WriteFile() { - std::time_t time = std::time(nullptr); - stringstream ss; ss << "platform\\logs\\" << "apex_crash_" << std::put_time(std::localtime(&time), "%Y-%m-%d %H-%M-%S.txt"); + string svLogDirectory = fmt::format("{:s}{:s}", g_svLogSessionDirectory, "apex_crash.txt"); + CIOStream ioLogFile(svLogDirectory, CIOStream::Mode_t::WRITE); - CIOStream ioLogFile = CIOStream(ss.str(), CIOStream::Mode_t::WRITE); ioLogFile.WriteString(m_svBuffer); } +//----------------------------------------------------------------------------- +// Purpose: creates the crashmsg process displaying the error to the user +// the process has to be separate as the current process is getting killed +//----------------------------------------------------------------------------- +void CCrashHandler::CreateMessageProcess() +{ + if (m_bCrashMsgCreated) + { + return; // CrashMsg already displayed. + } + m_bCrashMsgCreated = true; + + PEXCEPTION_RECORD pExceptionRecord = m_pExceptionPointers->ExceptionRecord; + PCONTEXT pContextRecord = m_pExceptionPointers->ContextRecord; + + if (pExceptionRecord->ExceptionCode == 0xC0000005 && + pExceptionRecord->ExceptionInformation[0] == 8 && + pExceptionRecord->ExceptionInformation[1] != pContextRecord->Rip) + { + m_svCrashMsgInfo = "bin\\crashmsg.exe overclock"; + } + else + { + m_svCrashMsgInfo = fmt::format("bin\\crashmsg.exe crash {:d} \"{:s}\"", m_nCrashMsgFlags, m_svCrashMsgInfo); + } + + PROCESS_INFORMATION processInfo; + STARTUPINFOA startupInfo = { 0 }; + + startupInfo.cb = sizeof(STARTUPINFOA); + + if (CreateProcessA(NULL, (LPSTR)m_svCrashMsgInfo.c_str(), NULL, NULL, TRUE, CREATE_NO_WINDOW, NULL, NULL, &startupInfo, &processInfo)) + { + CloseHandle(processInfo.hProcess); + CloseHandle(processInfo.hThread); + } +} + //----------------------------------------------------------------------------- // Purpose: //----------------------------------------------------------------------------- @@ -366,14 +411,25 @@ long __stdcall ExceptionFilter(EXCEPTION_POINTERS* exceptionInfo) { g_CrashHandler->Lock(); + g_CrashHandler->SetExceptionPointers(exceptionInfo); + if (g_CrashHandler->ExceptionToString() == g_CrashHandler->ExceptionToString(-1)) + { + g_CrashHandler->Unlock(); + return EXCEPTION_CONTINUE_SEARCH; + } + + if (IsDebuggerPresent()) + { + g_CrashHandler->Unlock(); + return EXCEPTION_CONTINUE_SEARCH; + } + // Kill on recursive call. - static bool bLogged = false; - if (bLogged) + if (g_CrashHandler->GetState()) ExitProcess(1u); - bLogged = true; + g_CrashHandler->SetState(true); g_CrashHandler->GetCallStack(); - g_CrashHandler->SetExceptionPointers(exceptionInfo); g_CrashHandler->FormatCrash(); g_CrashHandler->FormatCallstack(); @@ -382,24 +438,10 @@ long __stdcall ExceptionFilter(EXCEPTION_POINTERS* exceptionInfo) g_CrashHandler->FormatBuildInfo(); g_CrashHandler->WriteFile(); + g_CrashHandler->CreateMessageProcess(); + g_CrashHandler->Unlock(); - -//#ifndef _DEBUG -// // THIS WONT WORK ON DEBUG!!! -// // THIS IS DUE TO A JMP TABLE CREATED BY MSVC!! -// static auto find_IMI_ref = CMemory(IsMaterialInternal).FindAllCallReferences(reinterpret_cast(BuildPropStaticFrustumCullMap), 1000); -// if (!find_IMI_ref.empty()) -// { -// const void* imiRetAddr = find_IMI_ref.at(0).Offset(0x5).RCast(); -// for (WORD i = 0; i < 7; i++) -// { -// if (imiRetAddr == pStackTrace[i]) -// return EXCEPTION_CONTINUE_SEARCH; -// } -// } -//#endif // _DEBUG - return EXCEPTION_EXECUTE_HANDLER; } @@ -408,8 +450,11 @@ long __stdcall ExceptionFilter(EXCEPTION_POINTERS* exceptionInfo) //----------------------------------------------------------------------------- CCrashHandler::CCrashHandler() : m_ppStackTrace() + , m_pExceptionPointers(nullptr) , m_nCapturedFrames(0) - + , m_nCrashMsgFlags(0) + , m_bCallState(false) + , m_bCrashMsgCreated(false) { m_hExceptionHandler = AddVectoredExceptionHandler(TRUE, ExceptionFilter); } @@ -422,4 +467,4 @@ CCrashHandler::~CCrashHandler() RemoveVectoredExceptionHandler(m_hExceptionHandler); } -#endif // _DEBUG \ No newline at end of file +CCrashHandler* g_CrashHandler = new CCrashHandler(); \ No newline at end of file diff --git a/r5dev/public/utility/crashhandler.h b/r5dev/public/utility/crashhandler.h index 1c8e6899..e3fa82b4 100644 --- a/r5dev/public/utility/crashhandler.h +++ b/r5dev/public/utility/crashhandler.h @@ -10,24 +10,40 @@ public: CCrashHandler(); ~CCrashHandler(); + //------------------------------------------------------------------------- + // Inlines: + //------------------------------------------------------------------------- void Lock() const { m_Mutex.lock(); }; void Unlock() const { m_Mutex.unlock(); }; + bool GetState() const { return m_bCallState; }; + void SetState(bool bState) { m_bCallState = bState; }; + //------------------------------------------------------------------------- + // Formatters: + //------------------------------------------------------------------------- void FormatCrash(); void FormatCallstack(); void FormatRegisters(); void FormatSystemInfo(); void FormatBuildInfo(); + //------------------------------------------------------------------------- + // Utility: + //------------------------------------------------------------------------- const char* ExceptionToString() const; + const char* ExceptionToString(DWORD nExceptionCode) const; void SetExceptionPointers(EXCEPTION_POINTERS* pExceptionPointers) { m_pExceptionPointers = pExceptionPointers; }; void WriteFile(); void GetCallStack(); + void CreateMessageProcess(); private: + //------------------------------------------------------------------------- + // Internals: + //------------------------------------------------------------------------- void FormatExceptionAddress(LPCSTR pExceptionAddress = nullptr); void FormatExceptionCode(); @@ -42,12 +58,20 @@ private: NUM_FRAMES_TO_CAPTURE = 60 }; - void* m_hExceptionHandler; + PVOID m_hExceptionHandler; PVOID m_ppStackTrace[NUM_FRAMES_TO_CAPTURE]; EXCEPTION_POINTERS* m_pExceptionPointers; WORD m_nCapturedFrames; - string m_svBuffer; + + string m_svBuffer; // Buffer containing the entire crash log. + string m_svCrashMsgInfo; + uint8_t m_nCrashMsgFlags; + + bool m_bCallState; // Set when called to prevent recursive calls. + bool m_bCrashMsgCreated; // Set when crashmsg.exe is created to prevent recursive messages. mutable std::mutex m_Mutex; }; +extern CCrashHandler* g_CrashHandler; + #endif // CRASHHANDLER_H \ No newline at end of file diff --git a/r5dev/public/utility/utility.cpp b/r5dev/public/utility/utility.cpp index 2c2bad8e..c8b3d703 100644 --- a/r5dev/public/utility/utility.cpp +++ b/r5dev/public/utility/utility.cpp @@ -351,6 +351,27 @@ string RemoveFileName(const string& svInput, bool bWindows) return svInput.substr(0, nPos); } +/////////////////////////////////////////////////////////////////////////////// +// For creating a file name with the current (now) date and time +string CreateTimedFileName() +{ + auto now = std::chrono::system_clock::now(); + + // Get number of milliseconds for the current second (remainder after division into seconds). + auto ms = std::chrono::duration_cast(now.time_since_epoch()) % 1000; + + // Convert to std::time_t in order to convert to std::tm (broken time). + auto timer = std::chrono::system_clock::to_time_t(now); + std::tm bt = *std::localtime(&timer); + + ostringstream oss; + + oss << std::put_time(&bt, "%Y-%m-%d_%H-%M-%S"); + oss << '.' << std::setfill('0') << std::setw(3) << ms.count(); + + return oss.str(); // 'YY-MM-DD_HH-MM-SS.MMM'. +} + /////////////////////////////////////////////////////////////////////////////// // For creating directories for output streams. string CreateDirectories(string svInput, bool bWindows) diff --git a/r5dev/public/utility/utility.h b/r5dev/public/utility/utility.h index ea8a6de3..46abdb6d 100644 --- a/r5dev/public/utility/utility.h +++ b/r5dev/public/utility/utility.h @@ -29,7 +29,9 @@ bool HasFileName(const string& svInput, const string& svFileName); string GetFileName(const string& svInput, bool bRemoveExtension = false, bool bWindows = false); string RemoveFileName(const string& svInput, bool bWindows = false); +string CreateTimedFileName(); string CreateDirectories(string svInput, bool bWindows = false); + string ConvertToWinPath(const string& svInput); string ConvertToUnixPath(const string& svInput);