fix crashes during destruction of static objects (#8)

* prevent TLS being used after destruction

* prevent log static data from being destroyed prematurely

* fix alignment of g_log_data

* fix re-entrancy in alloc logging, add static test

* use storage for static data

* add test

* fix release build

---------

Co-authored-by: TheNumbat <[email protected]>

Author: the-be-to

rpp/impl/log.cpp

@@ -40,9 +40,21 @@ struct Static_Data {
     }
 };
 
-static Static_Data g_log_data;
+static Storage<Static_Data> g_log_data;
 static thread_local u64 g_log_indent = 0;
 
+namespace detail {
+
+Static_Init::Static_Init() noexcept {
+    g_log_data.construct();
+}
+
+Static_Init::~Static_Init() noexcept {
+    g_log_data.destruct();
+}
+
+} // namespace detail
+
 #ifdef RPP_OS_WINDOWS
 
 [[nodiscard]] String_View sys_error() noexcept {
@@ -147,23 +159,25 @@ void output(Level level, const Location& loc, String_View msg) noexcept {
     Thread::Id thread = Thread::this_id();
     ::time_t timer = ::time(null);
 
-    Thread::Lock lock(g_log_data.lock);
+    {
+        Thread::Lock lock(g_log_data->lock);
 
-    String_View time = sys_time_string(timer);
+        String_View time = sys_time_string(timer);
 
-    printf(format_str, time.length(), time.data(), level_str, thread, loc.file.length(),
-           loc.file.data(), loc.line, g_log_indent * INDENT_SIZE, "", msg.length(), msg.data());
-    fflush(stdout);
+        printf(format_str, time.length(), time.data(), level_str, thread, loc.file.length(),
+               loc.file.data(), loc.line, g_log_indent * INDENT_SIZE, "", msg.length(), msg.data());
+        fflush(stdout);
 
-    for(auto& [_, callback] : g_log_data.callbacks) {
-        callback(level, thread, timer, loc, msg);
+        if(g_log_data->file) {
+            fprintf(g_log_data->file, format_str, time.length(), time.data(), level_str, thread,
+                    loc.file.length(), loc.file.data(), loc.line, g_log_indent * INDENT_SIZE, "",
+                    msg.length(), msg.data());
+            fflush(g_log_data->file);
+        }
     }
 
-    if(g_log_data.file) {
-        fprintf(g_log_data.file, format_str, time.length(), time.data(), level_str, thread,
-                loc.file.length(), loc.file.data(), loc.line, g_log_indent * INDENT_SIZE, "",
-                msg.length(), msg.data());
-        fflush(g_log_data.file);
+    for(auto& [_, callback] : g_log_data->callbacks) {
+        callback(level, thread, timer, loc, msg);
     }
 }
 
@@ -178,17 +192,17 @@ Scope::~Scope() noexcept {
 
 [[nodiscard]] Token
 subscribe(Function<void(Level, Thread::Id, Time, Location, String_View)> f) noexcept {
-    Thread::Lock lock(g_log_data.lock);
-    Token t = g_log_data.next++;
-    g_log_data.callbacks.insert(t, rpp::move(f));
+    Thread::Lock lock(g_log_data->lock);
+    Token t = g_log_data->next++;
+    g_log_data->callbacks.insert(t, rpp::move(f));
     return t;
 }
 
 void unsubscribe(Token token) noexcept {
-    Thread::Lock lock(g_log_data.lock);
-    g_log_data.callbacks.erase(token);
-    if(g_log_data.callbacks.empty()) {
-        g_log_data.callbacks.~Map();
+    Thread::Lock lock(g_log_data->lock);
+    g_log_data->callbacks.erase(token);
+    if(g_log_data->callbacks.empty()) {
+        g_log_data->callbacks.~Map();
     }
 }
 

rpp/impl/profile.cpp

@@ -159,14 +159,16 @@ void Profile::Frame_Profile::exit() noexcept {
 
 void Profile::alloc(Alloc a) noexcept {
     if constexpr(DO_PROFILE) {
+        bool replaced = false;
+        bool no_entry = false;
         {
             Thread::Lock lock(allocs_lock);
             Alloc_Profile& prof = allocs.get_or_insert(a.name);
 
             if(a.size) {
 
                 if(prof.current_set.contains(a.address)) {
-                    warn("Profile: % reallocated %!", a.name, a.address);
+                    replaced = true;
                 }
                 prof.current_set.insert(a.address, a.size);
 
@@ -179,7 +181,7 @@ void Profile::alloc(Alloc a) noexcept {
 
                 Opt<Ref<u64>> sz = prof.current_set.try_get(a.address);
                 if(!sz.ok()) {
-                    warn("Profile: % freed % with no entry!", a.name, a.address);
+                    no_entry = true;
                 } else {
                     i64 size = **sz;
                     prof.current_set.erase(a.address);
@@ -189,10 +191,16 @@ void Profile::alloc(Alloc a) noexcept {
                 }
             }
         }
+
+        if(replaced) warn("Profile: % reallocated %!", a.name, a.address);
+        if(no_entry) warn("Profile: % freed % with no entry!", a.name, a.address);
+
         {
-            Thread::Lock lock(this_thread.frames_lock);
-            if(this_thread.during_frame) {
-                this_thread.frames.back().allocations.push(rpp::move(a));
+            if(!this_thread_destroyed) {
+                Thread::Lock lock(this_thread.frames_lock);
+                if(this_thread.during_frame) {
+                    this_thread.frames.back().allocations.push(rpp::move(a));
+                }
             }
         }
     }
@@ -248,10 +256,6 @@ void Profile::finalize() noexcept {
     } else {
         info("No regions leaked.");
     }
-    if(net != 0) {
-        warn("Memory leaked, shutting down now...");
-        Libc::exit(1);
-    }
 }
 
 } // namespace rpp

rpp/log.h

@@ -92,6 +92,18 @@ void log(Level level, const Location& loc, String_View fmt, const Ts&... args) n
     Region(R) output(level, loc, format<Mregion<R>>(fmt, args...).view());
 }
 
+namespace detail {
+
+struct Static_Init {
+    Static_Init() noexcept;
+    ~Static_Init() noexcept;
+};
+
+// Constructed before subsequent globals and destructed after them.
+inline Static_Init g_initializer;
+
+}; // namespace detail
+
 } // namespace Log
 
 RPP_NAMED_ENUM(Log::Level, "Level", info, RPP_CASE(info), RPP_CASE(warn), RPP_CASE(fatal));

rpp/profile.h

@@ -138,6 +138,7 @@ struct Profile {
         }
         ~Thread_Profile() noexcept {
             finalize();
+            this_thread_destroyed = true;
         }
 
         void finalize() noexcept {
@@ -161,6 +162,7 @@ struct Profile {
     static inline Thread::Mutex allocs_lock;
     static inline Thread::Mutex finalizers_lock;
     static inline thread_local Thread_Profile this_thread;
+    static inline thread_local bool this_thread_destroyed = false;
     static inline Map<Thread::Id, Ref<Thread_Profile>, Mhidden> threads;
     static inline Map<String_View, Alloc_Profile, Mhidden> allocs;
     static inline Vec<Function<void()>, Mhidden> finalizers;

test/static.cpp

@@ -0,0 +1,48 @@
+
+#include "test.h"
+
+#include <rpp/base.h>
+#include <rpp/thread.h>
+
+using Alloc = Mallocator<"Alloc">;
+
+struct Destroy {
+    ~Destroy() {
+        info("Log at static destruction.");
+        Profile::finalize();
+    }
+};
+Destroy at_exit;
+
+Test test{"static"_v};
+
+Vec<i32, Alloc> g_vec0;
+Vec<i32, Alloc> g_vec1{1, 2, 3};
+
+i32 main() {
+    Profile::begin_frame();
+
+    static Vec<i32, Alloc> vec{1, 2, 3};
+    static Box<i32, Alloc> box{5};
+
+    static thread_local Vec<i32, Alloc> tls_vec{1, 2, 3};
+    static thread_local Box<i32, Alloc> tls_box{5};
+
+    info("g_vec0: %", g_vec0);
+    info("g_vec1: %", g_vec1);
+    info("vec: %", vec);
+    info("box: %", box);
+    info("tls_vec: %", tls_vec);
+    info("tls_box: %", tls_box);
+
+    auto v = Thread::spawn([]() {
+        tls_vec = Vec<i32, Alloc>{1, 2, 3, 4, 5};
+        info("tls_vec in thread: %", tls_vec);
+        info("tls_box in thread: %", tls_box);
+        return move(tls_vec);
+    });
+    info("Thread returned: %", v->block());
+
+    Profile::end_frame();
+    return 0;
+}

test/static.expect

@@ -0,0 +1,9 @@
+[Level::info] g_vec0: Vec[]
+[Level::info] g_vec1: Vec[1, 2, 3]
+[Level::info] vec: Vec[1, 2, 3]
+[Level::info] box: Box{5}
+[Level::info] tls_vec: Vec[1, 2, 3]
+[Level::info] tls_box: Box{5}
+[Level::info] tls_vec in thread: Vec[1, 2, 3, 4, 5]
+[Level::info] tls_box in thread: Box{null}
+[Level::info] Thread returned: Vec[1, 2, 3, 4, 5]

test/test.h

@@ -6,12 +6,10 @@
 using namespace rpp;
 
 struct Test {
-    using Alloc = Mallocator<"Test">;
-
     explicit Test(String_View name) : name(name) {
         token = Log::subscribe(
             [&](Log::Level lvl, Thread::Id, Log::Time, Log::Location, String_View msg) {
-                auto m = format<Alloc>("[%] %\n"_v, lvl, msg);
+                auto m = format<Mhidden>("[%] %\n"_v, lvl, msg);
                 for(u8 c : m) {
                     result.push(c);
                 }
@@ -20,7 +18,7 @@ struct Test {
     ~Test() {
         Log::unsubscribe(token);
 
-        auto expect = name.append<Alloc>(".expect"_v);
+        auto expect = name.append<Mdefault>(".expect"_v);
         expected = move(*Files::read(expect.view()));
 
         bool differs = false;
@@ -36,14 +34,14 @@ struct Test {
         }
 
         if(differs) {
-            auto corrected = name.append<Alloc>(".corrected"_v);
+            auto corrected = name.append<Mdefault>(".corrected"_v);
             static_cast<void>(Files::write(corrected.view(), result.slice()));
             Libc::exit(1);
         }
     }
 
     String_View name;
-    Vec<u8, Alloc> result;
+    Vec<u8, Mhidden> result;
     Vec<u8, Files::Alloc> expected;
     Log::Token token;
 };