log: Close file after stop and fallback to stderr

src/common/logging/backend.cpp

@@ -51,6 +51,8 @@ public:
     virtual void EnableForStacktrace() = 0;
 
     virtual void Flush() = 0;
+
+    virtual void Close() = 0;
 };
 
 /**
@@ -72,6 +74,10 @@ public:
         std::fflush(stderr);
     }
 
+    void Close() override {
+        enabled = false;
+    }
+
     void EnableForStacktrace() override {
         enabled = true;
     }
@@ -130,6 +136,11 @@ public:
         file->Flush();
     }
 
+    void Close() override {
+        file->Close();
+        enabled = false;
+    }
+
     void EnableForStacktrace() override {
         enabled = true;
         bytes_written = 0;
@@ -158,6 +169,8 @@ public:
 
     void Flush() override {}
 
+    void Close() override {}
+
     void EnableForStacktrace() override {}
 };
 
@@ -177,11 +190,14 @@ public:
 
     void Flush() override {}
 
+    void Close() override {}
+
     void EnableForStacktrace() override {}
 };
 #endif
 
 bool initialization_in_progress_suppress_logging = true;
+bool logging_initialized = false;
 
 #ifdef CITRA_LINUX_GCC_BACKTRACE
 [[noreturn]] void SleepForever() {
@@ -216,6 +232,7 @@ public:
         instance = std::unique_ptr<Impl, decltype(&Deleter)>(
             new Impl(fmt::format("{}{}", log_dir, log_file), filter), Deleter);
         initialization_in_progress_suppress_logging = false;
+        logging_initialized = true;
     }
 
     static void Start() {
@@ -258,8 +275,8 @@ public:
         if (!filter.CheckMessage(log_class, log_level)) {
             return;
         }
-        Entry new_entry =
-            CreateEntry(log_class, log_level, filename, line_num, function, std::move(message));
+        Entry new_entry = CreateEntry(log_class, log_level, filename, line_num, function,
+                                      std::move(message), time_origin);
         if (!regex_filter.empty() &&
             !boost::regex_search(FormatLogMessage(new_entry), regex_filter)) {
             return;
@@ -274,6 +291,24 @@ public:
         }
     }
 
+    static Entry CreateEntry(Class log_class, Level log_level, const char* filename,
+                             unsigned int line_nr, const char* function, std::string&& message,
+                             const std::chrono::steady_clock::time_point& time_origin) {
+        using std::chrono::duration_cast;
+        using std::chrono::microseconds;
+        using std::chrono::steady_clock;
+
+        return {
+            .timestamp = duration_cast<microseconds>(steady_clock::now() - time_origin),
+            .log_class = log_class,
+            .log_level = log_level,
+            .filename = filename,
+            .line_num = line_nr,
+            .function = function,
+            .message = std::move(message),
+        };
+    }
+
 private:
     Impl(const std::string& file_backend_filename, const Filter& filter_)
         : filter{filter_}, file_backend{file_backend_filename} {
@@ -348,6 +383,8 @@ private:
             };
             while (!stop_token.stop_requested()) {
                 message_queue.PopWait(entry, stop_token);
+                // Only write the log if something was actually popped (entry.filename != nullptr)
+                // (for example, when the stop token is signaled).
                 if (entry.filename != nullptr) {
                     write_logs();
                 }
@@ -367,24 +404,10 @@ private:
             backend_thread.join();
         }
 
-        ForEachBackend([](Backend& backend) { backend.Flush(); });
-    }
-
-    Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
-                      const char* function, std::string&& message) const {
-        using std::chrono::duration_cast;
-        using std::chrono::microseconds;
-        using std::chrono::steady_clock;
-
-        return {
-            .timestamp = duration_cast<microseconds>(steady_clock::now() - time_origin),
-            .log_class = log_class,
-            .log_level = log_level,
-            .filename = filename,
-            .line_num = line_nr,
-            .function = function,
-            .message = std::move(message),
-        };
+        ForEachBackend([](Backend& backend) {
+            backend.Flush();
+            backend.Close();
+        });
     }
 
     void ForEachBackend(auto lambda) {
@@ -485,9 +508,19 @@ void SetColorConsoleBackendEnabled(bool enabled) {
 void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename,
                        unsigned int line_num, const char* function, fmt::string_view format,
                        const fmt::format_args& args) {
-    if (!initialization_in_progress_suppress_logging) {
+    if (initialization_in_progress_suppress_logging) [[unlikely]] {
+        return;
+    }
+
+    if (logging_initialized) [[likely]] {
         Impl::Instance().PushEntry(log_class, log_level, filename, line_num, function,
                                    fmt::vformat(format, args));
+    } else {
+        // In the rare case that logging occurs before initialization, write the
+        // message to stderr to preserve useful debug information.
+        Entry new_entry = Impl::CreateEntry(log_class, log_level, filename, line_num, function,
+                                            fmt::vformat(format, args), {});
+        PrintMessage(new_entry);
     }
 }
 } // namespace Common::Log