From 32801319fa6fb41686bed9f076256e1ad73e46a7 Mon Sep 17 00:00:00 2001 From: bicarus-dev <202771338+bicarus-dev@users.noreply.github.com> Date: Thu, 2 Oct 2025 18:42:49 -0700 Subject: [PATCH] Create a class for deferred error logging (#390) ## Link to GitHub Issue, if one exists #388 ## Description of change Instead of setting flags in `signal` and logging when we crash, create a class for logging deferred semi-fatal messages, and dump them to the log immediately before crashing or shutting down. ## Testing Tested each failure case by injection. --- src/spice2x/CMakeLists.txt | 1 + src/spice2x/avs/core.cpp | 9 ++- src/spice2x/games/iidx/iidx.cpp | 3 +- src/spice2x/games/sdvx/sdvx.cpp | 3 +- .../graphics/backends/d3d9/d3d9_backend.cpp | 19 ++++-- src/spice2x/launcher/shutdown.cpp | 4 ++ src/spice2x/launcher/signal.cpp | 65 +++---------------- src/spice2x/launcher/signal.h | 9 --- src/spice2x/util/deferlog.cpp | 44 +++++++++++++ src/spice2x/util/deferlog.h | 14 ++++ 10 files changed, 97 insertions(+), 74 deletions(-) create mode 100644 src/spice2x/util/deferlog.cpp create mode 100644 src/spice2x/util/deferlog.h diff --git a/src/spice2x/CMakeLists.txt b/src/spice2x/CMakeLists.txt index daef13f..f5ee805 100644 --- a/src/spice2x/CMakeLists.txt +++ b/src/spice2x/CMakeLists.txt @@ -611,6 +611,7 @@ set(SOURCE_FILES ${SOURCE_FILES} util/tapeled.cpp util/execexe.cpp util/dependencies.cpp + util/deferlog.cpp ) source_group(TREE ${CMAKE_CURRENT_SOURCE_DIR} PREFIX "Source Files" FILES ${SOURCE_FILES}) diff --git a/src/spice2x/avs/core.cpp b/src/spice2x/avs/core.cpp index 572a61e..d9b4bcb 100644 --- a/src/spice2x/avs/core.cpp +++ b/src/spice2x/avs/core.cpp @@ -9,6 +9,7 @@ #include "external/robin_hood.h" #include "launcher/logger.h" #include "launcher/signal.h" +#include "util/deferlog.h" #include "util/detour.h" #include "util/fileutils.h" #include "util/libutils.h" @@ -1739,8 +1740,12 @@ namespace avs { static void avs_dir_err(const std::filesystem::path &src_path) { - launcher::signal::AVS_DIR_CREATION_FAILURE = TRUE; - launcher::signal::AVS_SRC_PATH = src_path.string(); + deferredlogs::defer_error_messages({ + "AVS filesystem initialization failure was previously detected during boot!", + fmt::format(" ERROR: directory could not be created: {}", src_path.string().c_str()), + fmt::format(" this crash may have been caused by bad contents in {}", avs::core::CFG_PATH.c_str()), + " fix the XML file and try again" + }); } static void create_avs_dir( diff --git a/src/spice2x/games/iidx/iidx.cpp b/src/spice2x/games/iidx/iidx.cpp index cddd3b7..372ae5b 100644 --- a/src/spice2x/games/iidx/iidx.cpp +++ b/src/spice2x/games/iidx/iidx.cpp @@ -23,6 +23,7 @@ #include "misc/wintouchemu.h" #include "misc/eamuse.h" #include "util/detour.h" +#include "util/deferlog.h" #include "util/fileutils.h" #include "util/libutils.h" #include "util/memutils.h" @@ -235,7 +236,7 @@ namespace games::iidx { out.clear(); return true; } else if (data.find("SuperstepSound: Audio device is not available") != std::string::npos) { - launcher::signal::SUPERSTEP_SOUND_ERROR = TRUE; + deferredlogs::defer_error_messages(deferredlogs::SUPERSTEP_SOUND_ERROR_MESSAGE); return false; } else { return false; diff --git a/src/spice2x/games/sdvx/sdvx.cpp b/src/spice2x/games/sdvx/sdvx.cpp index 41baf6f..ef82d5a 100644 --- a/src/spice2x/games/sdvx/sdvx.cpp +++ b/src/spice2x/games/sdvx/sdvx.cpp @@ -13,6 +13,7 @@ #include "hooks/sleephook.h" #include "hooks/winuser.h" #include "touch/touch.h" +#include "util/deferlog.h" #include "util/detour.h" #include "util/logging.h" #include "util/sigscan.h" @@ -211,7 +212,7 @@ namespace games::sdvx { return true; } if (data.find("SuperstepSound: Audio device is not available") != std::string::npos) { - launcher::signal::SUPERSTEP_SOUND_ERROR = TRUE; + deferredlogs::defer_error_messages(deferredlogs::SUPERSTEP_SOUND_ERROR_MESSAGE); return false; } return false; diff --git a/src/spice2x/hooks/graphics/backends/d3d9/d3d9_backend.cpp b/src/spice2x/hooks/graphics/backends/d3d9/d3d9_backend.cpp index de85afb..0002afc 100644 --- a/src/spice2x/hooks/graphics/backends/d3d9/d3d9_backend.cpp +++ b/src/spice2x/hooks/graphics/backends/d3d9/d3d9_backend.cpp @@ -26,6 +26,7 @@ #include "misc/wintouchemu.h" #include "overlay/overlay.h" #include "util/detour.h" +#include "util/deferlog.h" #include "util/flags_helper.h" #include "util/libutils.h" #include "util/logging.h" @@ -204,6 +205,18 @@ static std::string presentation_interval2s(UINT presentation_interval) { static void update_backbuffer_dimensions(D3DPRESENT_PARAMETERS *params); +static void log_create_device_failure(HRESULT hresult) { + deferredlogs::defer_error_messages({ + fmt::format("D3D9 CreateDevice/CreateDeviceEx failed with {:#x}!", (UINT)hresult), + " this is a common graphics / monitor issue", + " double check any graphics options you configured in spicecfg", + " double check that your monitor supports the resolution + refresh rate that the game needs", + " enable GPU-side resolution scaling in your GPU options as needed", + " if you have three or more monitors, try unplugging them down to one or two, or enable -graphics-force-single-adapter option", + " failing all that, see if enabling windowed mode helps" + }); +} + static bool is_dx9_on_12_enabled() { switch (GRAPHICS_9_ON_12_STATE) { case DX9ON12_FORCE_OFF: @@ -776,8 +789,7 @@ HRESULT STDMETHODCALLTYPE WrappedIDirect3D9::CreateDevice( // log error log_info("graphics::d3d9", "IDirect3D9::CreateDevice failed, hr={}", FMT_HRESULT(ret)); - launcher::signal::D3D9_CREATE_DEVICE_FAILED = true; - launcher::signal::D3D9_CREATE_DEVICE_FAILED_HRESULT = ret; + log_create_device_failure(ret); } else if (!D3D9_DEVICE_HOOK_DISABLE) { graphics_hook_window(hFocusWindow, pPresentationParameters); @@ -997,8 +1009,7 @@ HRESULT STDMETHODCALLTYPE WrappedIDirect3D9::CreateDeviceEx( // log error log_warning("graphics::d3d9", "CreateDeviceEx failed, hr={}", FMT_HRESULT(result)); - launcher::signal::D3D9_CREATE_DEVICE_FAILED = true; - launcher::signal::D3D9_CREATE_DEVICE_FAILED_HRESULT = result; + log_create_device_failure(result); } else if (!D3D9_DEVICE_HOOK_DISABLE) { graphics_hook_window(hFocusWindow, pPresentationParameters); diff --git a/src/spice2x/launcher/shutdown.cpp b/src/spice2x/launcher/shutdown.cpp index bdd75f6..38f5058 100644 --- a/src/spice2x/launcher/shutdown.cpp +++ b/src/spice2x/launcher/shutdown.cpp @@ -7,6 +7,7 @@ #include "easrv/easrv.h" #include "rawinput/rawinput.h" #include "hooks/audio/audio.h" +#include "util/deferlog.h" #include "util/logging.h" #include "launcher.h" @@ -21,6 +22,9 @@ namespace launcher { // therefore, subsystems need to be guarded against multiple unload attempts log_info("launcher", "stopping subsystems"); + // before shutting down logger, dump any deferred log messages + deferredlogs::dump_to_logger(); + // flush/stop logger logger::stop(); diff --git a/src/spice2x/launcher/signal.cpp b/src/spice2x/launcher/signal.cpp index 6d20da5..5fe0046 100644 --- a/src/spice2x/launcher/signal.cpp +++ b/src/spice2x/launcher/signal.cpp @@ -5,12 +5,11 @@ #include #include -#include "avs/core.h" -#include "avs/game.h" #include "acio/acio.h" #include "external/stackwalker/stackwalker.h" #include "hooks/libraryhook.h" #include "launcher/shutdown.h" +#include "util/deferlog.h" #include "util/detour.h" #include "util/libutils.h" #include "util/logging.h" @@ -30,13 +29,6 @@ namespace launcher::signal { // settings bool DISABLE = false; bool USE_VEH_WORKAROUND = false; - - // states - bool SUPERSTEP_SOUND_ERROR = false; - bool AVS_DIR_CREATION_FAILURE = false; - std::string AVS_SRC_PATH; - bool D3D9_CREATE_DEVICE_FAILED = false; - uint32_t D3D9_CREATE_DEVICE_FAILED_HRESULT; } #define V(variant) case variant: return #variant @@ -124,54 +116,11 @@ static LONG WINAPI TopLevelExceptionFilter(struct _EXCEPTION_POINTERS *Exception // check ACIO init failures if (acio::IO_INIT_IN_PROGRESS) { - log_warning( - "signal", - "exception raised during ACIO init, this usually happens when a third party application interferes with hooks"); - log_warning( - "signal", - " please check for the following, disable them, and try launching the game again:"); - log_warning( - "signal", - " RivaTuner Statistics Server (RTSS), MSI Afterburner, kernel mode anti-cheat"); - } - - if (launcher::signal::SUPERSTEP_SOUND_ERROR) { - log_warning("signal", "audio initialization error was previously detected during boot!"); - log_warning("signal", " (W:SuperstepSound: Audio device is not available!!!)"); - log_warning("signal", " this crash is most likely related to audio init failure"); - log_warning("signal", " see if the default audio device changed, fix your audio configuration (e.g., sample rate)"); - log_warning("signal", " double check your spice audio options/patches, and try again"); - } - - if (launcher::signal::AVS_DIR_CREATION_FAILURE) { - log_warning("signal", - "AVS filesystem initialization failure was previously detected during boot!"); - log_warning("signal", - " ERROR: directory could not be created: {}", - launcher::signal::AVS_SRC_PATH.c_str()); - log_warning("signal", - " this crash may have been caused by bad contents in {}", - avs::core::CFG_PATH.c_str()); - log_warning("signal", " fix the XML file and try again"); - } - - if (launcher::signal::D3D9_CREATE_DEVICE_FAILED) { - log_warning("signal", - "D3D9 CreateDevice/CreateDeviceEx failed with {:#x}!", - launcher::signal::D3D9_CREATE_DEVICE_FAILED_HRESULT); - - log_warning("signal", - " this is a common graphics / monitor issue"); - log_warning("signal", - " double check any graphics options you configured in spicecfg"); - log_warning("signal", - " double check that your monitor supports the resolution + refresh rate that the game needs"); - log_warning("signal", - " enable GPU-side resolution scaling in your GPU options as needed"); - log_warning("signal", - " if you have three or more monitors, try unplugging them down to one or two, or enable -graphics-force-single-adapter option"); - log_warning("signal", - " failing all that, see if enabling windowed mode helps"); + deferredlogs::defer_error_messages({ + "exception raised during ACIO init, this usually happens when a third party application interferes with hooks", + " please check for the following, disable them, and try launching the game again:", + " RivaTuner Statistics Server (RTSS), MSI Afterburner, kernel mode anti-cheat" + }); } // walk the exception chain @@ -188,6 +137,8 @@ static LONG WINAPI TopLevelExceptionFilter(struct _EXCEPTION_POINTERS *Exception log_warning("signal", "failed to print callstack"); } + deferredlogs::dump_to_logger(); + if (MiniDumpWriteDump_local != nullptr) { HANDLE minidump_file = CreateFileA( "minidump.dmp", diff --git a/src/spice2x/launcher/signal.h b/src/spice2x/launcher/signal.h index 890739b..1053911 100644 --- a/src/spice2x/launcher/signal.h +++ b/src/spice2x/launcher/signal.h @@ -9,15 +9,6 @@ namespace launcher::signal { extern bool DISABLE; extern bool USE_VEH_WORKAROUND; - // error cases - extern bool SUPERSTEP_SOUND_ERROR; - extern bool AVS_DIR_CREATION_FAILURE; - extern std::string AVS_XML_PATH; - extern std::string AVS_SRC_PATH; - extern bool D3D9_CREATE_DEVICE_FAILED; - extern uint32_t D3D9_CREATE_DEVICE_FAILED_HRESULT; - - //void print_stacktrace(); void attach(); void init(); } diff --git a/src/spice2x/util/deferlog.cpp b/src/spice2x/util/deferlog.cpp new file mode 100644 index 0000000..7471458 --- /dev/null +++ b/src/spice2x/util/deferlog.cpp @@ -0,0 +1,44 @@ +#include + +#include "deferlog.h" +#include "util/logging.h" + +namespace deferredlogs { + + const std::initializer_list SUPERSTEP_SOUND_ERROR_MESSAGE = { + "audio initialization error was previously detected during boot!", + " (W:SuperstepSound: Audio device is not available!!!)", + " this crash is most likely related to audio init failure", + " see if the default audio device changed, fix your audio configuration (e.g., sample rate)", + " double check your spice audio options/patches, and try again" + }; + + std::vector> deferred_errors; + + void defer_error_messages(std::initializer_list messages) { + deferred_errors.emplace_back(messages); + } + + void dump_to_logger() { + static std::once_flag printed; + std::call_once(printed, []() { + if (!deferred_errors.empty()) { + log_warning("deferred_error", + "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!"); + log_warning("deferred_error", ""); + } + + for (auto messages : deferred_errors) { + for (auto message : messages) { + log_warning("deferred_error", "{}", message); + } + log_warning("deferred_error", ""); + } + + if (!deferred_errors.empty()) { + log_warning("deferred_error", + "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!"); + } + }); + } +} diff --git a/src/spice2x/util/deferlog.h b/src/spice2x/util/deferlog.h new file mode 100644 index 0000000..10bea86 --- /dev/null +++ b/src/spice2x/util/deferlog.h @@ -0,0 +1,14 @@ +#pragma once + +#include +#include +#include + +namespace deferredlogs { + + // some shared error messages + extern const std::initializer_list SUPERSTEP_SOUND_ERROR_MESSAGE; + + void defer_error_messages(std::initializer_list messages); + void dump_to_logger(); +}