use io_service::post (boost) when deadline_timer is waiting

Question

I have a problem while using deadline_timer and io_service::post as below:

#include "boost/asio.hpp"
#include "boost/thread.hpp"
int main()
{
    boost::asio::io_service io_service;

    boost::asio::deadline_timer timer1(io_service);
    boost::asio::deadline_timer timer2(io_service);

    timer1.expires_from_now(boost::posix_time::seconds(1));
    timer1.async_wait([](const boost::system::error_code& error) {
        boost::this_thread::sleep(boost::posix_time::seconds(5));
        printf("1 ");
    });

    timer2.expires_from_now(boost::posix_time::seconds(2));
    timer2.async_wait([](const boost::system::error_code& error) {
        printf("2 ");
    });

    boost::thread t([&io_service]() {
        boost::this_thread::sleep(boost::posix_time::seconds(5));
        io_service.post([]() {
            printf("3 ");
        });
        io_service.post([]() {
            printf("4 ");
        });
    });

    io_service.run();
    t.join();
    getchar();

    return 0;
}

I thougth that the result is "1 2 3 4" but the result is "1 3 4 2". Anyone can show me how to the callback of timer2(print "2") is performed before as the result "1 2 3 4" with boost library (and don't change the expire time of timer1 and timer2).

Thanks very much!

Answer 1

This is actually a pretty complicated example.

The io_service will run on the main thread. Here is the order of operations

Main Thread:

• Request Timer at T0 + 1
• Request Timer at T0 + 2
• Spawn thread
• Execute all pending io (io_service.run())

Secondary Thread:

• Sleep 5 seconds
• Request Timer
• Request Timer

First of all, nothing will execute in the io_service until io_service.run() is called.

Once io_service.run() is called, a timer for 1 second in the future is scheduled. When that timer fires, it first sleeps for 5 seconds before printing 1.

While that thread is executing, the secondary thread also comes up, and sleeps for 5 seconds. This thread is setup and scheduled before the timer executing in the handler for timer1 is completed. Since both of these threads sleep for 5 seconds, '2' and '3' are immediately posted to the io_service.

Now things get a bit tricky. It seems likely that the timeout for timer2 should have expired by now (it being at least 5 seconds in the future), but there were two commands directly posted to the io_service while it was handling timer1.

It seems that in the implementation details, boost gives priority to directly posted actions over deadline timer actions.

Answer 2

the first timer expiration blocks the io (main) thread from running, in the mean time the other thread posts a couple of items to asio work queue, once timer 1's callback completes, the second timers expiration is processed which causes the callback to be queued but not executed. since "3" & "4" where already queued (while "1" was blocking the main thread), they go ahead of "2"

The point of asio is to not block. By putting long running work in the first timers callback (the sleep) you have prevented the io thread from running in a timely manner. You should offload that work into a dedicated thread, and post its completion back to asio.

Answer 3

The io_service makes no guarantees about the invocation order of handlers. In theory, the handlers could be invoked in any order, with some permutations being significantly unlikely.

If handlers need to be invoked in a very specific order, then consider restructing the asynchronous call chains in a manner that enforces the desired handler chain. Additionally, one may find it necessary to use the guaranteed order of handler invocation that strand provides. Consider not trying to control complex handler invocations through with brittle sleeps and timers.

Answer 4

Your first problem is that you're trying to block inside a handler:

timer1.expires_from_now(boost::posix_time::seconds(1));
timer1.async_wait([](const boost::system::error_code& error) {
    boost::this_thread::sleep(boost::posix_time::seconds(5)); // <--- HERE
    printf("1 ");
});

What happens in the above code is that after timer1 waits for one second, it posts the callback to the io_service. Inside the io_service::run function this callback is executed but this execution happens inside the main thread, so it halts for five seconds, preventing timer2 from posting its handler for execution into io_service. It does so until the sixth second of the program execution (6 = 5+1).

Meanwhile the thread t gets executed and at fifth second of program execution it posts those two printf("3") and printf("4") to io_service.

boost::thread t([&io_service]() {
    boost::this_thread::sleep(boost::posix_time::seconds(5));
    io_service.post([]() {
        printf("3 ");
    });
    io_service.post([]() {
        printf("4 ");
    });
});

Once the handler from timer1 unblocks, it allows timer2 to post its handler to io_service. That again happens at sixth second of program exectuion, that is, once the printf("3") and printf("4") have already been posted!

All in all, I believe what you're looking for is this:

#include "boost/asio.hpp"
#include "boost/thread.hpp"

int main()
{
    boost::asio::io_service io_service;
    boost::optional<boost::asio::io_service::work> work(io_service);

    boost::asio::deadline_timer timer1(io_service);
    boost::asio::deadline_timer timer2(io_service);

    timer1.expires_from_now(boost::posix_time::seconds(1));
    timer1.async_wait([](const boost::system::error_code& error) {
        printf("1 ");
    });

    timer2.expires_from_now(boost::posix_time::seconds(2));
    timer2.async_wait([](const boost::system::error_code& error) {
        printf("2 ");
    });

    boost::thread t([&io_service, &work]() {
        boost::this_thread::sleep(boost::posix_time::seconds(5));
        io_service.post([]() {
            printf("3 ");
        });
        io_service.post([&work]() {
            printf("4 ");
            work = boost::none;
        });
    });

    io_service.run();
    t.join();

    return 0;
}