logger object is not ensured to outlive all static local variables that it uses

[wangjunZeroZeroSeven]

In this library, it is preferred that local static variables defines in a function scope, in this way this static variable will construct the first time we call this function .

Since static variables will destruct in the inverted order of construction, if the function is called after program starts, the static varaible inside the function will construct when program is running and it will destruct earlier than any normal destructors which execute at the end of program.

As a result, we can not safely use logger object in normal destructors since it may call some static variables that already destruct ! I met this program in my project , could you force all static local variables outlive logger object ?

[tt4g]

The lifetime of the spdlog logger is managed by std::shared_ptr.
If you want to access it safely in a destructor, just copy std::shared_ptr<spdlog::logger> into a member variable.

[wangjunZeroZeroSeven]

std::shared_ptr only controll the lifetime of spdlog logger, but it can't controll these basic things:

the s_mutex in :

struct console_mutex
{
    using mutex_t = std::mutex;
    static mutex_t &mutex()
    {
        static mutex_t s_mutex;
        return s_mutex;
    }
};

the s_mutex in :

struct console_nullmutex
{
    using mutex_t = null_mutex;
    static mutex_t &mutex()
    {
        static mutex_t s_mutex;
        return s_mutex;
    }
};

the mutex in :

SPDLOG_INLINE void logger::err_handler_(const std::string &msg)
{
    if (custom_err_handler_)
    {
        custom_err_handler_(msg);
    }
    else
    {
        using std::chrono::system_clock;
        static std::mutex mutex;
        static std::chrono::system_clock::time_point last_report_time;
        static size_t err_counter = 0;
        std::lock_guard<std::mutex> lk{mutex};
        auto now = system_clock::now();
        err_counter++;
        if (now - last_report_time < std::chrono::seconds(1))
        {
            return;
        }
        last_report_time = now;
        auto tm_time = details::os::localtime(system_clock::to_time_t(now));
        char date_buf[64];
        std::strftime(date_buf, sizeof(date_buf), "%Y-%m-%d %H:%M:%S", &tm_time);
#if defined(USING_R) && defined(R_R_H) // if in R environment
        REprintf("[*** LOG ERROR #%04zu ***] [%s] [%s] {%s}\n", err_counter, date_buf, name().c_str(), msg.c_str());
#else
        std::fprintf(stderr, "[*** LOG ERROR #%04zu ***] [%s] [%s] {%s}\n", err_counter, date_buf, name().c_str(), msg.c_str());
#endif
    }
}

and many other local static varaibles declared in a function scope, these variables may destruct ealier than our self-defined object, then in our object's destructor we can't use spdlog safely as I said.

[tt4g]

static objects will be destroyed after the application is exited.
Unless you call spdlog from the destructor of static object, I don't think you will have this problem.

[wangjunZeroZeroSeven]

Unfortunately that's exactly our case :-)

In our project , we use a static container to hold most of our objects as members.

So it's somehow a special case, if spdlog support that all basic things outlive spd logger object , then there still will be no problem in our project.

Our project is a library , so using static container to hold all whole lifetime objects is convenient.

[wangjunZeroZeroSeven]

Actually, force all basic things to live longer than spd logger is viable and will be more safe and save lots of exceptions, but it's annoying which I understand .

[tt4g]

Hmmm, this must be a problem with the library design.
I think it would be difficult to remove many static objects from the spdlog project (because it would break the library API).

Making the lifetime of other objects shorter than that of spdlog is probably the only workaround for the problem at this point.

[wangjunZeroZeroSeven]

Making the lifetime of other objects shorter than spdlog is easy, but making the lifetime of other objects shorter than all the basic things that spdlog relies on is difficult and hard to ensure.

I think out a way that can settle the lifetime issue of spdlog and won't break the library API:

Create a common header file like global.h , declare a struct Global that contains all static varaibles declared in function scope currently.

struct Global
{
  std::mutex mutex1;
  std::mutex mutex2;
  all other local static ...
};

Global& getGlobal()
{
   static Global global;
   return global;
}

in spd logger's constructor, we call this getGlobal(), then all is done.

[tt4g]

@gabime Are the proposed changes acceptable?

[gabime]

spdlog already has the details/registry singleton class to store globals, so maybe those mutexes can be placed in this class as well.
I am not sure if what solves the problem though. How can you decide when the destructor of this class will happen? especially across multiple compilation units?

[wangjunZeroZeroSeven]

According to these pages:
Destruction order of static objects in C++

std::exit

It is illustrated that static variables will destruct in the reverse order of construction, so what we can do is to controll the construction order ourselves. static objects that construct earlier will destruct later automatically. (this is tested locally)

According to the below page which refers to the very approach I mentioned:

Finding C++ static initialization order problems

If we declare a getInstance function to contain the static varaible inside, in this way, we can control when we first call getInstance , this is exactly the time when the inside static variable initializes. so we can control the construction time.

Since there is already a spdlog::details::registry , we can simply put all local static variables into this registry, and call registry::instance() in logger object's constructor, this can ensure registry object outlives any logger object. (this is tested locally)

[gabime]

I dont understand what would be difference from current situation where all static object are local function statics and would destructed after the logger that created them.

[wangjunZeroZeroSeven]

All local static objects declared in a function scope will construct when the first time we call this function, so it's hard to say these variables will initialize when program begins , it may initialize anytime when program is running.

As they are static objects , they will destruct at end of program, but in the reverse order of initilization, so they will destruct ealier than any other static variables. If we are using spd logger in some static variables's destructor (this is exact our case, we are developing a library which use a static container to hold all variables inside), this may cause problem, because some variables that spd logger relies on may destruct already.

[wangjunZeroZeroSeven]

Some static local varaibles that spd logger relies on may be not used when initilizing spd logger, they may be first used when we first log, or may be first used when first exception raises , or some other conditions to trigger than function.

As they are initialized after spd logger initialized, so when program ends, they will destruct ealier than spd logger.

I must admit this is a special condition, because we are logging in a static varaible's destructor.

[clarkholdham]

I've recently encountered the exact same issues as wangjunZeroZeroSeven. I was unable to come up with a perfectly safe solution (outside of removing any spdlog calls from local variable destruction).

[SirWhiteHat]

I second this, having encountered this exact problem too.

Could we do both @wangjunZeroZeroSeven 's suggestion of a class that contains all the currently-static variables, but in doing so create a "spdlog instance" (pSpdlog->get(), rather than spdlog::get()) which:

1. Can be explictly instantiated and lifetime-managed by the user (for users with this particular use case)
2. Is always instantiated as a static instance, which can then support the existing static API?

This should maintain the existing API via the static instance, but provide the option of a user-managed instance of the "global" (but really only instance-scoped) object.

[wangjunZeroZeroSeven]

@SirWhiteHat I have to point out that it's not absolutely safe either, as you can controll the life cycle of spdlog instance, but you cannot controll the basic static variable's life time inside spdlog library. As I listed: #2113 (comment)

They may live shorter than spdlog instance and can cause problems. We have to force developers do not use spd logger in any destructor that executes at program end.

[SirWhiteHat]

@wangjunZeroZeroSeven I'm proposing keeping the existing API using the static spdlog instance, but we also allow use of a lifetime-managed spdlog instance (which contains the same as those existing static variables, but non-static). I admit that this wouldn't make the existing API safe for use in other static objects, but it would provide a separate lifetime-managed instance that could be used in such a scenario!

[themarpe]

Related: #1738 (comment)
@wangjunZeroZeroSeven @SirWhiteHat
Do you perhaps know if creating your own logger (eg: spdlog::basic_logger_mt) without adding it to registry, etc.. and using that beyond the scope of static init/deinit of spdlog works as expected? Or do all the various mutexes, etc.. outlined in #2113 (comment) cause the issue for this kind of use?

[tfiner]

I am having the same problem as others, I know that a lot of this is duplicating what others said, but I really wanted to make sure why the current code has a problem.

Statics are a minor code smell in application code and downright stinky in library code. A library has no control over when its dependent statics gets destroyed. Since spdlog statics are being created in spdlog modules, there is no deterministic way to order the statics so that the logging API is initialized first and destroyed last. Add to this mess that some of the statics are created lazily (on first use). That pretty much guarantees crashes if you are logging in a static destructor, because the statics created by an application will certainly have been created before spdlog's were created which means spdlog's statics will be destroyed before the application's. Which means that the static destructor is calling spdlog's destroyed logger.

@wangjunZeroZeroSeven is 100% correct and it is completely normal to log on destruction within static variables. It is an unusual library that can't be called from a static object's destructor deterministically and safely.

A common solution is to have a global startup / shutdown function for "C" APIs (I saw the solutions up there mention this as an alternative). Everything that needs to be created happens in there. Well designed C++ APIs that need startup / shutdown should include an RAII class that does the same startup / shutdown on construction / destruction. Users of libraries that provide either are responsible if they chose to use a static objects that call the library API in their destructors.

A common solution for that issue is to put all the statics instances in one place in the order you want them created (logger RAII first, then all the objects that need the logger). That way, even in the face of exceptions, the logger is the last static destroyed.

[weihhh]

Is there already a solution to this problem?

[tfiner]

@weihhh Not that I have seen.

[adah1972]

Maybe, the logger simply should not rely on other static objects that can potentially be created after the logger? Those objects should be created on the free store and be managed by the logger object (possible via shared_ptr). There can still be static/global variables pointing to those objects, but they should also be shared_ptrs as well—or some other forms of reference-counted smart pointers.

[tfiner]

@adah1972 If you are saying that the logging library should not have static variables, then we are in agreement. If the library needs some static state, then it should offer the applications the opportunity to initialize and release them.

[adah1972]

I was saying that other global/static objects should not have lifetime issues with the logger object per se. And I believe it is doable.

[tfiner]

How I solved it without altering spdlog code, I have logging statements in the constructors and destructors, via pseudocode:

all of this is in main:

main
try
   init logging
   init static objs as smart pointers
catch all
   log exception
explicitly release objs
flush logging
exit
spdlog's statics get destroyed

This isn't ideal, the point of using smart pointers is that we shouldn't have to explicitly release them. But, because of the static state in spdlog, and the C++ rules surrounding static object destruction, this kind of solution is the only way I am aware of, right now, to deal with this.

The application programmer should be able to use a library without being forced to manage statics in libraries they are using.

[gabime]

I created a branch that attempts to address this issue:

• All static objects were removed from the codebase except of a single s_registry* raw pointer. This should solve all problems for logger objects that created manually when not using the registry.
• The registry object is dynamically allocated, ensuring it will not be implicitly deleted before, during, or after main. It will only be destroyed when the user calls shutdown().
• The downside is that it is a breaking change and requires the user to call shutdown() at some point; otherwise, there will be a memory leak (and possibly lost logs since logger destruction not called). Also we are now passing the burden of correctly calling shutdown() at the right place to the user which can to be very tricky task with static destrcutors.
• A possible option is to use std::shared_ptr for the registry pointer to get automatic cleanup, and let the user explicitly disable it using spdlog::registry::disable_auto_release or similar.

Please share your thoughts.

#include "spdlog/spdlog.h"

struct my_struct {
    my_struct() {
        spdlog::info("my_struct ctor");
    }
    ~my_struct() {
        spdlog::info("my_struct dtor");
        //spdlog::shutdown(); // call this if you are sure spdlog would never be called again
    }
};

my_struct global_struct;

int main(int, char *[]) {
    spdlog::info("In main");
    //spdlog::shutdown(); // call this if you are sure spdlog would never be called again
}

[Project579]

I have just hit this issue.

I'm creating a wrapper object around spdlog and calling spdlog::shutdown() on it's destructor, the wrapper object is allocated dynamically but freed statically (I have a std::shared_ptr static variable), the issue is that on program shutdown the destructor for the registry is called before the destructor of the wrapper object, than the destructor of my object causes a double free when calling spdlog::shudown(), it would be nice if the branch could be updated as I would like to give it a try, I assume that would allow the registry to be freed during the spdlog::shudown() call instead of before.

[adah1972]

#include "spdlog/spdlog.h"

struct my_struct {
    my_struct() {
        spdlog::info("my_struct ctor");
    }
    ~my_struct() {
        spdlog::info("my_struct dtor");
        spdlog::shutdown(); // call this if you are sure spdlog would never be called again
    }
};

This probably does not work, as people encountering this issue may have many static objects, or, worse, they use several different libraries, each of which wants to use a logger in its destructor....

I think a reference-counted method is probably necessary. The "current" static object should decrease the global reference count, normally shutting down the logger when the program exits. All (static) objects that need to use the logger in its destructor should call spdlog::retain() in its contructor and spdlog::release() in its destructor—retain and release are imagined reference increasing/decreasing method names for your consideration.

This will not change the current behaviour, while providing a way to people who need to control the logger lifetime. Of course, the refactoring to change all static objects that the logger depends on are still necessary.

[ddassie-texa]

I think this issue could be solved the same way as #3003 , if the user can provide an instance of the registry that they allocated, they will also be able to control it's lifetime (as long as all mutable global state is contained in the registry).

[gabime]

I think this issue could be solved the same way as #3003 , if the user can provide an instance of the registry that they allocated, they will also be able to control it's lifetime (as long as all mutable global state is contained in the registry).

Right, this and also having spdlog dynamically allocate the default registry instance would solve this.