Home > Net >  Inconsistent behaviour when calling join() in the destructor
Inconsistent behaviour when calling join() in the destructor

Time:10-31

Considering the following code, where I declare a simple class for executing asynchronous/threaded operations:

#include <chrono>
#include <thread>
#include <mutex>
#include <future>
#include <iostream>

using namespace std::chrono_literals;

class basic_executor {
 public:
    basic_executor() {
        _mx.lock();
        printf("Ctor @%p\n", this);
        _mx.unlock();
    }

    virtual ~basic_executor() {
        _mx.lock();
        printf("Dtor @%p\n", this);
        _mx.unlock();

        if (_thread.joinable()) {
            _thread.join();

            _mx.lock();
            printf("Joined thread @%p\n", this);
            _mx.unlock();
        }
    }

    // sync call
    void run() {
        start();
        execute();
        stop();
    }

    // async call
    void launch(bool detach = false) {
        // create packaged task
        std::packaged_task< void() > task([this] {
            start();
            execute();
            stop();
        });
        // assign future object to function return
        _done = task.get_future();
        // launch function on a separate thread
        _thread = std::thread(std::move(task));
        // detach them from main thread in order to avoid waiting for them
        if (detach == true) {
            _thread.detach();
        }
    }

    // blocking wait for async (detached/joinable)
    void wait() const {
        _done.wait();
    }

 protected:
    virtual void start()   { /* for derived types to implement */ }
    virtual void stop()    { /* for derived types to implement */ }
    virtual void execute() { /* for derived types to implement */ }

    std::mutex _mx;
    std::thread _thread;
    std::future< void > _done;
};

And using the following application example where I derive from it to create two logger objects that make dummy prints for a certain span of time:

class logger : public basic_executor {
 public:
    logger() { /* ... */}

    ~logger() {
        _mx.lock();
        std::cout << "logger destructor " << std::endl;
        _mx.unlock();
    }

    void execute() override {
        std::this_thread::sleep_for(1s);
        for (int i = 0; i < 10;   i) {
            _mx.lock();
            printf("L1: I am printing something\n");
            _mx.unlock();
            std::this_thread::sleep_for(1s);
        }
    }

    void stop() override {
        _mx.lock();
        printf("L1: I am done!\n");
        _mx.unlock();
    }
};


class logger2 : public basic_executor {
 public:
    logger2() { /* ... */}

    ~logger2() {
        _mx.lock();
        printf("logger2 destructor\n");
        _mx.unlock();
    }

    void execute() override {
        for (int i = 0; i < 10;   i) {
            _mx.lock();
            printf("L2: I am ALSO printing something\n");
            _mx.unlock();
            std::this_thread::sleep_for(2s);
        }
    }

    void stop() override {
        _mx.lock();
        printf("L2: I am done!\n");
        _mx.unlock();
    }
};



int main(int argc, char const *argv[]) {
    /* code */

    // printf("log:\n");
    logger log1;

    // printf("log1:\n");
    logger2 log2;

    printf("----------------------------------!\n");

    log2.launch();
    log1.launch();

    // log1.wait();
    // log2.wait();

    printf("----------------------------------!\n");
    return 0;
}

I am getting an unexpected behavior from the program:

Ctor @0x7fff8b18c990
Ctor @0x7fff8b18c9e0
----------------------------------!
----------------------------------!
logger2 destructor
Dtor @0x7fff8b18c9e0
Joined thread @0x7fff8b18c9e0
logger destructor 
Dtor @0x7fff8b18c990
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
L1: I am printing something
Joined thread @0x7fff8b18c990

in that occasionally, the 'log2' object never starts its execution before being destroyed, or the 'join()' call on its destructor hangs indefinitely. Is there any obvious reason why this happens, what exactly am I missing here?

CodePudding user response:

The bug can occur with either logging class. However, with undefined behavior you have no guarantees whatsoever, and no expectation of any kind of consistent results. You've only, so far, observed the same bug with one of two logging classes. Although I can explain why is that, in practical terms, it is immaterial. The bug can happen with either of the objects. Let's begin here:

    _thread = std::thread(std::move(task));

You are not going to get any guarantees whatsoever that the new execution thread will immediately start executing any of the following before this code proceeds and returns from launch():

    std::packaged_task< void() > task([this] {
        start();
        execute();
        stop();
    });

Most of the time, practically, this is going to start running pretty quickly, in the new execution thread. But you cannot rely on that. All that C guarantees you is that at some point after std::thread finishes constructing a new execution thread will start running. It may be immediate. Or, it may be a few hundred milliseconds later because your operating system had something more important on its plate.

You are expecting that the new execution thread will always start executing "immediately", simultaneous with std::thread getting constructed. That is not true. After all, you might be running with a single CPU core, and after constructing the std::thread object you're continuing to execute what follows in the same execution thread, and only a while later a context switch occurs, to the new execution thread.

Meanwhile:

  1. launch() returns.

  2. The parent execution thread reaches the end of main().

  3. All of the objects in the automatic scope are going to get destroyed, one by one.

  4. In C , when an object consists of a superclass and a subclass, the subclass gets destroyed first, followed by the superclass. This is how C works.

  5. So, the logger/logger2 subclass's destructor gets immediately invoked and it destroys the its object (just the logger/logger2 subclass).

  6. Now the superclass's destructor gets invoked, to destroy the superclass. ~basic_executor starts doing its thing, patiently waiting.

  7. And now, finally, that new execution thread, remember that one? Guess what: it finally starts running, and valiantly tries to execute start(), execute(), and stop(). Or maybe it managed to get through start(), first, but hasn't reached execute() yet. But since the actual logger subclass is already destroyed now, guess what happens? Nothing. It's gone. The subclass is no more. It ceased to be. It joined the choir invisible. It is pining for the fjords. It's an ex-subclass. There is no logger::execute or logger2::execute() any more.

  • Related