No timer callback after periodic timer cancellation

[brain5lug]

#include <seastar/core/app-template.hh>
#include <seastar/core/timer.hh>
#include <seastar/core/reactor.hh>
#include <seastar/core/print.hh>
#include <seastar/core/thread.hh>
#include <seastar/core/sleep.hh>
#include <chrono>
#include <iostream>

using namespace seastar;
using namespace std::chrono_literals;

struct timer_hang_test {
    timer<steady_clock_type> t1;
    timer<steady_clock_type> t2;
    promise<> pr1;
    promise<> pr2;

    future<> run() {
        t1.set_callback([this](){
            std::cerr << "has t1 callback"<< std::endl;
            if (t1.cancel()) {
                std::cerr << "t1 has been cancelled"<< std::endl;
            }
            pr1.set_value();
        });
        t2.set_callback([this](){
            std::cerr << "no t2 callback"<< std::endl;
            pr2.set_value();
        });

        (void)pr1.get_future().then([this]{
            t2.arm(2ms);
            std::cerr << "t2 has been armed"<< std::endl;
        });

        t1.arm_periodic(1ms);

        // some work here
        std::this_thread::sleep_for(1ms);
        std::cerr << "some work is done"<< std::endl;

        // this future never resolves
        return pr2.get_future();
    }
};

int main(int ac, char** av) {
    app_template app;
    timer_hang_test t1;
    return app.run_deprecated(ac, av, [&t1] {
        fmt::print("=== Start Timer hang test\n");
        return t1.run().then([] {
            fmt::print("Done\n");
            engine().exit(0);
        });
    });
}

The test hangs untill Ctrl+C is pressed. The text fails 100%. Full test output:

WARN  2025-10-02 12:29:11,090 seastar - Your system does not have enough AIO capacity for optimal network performance; reducing `max-networking-io-control-blocks'.
WARN  2025-10-02 12:29:11,090 seastar - Resultant AIO control block usage:
WARN  2025-10-02 12:29:11,090 seastar - 
WARN  2025-10-02 12:29:11,090 seastar - purpose  per cpu  all 8 cpus
WARN  2025-10-02 12:29:11,090 seastar - -------  -------  ----------
WARN  2025-10-02 12:29:11,090 seastar - reserve                    0
WARN  2025-10-02 12:29:11,090 seastar - storage     1024        8192
WARN  2025-10-02 12:29:11,090 seastar - preempt        2          16
WARN  2025-10-02 12:29:11,090 seastar - network     7166       57328
WARN  2025-10-02 12:29:11,090 seastar - -------  -------  ----------
WARN  2025-10-02 12:29:11,090 seastar - total       8192       65536
WARN  2025-10-02 12:29:11,090 seastar - 
WARN  2025-10-02 12:29:11,090 seastar - For optimal network performance, set /proc/sys/fs/aio-max-nr to at least 88208.
INFO  2025-10-02 12:29:11,091 seastar - Reactor backend: linux-aio
INFO  2025-10-02 12:29:11,092 seastar - Perf-based stall detector creation failed (EACCESS), try setting /proc/sys/kernel/perf_event_paranoid to 1 or less to enable kernel backtraces: falling back to posix timer.
INFO  2025-10-02 12:29:11,102 [shard 0:main] seastar - IO queue was unable to find a suitable maximum request length, the search was cut-off early at: 16MB
INFO  2025-10-02 12:29:11,102 [shard 0:main] seastar - IO queue was unable to find a suitable maximum request length, the search was cut-off early at: 16MB
=== Start Timer hang test
some work is done
has t1 callback
t1 has been cancelled
t2 has been armed

[tgrabiec]

Try replacing run_deprecated() with run().

[brain5lug]

Here is code with replacement. Result is quite the same. It hangs, but a had to stop it with SIGKILL.

#include <seastar/core/app-template.hh>
#include <seastar/core/timer.hh>
#include <seastar/core/reactor.hh>
#include <seastar/core/print.hh>
#include <seastar/core/thread.hh>
#include <seastar/core/sleep.hh>
#include <chrono>
#include <iostream>

using namespace seastar;
using namespace std::chrono_literals;

struct timer_hang_test {
    timer<steady_clock_type> t1;
    timer<steady_clock_type> t2;
    promise<> pr1;
    promise<> pr2;

    future<> run() {
        t1.set_callback([this](){
            std::cerr << "has t1 callback"<< std::endl;
            if (t1.cancel()) {
                std::cerr << "t1 has been cancelled"<< std::endl;
            }
            pr1.set_value();
        });
        t2.set_callback([this](){
            std::cerr << "no t2 callback"<< std::endl;
            pr2.set_value();
        });

        (void)pr1.get_future().then([this]{
            t2.arm(2ms);
            std::cerr << "t2 has been armed"<< std::endl;
        });

        t1.arm_periodic(1ms);

        // some work here
        auto end = std::chrono::steady_clock::now() + 1ms;
        do {
        } while (std::chrono::steady_clock::now() < end);
        std::cerr << "some work is done"<< std::endl;

        // this future never resolves
        return pr2.get_future();
    }
};

int main(int ac, char** av) {
    app_template app;
    timer_hang_test t1;
    return app.run(ac, av, [&t1] {
        fmt::print("=== Start Timer hang test\n");
        return t1.run().then([] {
            fmt::print("Done\n");
            engine().exit(0);
        });
    });
}

WARN  2025-10-02 19:06:38,292 seastar - Your system does not have enough AIO capacity for optimal network performance; reducing `max-networking-io-control-blocks'.
WARN  2025-10-02 19:06:38,292 seastar - Resultant AIO control block usage:
WARN  2025-10-02 19:06:38,292 seastar - 
WARN  2025-10-02 19:06:38,292 seastar - purpose  per cpu  all 8 cpus
WARN  2025-10-02 19:06:38,292 seastar - -------  -------  ----------
WARN  2025-10-02 19:06:38,292 seastar - reserve                    0
WARN  2025-10-02 19:06:38,292 seastar - storage     1024        8192
WARN  2025-10-02 19:06:38,292 seastar - preempt        2          16
WARN  2025-10-02 19:06:38,292 seastar - network     7166       57328
WARN  2025-10-02 19:06:38,292 seastar - -------  -------  ----------
WARN  2025-10-02 19:06:38,292 seastar - total       8192       65536
WARN  2025-10-02 19:06:38,292 seastar - 
WARN  2025-10-02 19:06:38,292 seastar - For optimal network performance, set /proc/sys/fs/aio-max-nr to at least 88208.
INFO  2025-10-02 19:06:38,293 seastar - Reactor backend: linux-aio
INFO  2025-10-02 19:06:38,298 seastar - Perf-based stall detector creation failed (EACCESS), try setting /proc/sys/kernel/perf_event_paranoid to 1 or less to enable kernel backtraces: falling back to posix timer.
INFO  2025-10-02 19:06:38,310 [shard 0:main] seastar - IO queue was unable to find a suitable maximum request length, the search was cut-off early at: 16MB
INFO  2025-10-02 19:06:38,311 [shard 0:main] seastar - IO queue was unable to find a suitable maximum request length, the search was cut-off early at: 16MB
=== Start Timer hang test
some work is done
has t1 callback
t1 has been cancelled
t2 has been armed
^Cfish: Job 1, 'build/debug/tests/unit/fail_tim…' terminated by signal SIGKILL (Forced quit)

[tgrabiec]

Reproduced. Interestingly, works with --reactor-backend=epoll.

[xemul]

Nice catch

reactor::service_highres_timer() starts
calls timer_set::complete() which expires timers
complete method picks up t1 and calls readd_periodic() on it
read_periodic calls queue_timer which calls timer_set::insert()
timer_set::insert() sets timer_set::_next to t1's timestamp
then t1 callback is called which removes the timer from timer_set and resolves p1
then enable_fn() from service_highres_timer is called which notices that timers are empty and doesn't re-enable highres timer from backend

eventually p1's future is resolved and arms t2
t2::arm() calls reactor::add_timer() which calls reactor::queue_timer() which calls timer_set::insert()
the insert method notices, that _next is left from t2 and returns "false"
reactor::add_timer() does not re-enables highres timer from backend

the fix should be smth like -- when a timer is removed from timer_set and it notices, that it's empty, the _next should be reset to max timestamp

[tgrabiec]

@xemul Are you working on a fix?

the fix should be smth like -- when a timer is removed from timer_set and it notices, that it's empty, the _next should be reset to max timestamp

The contract is violated in enable_fn impl, which should look at _timers.get_next_timeout() rather than _timers.empty().
Clearing _next is an optimization.

[xemul]

Are you working on a fix?

Not yet

The contract is violated in enable_fn impl, which should look at _timers.get_next_timeout() rather than _timers.empty().
Clearing _next is an optimization.

I think it might help here, but it looks wrong. In this test, after t1 callback is executed, if enable_fn() looks at get_next_timeout() it would notice that it's not "max" indeed, and would re-enable hrtimer from backend, but it's wrong, at this point no timers are pending. To fix this issue, at the time t2 is armed, the timer_set::insert() must return 'true' to make queue_timer re-enable hrtimer from backend.

[brain5lug]

You might check if removed timer is _next == get_timestamp(timer). In that rare case you would search for the next timer with the minimal expiration time or set max_timestamp if there are no any.

Also this function seems quite suspicious:

time_point get_next_timeout() const noexcept
{
    return time_point(duration(std::max(_last, _next)));
}

It returns timestamp for the next to be next hardware timer to be set. _last is only set to current time or 0. That means that _last is always outdated for hardware timer to be set.
If the seastar reactor adjusts harware timer for some close time in the future it would adjust it even if it was _next.
If hardware timer fails as it's interface claims it would fail anyway as some time already has been passed since _last has been updated last time.

[brain5lug]

Another possible good option would be in using 0 as invalid value for _next. max_timestamp does match this purpose as it actually a valid value for no timers condition.

1. In that case in case of removal you just set _next with 0 if _next == get_timestamp(timer).
2. Newly added timers check if _next less than current timer and that will be true all the time. So invalid state will saved until the next smallest element selection.
3. Selection of next timer for get_next_timeout() happens as it's required. Once _next re-validated and the next smallest timer selected it can work at worked before.

[tgrabiec]

Are you working on a fix?

Not yet

The contract is violated in enable_fn impl, which should look at _timers.get_next_timeout() rather than _timers.empty().
Clearing _next is an optimization.

I think it might help here, but it looks wrong. In this test, after t1 callback is executed, if enable_fn() looks at get_next_timeout() it would notice that it's not "max" indeed, and would re-enable hrtimer from backend, but it's wrong, at this point no timers are pending. To fix this issue, at the time t2 is armed, the timer_set::insert() must return 'true' to make queue_timer re-enable hrtimer from backend.

I wouldn't say it's wrong, just suboptimal. We will schedule a hrtimer, and when it fires, it will expire no timers, and then rearm to when the queued t2 is about to expire. It's the same case as if t1 was canceled right after complete(), not during it.

[tgrabiec]

You might check if removed timer is _next == get_timestamp(timer). In that rare case you would search for the next timer with the minimal expiration time or set max_timestamp if there are no any.

I don't think it's worth it to optimize for this case. The design goal behind timer_set is to make arming and cancellation cheap, offloading the cost of "sorting" timers to expiration time. Which should be spread in time, because most timers don't fire, they are cancelled. Which is also why the cost of scheduling an hrtimer is amortized.

[brain5lug]

@tgrabiec
Indeed, I now comprehend your point. I merely offered my perspective, assuming we wish to maintain the existing approach. Nevertheless, I believe your expertise will enable you to tackle this issue in the most effective manner 😃
Shouldn't we set a bug label on the issue as it's been already verified?