due_at date calculation appears to be incorrect

[simonk52]

The RedBeatSchedulerEntry.due_at function appears to be incorrect. Here's the definition:

redbeat/redbeat/schedulers.py

Lines 251 to 266 in 82110c5

	@property
	def due_at(self):
	# never run => due now
	if self.last_run_at is None:
	return self._default_now()
	delta = self.schedule.remaining_estimate(self.last_run_at)
	# if no delta, means no more events after the last_run_at.
	if delta is None:
	return None
	# overdue => due now
	if delta.total_seconds() < 0:
	return self._default_now()
	return self.last_run_at + delta

self.schedule.remaining_estimate returns the number of seconds until the task is due, counting from the current time, but the function ends up adding that delta to self.last_run_at.

Here's a test demonstrating the problem:

import datetime as dt
import mock
import pytz
from celery import schedules
import redbeat.schedulers as redbeat


def test_due_at():
    # pretend it is 2021-09-01 00:45:00 and we have an hourly task
    # that last ran at midnight
    now = dt.datetime(2021, 9, 1, 0, 45, 0, tzinfo=pytz.utc)
    schedule = schedules.schedule(
        run_every=3600,
        nowfun=lambda: now,
    )
    last_run_at = dt.datetime(2021, 9, 1, 0, 0, 0, tzinfo=pytz.utc)

    # there should be 15 minutes remaining. This assertion succeeds.
    expected_remaining = 15 * 60
    assert schedule.is_due(last_run_at) == (False, expected_remaining)

    entry = redbeat.RedBeatSchedulerEntry(
        app=mock.Mock(),
        schedule=schedule,
        last_run_at=last_run_at,
    )

    remaining = entry.schedule.remaining_estimate(entry.last_run_at)
    assert remaining == dt.timedelta(seconds=expected_remaining)

    # the entry should be due at 1am. This assertion fails. The acual
    # return value is 2021-09-01 00:15:00, ie. the 15-minute delta has
    # been added to last_run_at rather than the current time.
    assert entry.due_at == dt.datetime(2021, 9, 1, 1, 0, 0, tzinfo=pytz.utc)

[sibson]

good catch, what would you propose to fix?

[simonk52]

In my code I've monkeypatched RedBeatSchedulerEntry with this:

def due_at(self):
    # never run => due now
    if self.last_run_at is None:
        return self._default_now()

    delta = self.schedule.remaining_estimate(self.last_run_at)
    # if no delta, means no more events after the last_run_at.
    if delta is None:
        return None

    # overdue => due now
    if delta.total_seconds() < 0:
        return self._default_now()

    return self.default_now() + delta

ie. just changing the last line to use self.default_now() instead of self.last_run_at. It seems to work, but I confess that I haven't tried running the redbeat tests with that change :-)

[jlaine]

I think I might be getting bitten by this, I run very frequent periodic tasks (i.e. every couple of seconds) and occasionally tasks stop kicking off for exactly 5mn, which looks suspiciously like the default beat_max_loop_interval.

Applying the change suggested by @simonk52 definitely breaks the test suite, specifically tests.test_entry.test_RedBeatEntry.test_due_at.

[ziptnf]

@sibson is there a plan to fix this anytime soon? This seems fairly fixable as per @simonk52 's monkeypatch.