troubleshooter: properly fix deadlock (#395)

## Description of change
Finally figured out where the deadlock was coming from - it's because
the `dump_to_logger` was writing `SuperstepSound: Audio device is not
available` to the logger which calls back into the log hook, and then
emits another deferred message, trying to acquire the lock again on the
same stack.

## Testing
Tested the superstep sound failure case again.

src/spice2x/launcher/signal.cpp

@@ -101,7 +101,7 @@ static LONG WINAPI TopLevelExceptionFilter(struct _EXCEPTION_POINTERS *Exception
         switch (ExceptionRecord->ExceptionCode) {
             case EXCEPTION_ILLEGAL_INSTRUCTION:
                 deferredlogs::defer_error_messages({
-                    "Illegal instruction exception:",
+                    "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."
                     });
@@ -124,7 +124,7 @@ static LONG WINAPI TopLevelExceptionFilter(struct _EXCEPTION_POINTERS *Exception
 
         // 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();
+        deferredlogs::dump_to_logger(true);
 
         // walk the exception chain
         struct _EXCEPTION_RECORD *record_cause = ExceptionRecord->ExceptionRecord;

src/spice2x/util/deferlog.cpp

@@ -8,7 +8,6 @@ namespace deferredlogs {
 
     const std::initializer_list<std::string> 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",
         "      * check if the default audio device has changed",
         "      * fix your audio device settings (e.g., sample rate)",
@@ -17,37 +16,47 @@ namespace deferredlogs {
 
     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);
     }
 
-    void dump_to_logger() {
+    void dump_to_logger(bool is_crash) {
         static std::once_flag printed;
-        std::call_once(printed, []() {
+        std::call_once(printed, [is_crash]() {
-            too_late = true;
+
-            if (deferred_errors.empty()) {
+            // move to a local vector under lock first
-                return;
+            // this is to avoid holding a lock while emitting to the logger, which may deadlock
+            // due to recursive calls (e.g., via log hooks used for failure detection which then
+            // again calls into defer_error_messages), and std::mutex cannot be acquired recursively
+            std::vector<std::vector<std::string>> errors;
+            {
+                std::lock_guard<std::mutex> lock(deferred_errors_mutex);
+                if (deferred_errors.empty() && !is_crash) {
+                    return;
+                }
+                errors = std::move(deferred_errors);
             }
 
             log_warning("troubleshooter", "/------------------------ spice2x auto-troubleshooter ------------------------\\");
             log_warning("troubleshooter", "");
             
-            for (auto messages : deferred_errors) {
+            if (is_crash) {
+                log_warning("troubleshooter", "  the game has crashed");
+                log_warning("troubleshooter", "      share this entire log file with someone for troubleshooting");
+                log_warning("troubleshooter", "      spice will also attempt to create a minidump (minidump.dmp)");
+                log_warning("troubleshooter", "");
+            }
+
+            for (auto messages : errors) {
                 for (auto message : messages) {
                     log_warning("troubleshooter", "  {}", message);
                 }
                 log_warning("troubleshooter", "");
             }
 
-            log_warning("troubleshooter", "  Still unsure? Check the FAQ:");
+            log_warning("troubleshooter", "  unsure what to do next? check the FAQ:");
             log_warning("troubleshooter", "      https://github.com/spice2x/spice2x.github.io/wiki/Known-issues");
             log_warning("troubleshooter", "");
             log_warning("troubleshooter", "\\------------------------ spice2x auto-troubleshooter -----------------------/");

src/spice2x/util/deferlog.h

@@ -10,5 +10,5 @@ namespace deferredlogs {
     extern const std::initializer_list<std::string> SUPERSTEP_SOUND_ERROR_MESSAGE;
 
     void defer_error_messages(std::initializer_list<std::string> messages);
-    void dump_to_logger();
+    void dump_to_logger(bool is_crash=false);
 }