Duplicate callbacks from ioLoop.PeriodicCallback

[DavidEwing]

Was occasionally seeing multiple callback invocations in a single PeriodicCallback interval.
The problem is with the _schedule_next() function. On a fast machine, the current_time can be equal to the _next_timeout!

The fix in PeriodicCallback._schedule_next() is to change:

     while self._next_timeout < current_time:

to:

     while self._next_timeout <= current_time:

[bdarnell]

I'm sorry, can you explain the problematic scenario in a little more detail? If current_time is equal to _next_timeout, why shouldn't it run the callback again immediately? Is this a problem with the resolution of time.time()?

[DavidEwing]

Yes, if time.time() had infinite resolution then this wouldn't be a problem. But at least on some systems, successive calls to time.time() will return equal values. So the problematic scenario is as follows:
Immediately after a callback is run, the _schedule_next method is invoked. The purpose of _schedule_next is to advance _next_timeout. However, if the callback ran quickly, the previous value of _next_timeout will be equal to current_time. As the code stands, this will cause the callback to be scheduled for immediate re-execution. In other words, the increment is skipped and the old value of _next_timeout will be re-queued. For example, I have a simple PeriodicCallback scheduled at a 5 second interval, but occasionally it fires multiple times in rapid succession, separated by "zero" seconds!

[bdarnell]

I'll make this change, since time.time() isn't always accurate to the microsecond, but 5 seconds is an awfully long time. If you're seeing a 5 second PeriodicCallback run into this issue, the problem is something more than just a lack of resolution. Maybe NTP adjustments, or something related to virtualization?

[DavidEwing]

Really it's independent of the interval. The issue is that time.time() returns the same value twice if you call it really quickly, e.g. on a fast machine with a callback that doesn't do much processing. The 'callback_time' interval never comes into play, since the while loop bypasses incrementing when time.time() didn't change.

[bdarnell]

Ah, I see now. Thanks for the explanation. What platform are you seeing this on, by the way?

[DavidEwing]

Was afraid you'd ask ;) I've only seen this problem on our Windows XP
development machines. We deploy on embedded ARM Linux as well as on Ubuntu
servers, and I don't think I've seen this issue on either of those
platforms.

On Tue, Oct 4, 2011 at 11:04 AM, bdarnell <
reply@reply.github.com>wrote:

Ah, I see now. Thanks for the explanation. What platform are you seeing
this on, by the way?

Reply to this email directly or view it on GitHub:
#366 (comment)