Is there a way to cleanly use spdlog after main() (i.e. in static / global objects' destructors)?

[rzvncj]

Hello (and thanks for your work on spdlog),

Is there an endorsed way of logging from global / static objects' destructors (that is, after main() is done)?
Specifically, I want to use a rotating, async logger, and have a static Singleton that's supposed to manage spdlog. The static object's destructor will do a drop_all() and no other objects are supposed to be using spdlog after that.

I know that the recommended way is to call drop_all() (or shutdown()? I've seen both being recommended, and not together - should I just use one of them? both? if both, I assume drop_all() before shutdown()?).

Anyway, I'm seeing what appears to me to be the right order of construction and destruction, that is ~thread_pool() and ~registry run after my Singletons' destructors, but I am losing a bunch of messages (pretty much all that's logged after main() doesn't show up - I've tried sleep()s before drop_all() with no success). That doesn't occur when I am using the default stdout spdlog logger.

Long story short, is there a recommended way to be able to go about achieving this, or is logging after main() just not done under any circumstances? And for debugging, what other spdlog globals should I be watching out for (are there any others, other than registry and thread_pool)?

[rzvncj]

Actually it's even more subtle than that, the Singletons are in an Windows .DLL, and their destructors run after DLL_PROCESS_DETACH.

[tt4g]

As far as I know, after the execution of main(), the process cleanup process begins.
Since this process includes freeing the file handles opened by the process, I don't think you can perform I/O operations after main().

It is also difficult to control the destructor call order of the static object: https://stackoverflow.com/questions/469597/destruction-order-of-static-objects-in-c

[rzvncj]

The call order looks fine, but I did figure out what the problem was. After DllMain there's only one thread left, the one calling the destructors, so the best case scenario is that spdlog can't use the async logger worker thread (because it's dead) - so log messages just go missing - or it just hangs (I assume because the worker thread was killed before it could unlock a mutex, or some such thing).

The long and short of it seems to be that I just shouldn't use spdlog past DllMain (so in the destructors of global / static objects).

[tt4g]

Yes, thread does not work in DllMain.
This is due to the fact that before and after DllMain the instruction code is read into memory.

[rzvncj]

In any case, I'm happy with my findings, please feel free to close the issue anytime you want.
Thanks!

[tt4g]

The workaround is to prepare a startup function and a cleanup function (like Winsock's WSAStartup() and WSACleanup()) and call them with main().

[rzvncj]

Yep, that's the route I'm going for.

[rzvncj]

Actually, just one more thing: to be OK do I call just drop_all(), just shutdown(), or both, before exiting main() (in the .DLL)?

[tt4g]

Calling it is only OK with shutdown().

[xloem]

@tt4g is there an open issue already regarding the destructor limitations in spdlog? I know that, with enough visiting volunteer effort, pretty much any problem can be eventually solved. It helps a lot of there is a clear way to reproduce the issue and a location to share information on it.

Are you familiar with the construct on first use idiom and the nifty/schwartz counter idiom? If not, they are often used to address problems like these, but it sounds like the issue might relate to specifics of dll loading as well.

[tt4g]

@xloem Calling in destructors is not the essence of the problem.
More precisely, the problem is that some platforms are unable to free up resources such as threads when variables declared as static are destroyed. So far, this problem has only been seen on Windows OS.

The problem is simple: static variables are automatically destroyed even if they are not destroyed before the application exit (in other words, before the main function exit).
Since the static variable inside spdlog is also destroyed, the threads and mutexes used at the same time are also destroyed.
And when the process terminates, it automatically releases resources such as threads and mutexes.
This means that the process of releasing threads and mutexes is called twice, once for the destruction of the static variable in spdlog and once for the cleanup process at the end of the process.
When a released resource is released again, an access violation will occur.

I am aware that this is not a spdlog problem, but rather a problem caused by the automatic cleanup process in Windows OS that does not identify released resources.

On Windows platforms, it is better to call spdlog::shutdown() before exiting the application.

[xloem]

Do you have a link to the windows cleanup issue somewhere?

Are you saying that the static object is destroyed before everyone is done using it, or that the thread is being closed by windows before the static object is destroyed, or that a dynamic library is being unloaded before everyone is done using it, or something else? Is there a way I or a visitor could reproduce a failure here?

I'm just thinking that if we slowly collected information in an open issue, people could eventually come up with an organised workaround you'd appreciate. There's always some workaround.

[tt4g]

I believe this is not a problem, but a specification (or limitation).
If read the following documentation, you will see that the Windows OS performs startup and cleanup before and after main() and DllMain().

• https://docs.microsoft.com/en-us/cpp/c-runtime-library/crt-initialization?view=msvc-160
• https://docs.microsoft.com/en-us/windows/win32/dlls/dynamic-link-library-best-practices
• https://docs.microsoft.com/en-us/troubleshoot/cpp/fatal-error-thread-exit-fls-callback
• https://docs.microsoft.com/en-us/windows/win32/dlls/dllmain

The startup process should load the application function symbols, etc. into memory, allocate the stack into memory, etc.

The cleanup process then releases resources such as dynamic memory, threads, and mutexes that have not been released by the time the application terminates.

This startup and cleanup behavior is not directly related to the C++ specification.

However, it is due to the C++ specification that static variables are discarded after the main() function.

https://en.cppreference.com/w/cpp/language/destructor

program termination, for objects with static storage duration

The static variable will be discarded after main() is finished.
However, before that, resources such as threads and mutexes may have been destroyed by the cleanup process.

The problem arises because the two different operating specifications do not (cannot) take each other into consideration.
The only workaround for the problem that C++ coders can do is to "make sure to release the resources before the application exits".

---

To add to this, it seems that different versions of the Windows OS have different start-up and clean-up behaviors.

• https://stackoverflow.com/questions/32517234/access-violation-on-static-initialization

[rzvncj]

Yes, you can reproduce it. (In a DLL) just create a global object that logs something on the destructor, and set the default spdlog logger to an async logger. If you then run your application enough times, it'll either hang or crash. FWIW, last time I did this the EXE and DLL were using a shared runtime, with Visual Studio 2019.

The concise explanation for this is that by the time the destructor of the global DLL object gets called, Windows has killed all of the other threads. You will only have one thread running. But that thread is trying to log something, by placing the thing to be logged in spdlog's queue and signaling it (which involves mutexes, condition variables, something of that sort). Another thread was supposed to pick up the thing posted in the queue and output it to its final destination. But that thread is dead (remember, they've all been killed by Windows), possibly just after it locked the mutex you're trying to use to post to the queue (in which case you're deadlocked, hence the hang).

More info:

https://docs.microsoft.com/en-us/windows/win32/dlls/dllmain (see the Warning sections)
https://devblogs.microsoft.com/oldnewthing/20141017-00/?p=43823

I would also politely disagree with the statement "with enough visiting volunteer effort, pretty much any problem can be eventually solved". I applaud the sentiment, but I dispute its accuracy. :)

[xloem]

Thanks for your description of how to reproduce, that's a great path for pursuing this further.

I have read some of your references. It sounds like this particular issue is present within the dll that runs the log thread, but not in dlls it loads, and only on windows. It sounds like the situation could also be detected with a flag to make it safe (but nonfunctional) to log from such destructors.

I would also politely disagree with the statement "with enough visiting volunteer effort,
pretty much any problem can be eventually solved". I applaud the sentiment, but I
dispute its accuracy. :)

Well, I am thinking on a scale of many years, when I say that, but of course it usually does not happen, it just can. This WSL issue was opened in 2016; I shared a workaround in 2019 on that thread that functioned by actually hooking the windows system calls and changing their behavior, and people actually used this. Microsoft then resolved the underlying issue in their next release.

[rzvncj]

Yes, it's a Windows-only issue. See also: https://spdlog.docsforge.com/v1.x/0.faq/#asynchronous-logging-hangs-on-application-exit-under-windows

In fact, the application where the problem mainfested was cross-platform (Linux, macOS and Windows) and exhaustively tested on all platforms. Only Windows had any spdlog problems.

[artemyv]

The problem when calling spdlog::shutdown from dllmain PROCESS_DETACH event is caused by code inside this function that tries to send notification to all threads created by spdlog to close and starts waiting for these threads to exit. But the PROCESS_DETACH event is called by Windows after all threads but the last one are already closed by OS.
In my code I solved it by closing splog threads from WinMain. I'm not using the async loggers - So I had only problems with periodic flush thread.

For me it was enough to disable periodic flush before exiting WinMain (and enable flush on every message level instead). In this case no threads created by spdlog are alive at the moment of dllmain calling spdlog::shutdown
And all the logging is done perfectly by any global object destructors.

I do not know if there is an API that could be used to close only async loggers and cause the threads related to them to be stopped before exiting WinMain and leave sync loggers without periodic flush to live till the process end

[themarpe]

@gabime @xloem
My observation I have with this issue is that is easily reproducible and causes issues.
While the heap use after free issue presented by address sanitizer might not be visible usually, in our depthai-core it crashes the app in a bad way (modifies some global std::unordered_map in an underlying XLink library)

My question is, can we introduce something along the lines that @xloem mentioned, or atleast some sort of capability of letting registry know that there are still some handles out there, etc...

Also, I think in our case it would be best to maybe go ahead with the above proposed nifty counter, if we create a logger manually. Would that work, eg. does the life of manually created logger extend over the registry (and potentially other spdlog internals) destruction?

A minimal code that represents the issue (tested /w compiled spdlog 1.9.2, app compiled with flags: -fno-omit-frame-pointer -fsanitize=address,undefined, as well as include only library in below steps):

1. Download 1.9.2 spdlog
2. Place the following code snippet into include/main.cpp

#include <memory>
#include <spdlog/spdlog.h>
struct Device {
    Device() = default;
    ~Device() {
        spdlog::debug("Device destructed");
    }
};
std::shared_ptr<Device> obj;
int main() {
    spdlog::debug("test");
    obj = std::make_shared<Device>();
}

3. Compile and run

g++ main.cpp -I. -fsanitize=address -o main
./main 

4. Examine the crash

=================================================================
==12494==ERROR: AddressSanitizer: heap-use-after-free on address 0x611000000310 at pc 0x5561d12ae937 bp 0x7fff7d98a920 sp 0x7fff7d98a910
READ of size 4 at 0x611000000310 thread T0
    #0 0x5561d12ae936 in spdlog::logger::should_log(spdlog::level::level_enum) const (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x17936)
    #1 0x5561d12ae71d in spdlog::logger::log(spdlog::source_loc, spdlog::level::level_enum, fmt::v8::basic_string_view<char>) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1771d)
    #2 0x5561d130999e in void spdlog::logger::log<char [18], 0>(spdlog::source_loc, spdlog::level::level_enum, char const (&) [18]) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x7299e)
    #3 0x5561d12ec521 in void spdlog::logger::log<char [18]>(spdlog::level::level_enum, char const (&) [18]) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x55521)
    #4 0x5561d12db8f4 in void spdlog::logger::debug<char [18]>(char const (&) [18]) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x448f4)
    #5 0x5561d12c7dac in void spdlog::debug<char [18]>(char const (&) [18]) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x30dac)
    #6 0x5561d12b694f in Device::~Device() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f94f)
    #7 0x5561d135a203 in void __gnu_cxx::new_allocator<Device>::destroy<Device>(Device*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xc3203)
    #8 0x5561d1358b14 in void std::allocator_traits<std::allocator<Device> >::destroy<Device>(std::allocator<Device>&, Device*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xc1b14)
    #9 0x5561d1349004 in std::_Sp_counted_ptr_inplace<Device, std::allocator<Device>, (__gnu_cxx::_Lock_policy)2>::_M_dispose() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xb2004)
    #10 0x5561d12c9f92 in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x32f92)
    #11 0x5561d12baf59 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::~__shared_count() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x23f59)
    #12 0x5561d12b696f in std::__shared_ptr<Device, (__gnu_cxx::_Lock_policy)2>::~__shared_ptr() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f96f)
    #13 0x5561d12b69c7 in std::shared_ptr<Device>::~shared_ptr() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f9c7)
    #14 0x7f984b551160  (/lib/x86_64-linux-gnu/libc.so.6+0x43160)
    #15 0x7f984b551259 in exit (/lib/x86_64-linux-gnu/libc.so.6+0x43259)
    #16 0x7f984b52fbfd in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21bfd)
    #17 0x5561d12a2209 in _start (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xb209)

0x611000000310 is located 80 bytes inside of 224-byte region [0x6110000002c0,0x6110000003a0)
freed by thread T0 here:
    #0 0x7f984bf812c0 in operator delete(void*) (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xe12c0)
    #1 0x5561d13454cd in __gnu_cxx::new_allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> >::deallocate(std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2>*, unsigned long) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xae4cd)
    #2 0x5561d134048f in std::allocator_traits<std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> > >::deallocate(std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> >&, std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2>*, unsigned long) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xa948f)
    #3 0x5561d1334c77 in std::__allocated_ptr<std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> > >::~__allocated_ptr() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x9dc77)
    #4 0x5561d1349616 in std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2>::_M_destroy() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xb2616)
    #5 0x5561d12ca009 in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x33009)
    #6 0x5561d12baf59 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::~__shared_count() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x23f59)
    #7 0x5561d12b3fa3 in std::__shared_ptr<spdlog::logger, (__gnu_cxx::_Lock_policy)2>::~__shared_ptr() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1cfa3)
    #8 0x5561d12b3fbf in std::shared_ptr<spdlog::logger>::~shared_ptr() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1cfbf)
    #9 0x5561d1334f8b in std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >::~pair() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x9df8b)
    #10 0x5561d1334fb7 in void __gnu_cxx::new_allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >::destroy<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >(std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x9dfb7)
    #11 0x5561d1324c8d in void std::allocator_traits<std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > > >::destroy<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >(std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >&, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x8dc8d)
    #12 0x5561d1308844 in std::__detail::_Hashtable_alloc<std::allocator<std::__detail::_Hash_node<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, true> > >::_M_deallocate_node(std::__detail::_Hash_node<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, true>*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x71844)
    #13 0x5561d12eb437 in std::__detail::_Hashtable_alloc<std::allocator<std::__detail::_Hash_node<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, true> > >::_M_deallocate_nodes(std::__detail::_Hash_node<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, true>*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x54437)
    #14 0x5561d12dabcb in std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::clear() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x43bcb)
    #15 0x5561d12c752b in std::_Hashtable<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > >, std::__detail::_Select1st, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::~_Hashtable() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x3052b)
    #16 0x5561d12b5c59 in std::unordered_map<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::shared_ptr<spdlog::logger>, std::hash<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const, std::shared_ptr<spdlog::logger> > > >::~unordered_map() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1ec59)
    #17 0x5561d12b685f in spdlog::details::registry::~registry() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f85f)
    #18 0x7f984b551160  (/lib/x86_64-linux-gnu/libc.so.6+0x43160)

previously allocated by thread T0 here:
    #0 0x7f984bf80448 in operator new(unsigned long) (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xe0448)
    #1 0x5561d134549c in __gnu_cxx::new_allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> >::allocate(unsigned long, void const*) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xae49c)
    #2 0x5561d13403e2 in std::allocator_traits<std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> > >::allocate(std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> >&, unsigned long) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xa93e2)
    #3 0x5561d1334bdd in std::__allocated_ptr<std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> > > std::__allocate_guarded<std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> > >(std::allocator<std::_Sp_counted_ptr_inplace<spdlog::logger, std::allocator<spdlog::logger>, (__gnu_cxx::_Lock_policy)2> >&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x9dbdd)
    #4 0x5561d13252d2 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<spdlog::logger, std::allocator<spdlog::logger>, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> > >(std::_Sp_make_shared_tag, spdlog::logger*, std::allocator<spdlog::logger> const&, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> >&&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x8e2d2)
    #5 0x5561d1308f7e in std::__shared_ptr<spdlog::logger, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<spdlog::logger>, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> > >(std::_Sp_make_shared_tag, std::allocator<spdlog::logger> const&, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> >&&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x71f7e)
    #6 0x5561d12eb698 in std::shared_ptr<spdlog::logger>::shared_ptr<std::allocator<spdlog::logger>, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> > >(std::_Sp_make_shared_tag, std::allocator<spdlog::logger> const&, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> >&&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x54698)
    #7 0x5561d12db232 in std::shared_ptr<spdlog::logger> std::allocate_shared<spdlog::logger, std::allocator<spdlog::logger>, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> > >(std::allocator<spdlog::logger> const&, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> >&&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x44232)
    #8 0x5561d12c79e3 in std::shared_ptr<spdlog::logger> std::make_shared<spdlog::logger, char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> > >(char const*&, std::shared_ptr<spdlog::sinks::ansicolor_stdout_sink<spdlog::details::console_mutex> >&&) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x309e3)
    #9 0x5561d12b63dd in spdlog::details::registry::registry() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f3dd)
    #10 0x5561d12b68cf in spdlog::details::registry::instance() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f8cf)
    #11 0x5561d12b692d in spdlog::default_logger_raw() (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x1f92d)
    #12 0x5561d12c7dc0 in void spdlog::debug<char [5]>(char const (&) [5]) (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x30dc0)
    #13 0x5561d12a26d7 in main (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0xb6d7)
    #14 0x7f984b52fbf6 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21bf6)

SUMMARY: AddressSanitizer: heap-use-after-free (/home/themarpe/Documents/tmp/spdlog-1.9.2/include/main+0x17936) in spdlog::logger::should_log(spdlog::level::level_enum) const
Shadow bytes around the buggy address:
  0x0c227fff8010: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c227fff8020: fd fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c227fff8030: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c227fff8040: fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa
  0x0c227fff8050: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
=>0x0c227fff8060: fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c227fff8070: fd fd fd fd fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c227fff8080: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c227fff8090: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c227fff80a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c227fff80b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==12494==ABORTING

[artemyv]

I suppose if you will use spdlog in the constructor of the global object it will force to construct registry before your global object in this case it will be still alive to be used in destructor as well
Ensuring that spdlog static objects are created before any other global object that uses it is not too hard task and we do so in our application and have no problem with logging till the very end.

And as a hint - do not use globals. Use static vars in the GetInstance() function - to avoid issues when one global var tries to use another one. When you call GetInstance() function it is guaranteed that any static var in it is initialized. When you access global var from other global var - there is no such guarantee

[themarpe]

@artemyv the issue at hand is calling spdlog from destructor of a global object.
Where the spdlog gets destructed sooner than the global object's destructor, which calls spdlog afterwards, causing memory corruption.

[artemyv]

@artemyv the issue at hand is calling spdlog from destructor of a global object. Where the spdlog gets destructed sooner than the global object's destructor, which calls spdlog afterwards, causing memory corruption.

The order of destruction is opposite to order of construction. You need to ensure the right order of construction to be able to use logger in destructors. That's why my suggestion was about usage of logger in constructor.

[xloem]

I had gotten confused by the addition of a different concern to the discussion, but I'm popping back here just a little bit.

To clarify, it looks like @themarpe's case would be resolved via a nifty/schwartz counter or shared pointer on the structure (maybe the registry, I infer) containing the data that is deallocated too early. I tried the example code with latest spdlog commit, and I also tried changing it to call the logger in the constructor as artemyv suggested: both failed for me. (edit: this could be because the registry is allocated as a static local variable)

This problem is distinct from the DLL unloading concern which is likely a little more complex.

I infer that #2113 is tracking @themarpe's platform-independent deallocation order issue, and that there is still no issue tracking the windows dll unloading issue.

[themarpe]

Godbolt of the above bug: https://godbolt.org/z/9qxo4Meex

@xloem / @wangjunZeroZeroSeven - rereading the #2113 and above, what do you think about doing such change to spdlog:

1. move all static data to eg registry or some other global structure.
2. add access to this structure:

// New
std::shared_ptr<registry> instance_ptr() {
    static auto ptr = std::make_shared<registry>();
    return ptr;
}

// Existing, slightly modified
registry& instance() {
    static registry& s_instance = *instance_ptr();
    return s_instance;
}

Where instance_ptr could be used to forcefully extend the lifetime of spdlog as a whole.
Eg if you need to call spdlog from destructor, add this to your object:

struct Device {
    auto spdlogExtend = spdlog::details::registry::instance_ptr(); // Add this line
    Device() = default;
    ~Device() {
        spdlog::debug("Device destructed");
    }
};

Note, not tested yet, just an idea

[xloem]

I'm still just casually looking at this; I have not understood the problem in depth.

It sounds to me like the simplest solution would be to bump a major version and change the api to have c-style initialisation and destruction as recommended at #2113 (comment) . This would simplistically resolve nearly all the potential problems here, but would be a major change to the library. There's a good chance the maintainers would not accept such a change. Getting feedback from them via tagging or opening a pr could move that decision forward.

Second to that the solution would of course be to wrap everything in one object and provide access to that object as you recommend, and then document and later implement workarounds for any quirks that exist. If this can be done without breaking the interface then there's a good chance a PR would be accepted.

Given people are saying the problems lie with static data that is outside the registry, a first step could be to simply move all the static data into it, as also mentioned in the other issue. This would make progress on both approaches.

[raakasf]

Why has this been closed? I am still facing this issue, has a solution already been proposed and added?

[gabime]

No, it is considered an invalid usage/limitation of spdlog. You are welcome to propose a solution.