Fun Bugs: Static initializers and Segfaults

This one kept me up for quite a bit recently. Consider the following code. It has a couple of issues, let’s see if we can find them all:

#include <iostream>
#include <string>

static const std::string LOG_PREFIX = "[LOGGER]";

class logger
{
public:
    logger()
    {
        log("Starting logger...");
    }

    ~logger()
    {
        log("Stopping logger...");
    }

    void log(const std::string &msg)
    {
        std::clog << LOG_PREFIX << " " << msg << std::endl;
    }
};

static logger L{};

int some_func(int x)
{
    L.log("func called");
    return 2*x;
}

int main(void)
{
    L.log("Starting program!");
    std::cout << some_func(5) << std::endl;
    return 0;
}

In case you’re wondering: This is a super simplified version of code that I was actually testing; it’s basically distilled down to the bug.

First, what happens if we compile and run it? Most likely, it’ll do what you think it does. Here’s the output I got:

[LOGGER] Starting logger...
[LOGGER] Starting program!
[LOGGER] func called
10
[LOGGER] Stopping logger...

Except sometimes, it doesn’t. Sometimes it segfaults. This happened a while ago in UHD code, using certain (older) compilers. If it hadn’t been for our continuous integration system, I might have released similar code to the public. What a nightmare! But what’s the problem?

First, let’s reproduce this problem. I could reliably trigger the problem running this on a 32-bit ARM processor, although the precise gcc version might have mattered too. The problem occurred at the end of the program; i.e., my unit tests were passing, but when the program was about to terminate, it would segfault. Given that clue, can you spot the problem? (In my application, gdb stack traces were not very helpful, so for this article I’ll pretend as if there’s no such thing as a debugger.)

Let’s ignore the clue for now, and go from top to bottom. The logger class is clearly quite useless, but obviously, it was designed to illustrate a problem. Something smells: We have a global static class! Could this be part of the issue? Static globals are evil, evil beasts and should be eradicated from any codebase. But sometimes, they can be useful or even the cleanest solution for implementing something. There’s two issues here: The fact that L is global, and the fact that its constructor gets called outside of main(). And yet, we know that the constructor is working fine. Maybe that’s the issue, but let’s table that for now.

Here’s another hint: When it segfaults, the last line of the output is not printed. So maybe the destructor is the problem? Does our C++ runtime library know how to deal with destructing globals that were not created in main()?

Actually, it does. And what’s more, the C++ standard will make sure that destruction is executed properly; i.e., first the destructor is run, and then class attributes are destroyed. However, if something’s going awry in a destructor, that’ll explain why our stack traces are odd.

Let’s amend the destructor:

    ~logger()
    {
        std::cout << "dtor" << std::endl;
        log("Stopping logger...");
    }

I’m making this up as I go along, but let’s say the code crashes in the way I was seeing earlier. Then, “dtor” would get printed, but “Stopping logger” would not. Getting closer!

OK, so something’s going wrong in the log() method, but only when called during destruction. What’s wrong with this method then? Let’s take another look:

    void log(const std::string &msg)
    {
        std::clog << LOG_PREFIX << " " << msg << std::endl;
    }

When calling this function, we actually access a bunch of objects: A this pointer, std::clog, LOG_PREFIX and the messsage itself. The problematic one out of these is LOG_PREFIX (this is guaranteed to be valid until the destructor is done, std::clog actually points to stderr and always works too, and the message in msg gets generated in the destructor and will stick around until the destructor is done; i.e., long after log() is finished).

The matter with LOG_PREFIX is that it itself is a std::string, which is a non-trivial object. This means its destructor also will be called at some arbitrary point in time on termination, and the problem occurs exactly when the compiler decides to de-allocate LOG_PREFIX before L.

Note that we could have had the same issue on construction: Who says that LOG_PREFIX is ready before L is?

To fix this issue (assuming you can’t, for whatever reason, get rid of your global logger object), a simple solution would be to simply use a static const char *LOG_PREFIX instead of a std::string. Or even a #define, if you’re so inclined (wearing our C++ developer hat, we don’t really want to do that, but maybe there’s legitimate reasons for doing so).

Are there reasons to use static global std::strings? Maybe, but they’re similar to reasons to use other static global non-trivial types, and should be treated with care. In general, this all goes back to the evil of static initializers, about which a few other people have blogged about.