BOOST_LOG_FUNCTION + asynchronous_sink + UnloadLibrary = crash

[Chris Newbold]

Full disclosure: this is admittedly an edge case and I have not actually yet attempted reproduction against 1.54; I am using a somewhat earlier version of Boost.Log. But code inspection of 1.54 suggests the issue likely remains.

Our application is using BOOST_LOG_FUNCTION to track control flow and Boost.Log is configured with an asynchronous_sink that is spooling log records to disk in the background. We also heavily use dynamic libraries for plug-ins: they are frequently loaded and unloaded during execution in response to user input.

I am occasionally seeing crashes deep inside the log record formatting machinery driven by the asynchronous_sink and have tracked the problem down to the combination of BOOST_LOG_FUNCTION and the unloading of dynamic libraries.

basic_named_scope_entry captures the function and file names using basic_string_literal, which just hangs on to the character pointer supplied during construction. BOOST_LOG_FUNCTION obtains function and file names using built-in constants such as __FILE__, which just flow through into the basic_named_scope_entries that comprise the current thread's context. These string constants (at least with MSVC on Windows) are stored in the dynamic library containing the code. So when a library is unloaded, the pointed-to strings are no longer valid.

Digging deeper, the implementation of named_scope_value::detach_from_thread() copies the scope list, but since this is just a container of basic_string_literals, only ends up copying the pointers to the literals and not the actual data. So FOO.DLL does some logging with BOOST_LOG_FUNCTION, log records get queued in the asynchronous_sink and then we unload FOO.DLL. Eventually the feeding thread in the asynchronous_sink gets to processing these records and crashes because the string literal pointers in the named scope list are now invalid.

(Note that we are careful not to otherwise pass data by reference to Boost.Log from FOO.DLL; all data is passed by value.)

One way to fix this would be to have named_scope_value::detach_from_thread() make a true deep copy of the named scope stack, including the string literals. More expensive, yes, but it closes this hole where library clients can inadvertently queue records with references to data.