logger: more fixes to deferred logging (troubleshooter) (#394)

## Description of change
Various fixes to deferred logger -

* Rename to "auto troubleshooter"
* Fix potential deadlock
* Reword the error messages to fit in a narrower column

## Testing
tested all the error cases

src/spice2x/avs/core.cpp

@@ -2003,8 +2003,9 @@ namespace avs {
                 deferredlogs::defer_error_messages({
                     fmt::format(
                         "log level is set to `{}` (either in avs-config.xml or using -loglevel)", log_level_as_str),
-                        "    if you are troubleshooting crashes or failures, it is recommended that you set ",
+                        "    this log file may have omitted important error messages from the game",
-                        "    AVS Log Level (-loglevel) option to `all`",
+                        "    if you are troubleshooting crashes or failures, it is recommended that you",
+                        "    set AVS Log Level (-loglevel) option to `all`",
                         });
             }
 

src/spice2x/hooks/graphics/backends/d3d9/d3d9_backend.cpp

@@ -209,11 +209,13 @@ 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 any graphics options you configured in spicecfg",
-        "    double check that your monitor supports the resolution + refresh rate that the game needs",
+        "    * double check that your monitor supports the resolution + refresh rate",
-        "    enable GPU-side resolution scaling in your GPU options as needed",
+        "          combination that the game requires",
-        "    if you have three or more monitors, try unplugging them down to one or two, or enable -graphics-force-single-adapter option",
+        "    * enable GPU-side resolution scaling in your GPU options as needed",
-        "    failing all that, see if enabling windowed mode helps"
+        "    * 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"
     });
 }
 

src/spice2x/launcher/signal.cpp

@@ -98,31 +98,34 @@ static LONG WINAPI TopLevelExceptionFilter(struct _EXCEPTION_POINTERS *Exception
         // print signal
         log_warning("signal", "exception raised: {}", exception_code(ExceptionRecord));
 
-        std::string err;
         switch (ExceptionRecord->ExceptionCode) {
             case EXCEPTION_ILLEGAL_INSTRUCTION:
-                err = "Illegal instruction: either your CPU is too old (e.g., does not support "
+                deferredlogs::defer_error_messages({
-                    "SSE4.2 or AVX2 but perhaps the game requires it); or, a bad patch was applied.";
+                    "Illegal instruction exception:",
+                    "    either your CPU is too old (e.g., does not support SSE4.2 or AVX2 ",
+                    "    but perhaps the game requires it); or, a bad patch was applied."
+                    });
                 break;
             default:
                 break;
         }
-        if (!err.empty()) {
-            log_warning(
-                "signal",
-                "likely cause for your error based on the exception code:\n    {}",
-                err.c_str());
-        }
 
         // check ACIO init failures
         if (acio::IO_INIT_IN_PROGRESS) {
             deferredlogs::defer_error_messages({
-                "exception raised during ACIO init, this usually happens when a third party application interferes with hooks",
+                "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"
+                "      * RivaTuner Statistics Server (RTSS)",
+                "      * MSI Afterburner",
+                "      * kernel mode anti-cheat"
             });
         }
 
+        // dump deferred logs BEFORE stack trace since some errors cause stack trace logic to hang
+        // (e.g., ACIO init hang due to RTSS)
+        deferredlogs::dump_to_logger();
+
         // walk the exception chain
         struct _EXCEPTION_RECORD *record_cause = ExceptionRecord->ExceptionRecord;
         while (record_cause != nullptr) {
@@ -137,8 +140,6 @@ 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",

src/spice2x/util/deferlog.cpp

@@ -1,4 +1,5 @@
 #include <mutex>
+#include <atomic>
 
 #include "deferlog.h"
 #include "util/logging.h"
@@ -9,14 +10,21 @@ namespace deferredlogs {
         "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)",
+        "      * check if the default audio device has changed",
-        "    double check your spice audio options/patches, and try again"
+        "      * fix your audio device settings (e.g., sample rate)",
+        "      * double check your spice audio options and patches"
     };
 
     std::mutex deferred_errors_mutex;
     std::vector<std::vector<std::string>> deferred_errors;
+    std::atomic<bool> too_late;
 
     void defer_error_messages(std::initializer_list<std::string> messages) {
+        // don't try to acquire lock if already dumping to logger
+        if (too_late) {
+            return;
+        }
+
         std::lock_guard<std::mutex> lock(deferred_errors_mutex);
         deferred_errors.emplace_back(messages);
     }
@@ -24,24 +32,25 @@ namespace deferredlogs {
     void dump_to_logger() {
         static std::once_flag printed;
         std::call_once(printed, []() {
-            std::lock_guard<std::mutex> lock(deferred_errors_mutex);
+            too_late = true;
-            if (!deferred_errors.empty()) {
+            if (deferred_errors.empty()) {
-                log_warning("deferred_error",
+                return;
-                    "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!");
-                log_warning("deferred_error", "");
             }
 
+            log_warning("troubleshooter", "/------------------------ spice2x auto-troubleshooter ------------------------\\");
+            log_warning("troubleshooter", "");
+
             for (auto messages : deferred_errors) {
                 for (auto message : messages) {
-                    log_warning("deferred_error", "{}", message);
+                    log_warning("troubleshooter", "  {}", message);
                 }
-                log_warning("deferred_error", "");
+                log_warning("troubleshooter", "");
             }
 
-            if (!deferred_errors.empty()) {
+            log_warning("troubleshooter", "  Still unsure? Check the FAQ:");
-                log_warning("deferred_error",
+            log_warning("troubleshooter", "      https://github.com/spice2x/spice2x.github.io/wiki/Known-issues");
-                    "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!");
+            log_warning("troubleshooter", "");
-            }
+            log_warning("troubleshooter", "\\------------------------ spice2x auto-troubleshooter -----------------------/");
         });
     }
 }