Boost.Log asynchronous logging invoke flush() periodically

Question

I am implementing a wrapper on top of Boost.Log. in Asynchronous logging, the logger doesn't write the log message immediately and makes a queue of messages. when calling the core.get()->flush() method, messages will be written to file.

But obviously it is not efficient to invoke flush() after each message. And in that way async logging has no benefit. And also it is not a good idea to invoke it once at the end of the program. (maybe the program is running on server for a long time)

I want to write a code to invoke flush() periodicaly (e.g. every 10 ms).

With this example and this question, I wrote a asynchronous timer using Boost.asio, but it didn't write messages to file. Actually logger doesn't create any .log file. maybe because of flush() method must be invoked when no logging is occured.

typedef sinks::asynchronous_sink<
    sinks::text_file_backend,
    sinks::unbounded_ordering_queue<
        logging::attribute_value_ordering< unsigned int, std::less< unsigned int > >
    >
> Async_file_sink;

void do_flush(const boost::system::error_code& /*e*/,
    boost::asio::deadline_timer* t)
{
    logging::core::get()->flush();

    t->expires_at(t->expires_at() + boost::posix_time::milliseconds(10));
    t->async_wait(boost::bind(do_flush,
          boost::asio::placeholders::error, t));
}

struct PerodicTimer{
    PerodicTimer(boost::asio::deadline_timer &timer) : t(timer) {
        t.async_wait(boost::bind(do_flush,
                    boost::asio::placeholders::error, &t));
   }
   boost::asio::deadline_timer& t;
};

void init_flushing()
{
    boost::asio::io_service io;
    boost::asio::deadline_timer t(io, boost::posix_time::milliseconds(10));

    PerodicTimer m(t);
        std::thread th([&]{
        // std::cout << "inside thread" << std::endl;
        io.run();
    });

    th.detach();
}

static void init_logging() 
{
    logging::add_common_attributes();
    boost::shared_ptr< Async_file_sink > sink(new Async_file_sink(
        boost::make_shared< sinks::text_file_backend >(),
        keywords::file_name = "sample_%N.log",
        keywords::rotation_size = 1024 * 1024,
        // We'll apply record ordering to ensure that records from different threads go sequentially in the file
        keywords::order = logging::make_attr_ordering("LineID", std::less< unsigned int >())
    ));

    // Set up where the rotated files will be stored
    init_file_collecting(sink);
    sink->set_formatter(&my_formatter);
    sink->locked_backend()->scan_for_files();
    logging::core::get()->add_sink(sink);
    init_flushing();  // Starting Timer
} 

int main()
{
    init_logging();

    ADD_LOG("SOME MESSAGE");
}

I think the problem is when flush() is being invoked(), at the same time asynch logger is logging messages. I cannot run asynch timer in the same thread, because io.run() is blocking.

what is a minimal solution?

Answer 1

In init_flushing, you immediately exit after spawning a thread and destroy both io_service io and deadline_timer t objects while the thread is running. This is undefined behavior, so that could explain why the code is not behaving as you expect.

Both io and t must stay alive while the thread is running. But, since you're not using io for anything else but waiting for the timer, it would be much simpler to just have a loop that calls std::this_thread::sleep_for to wait and an atomic flag to terminate the loop.

std::thread flushing_thread;
std::atomic<bool> terminate_flushing_thread{ false };

void init_flushing()
{
    assert(!flushing_thread.joinable());

    flushing_thread = std::thread([]()
    {
        while (!terminate_flushing_thread.load(std::memory_order_relaxed))
        {
            std::this_thread::sleep_for(std::chrono::milliseconds(10));
            logging::core::get()->flush();
        }
    });
}

void stop_flushing()
{
    if (flushing_thread.joinable())
    {
        terminate_flushing_thread.store(true, std::memory_order_relaxed);
        flushing_thread.join();
    }
}