backoff icon indicating copy to clipboard operation
backoff copied to clipboard

Async operation invoked prior to backoff delay

Open ramosbugs opened this issue 3 years ago • 1 comments

Thanks for this useful crate!

I ran into some unexpected behavior around the timing of retries and finally got to the bottom of it. When a transient error occurs, backoff::future::Retry sets the sleeper delay but then immediately invokes the operation function, without waiting for the delay to elapse: https://github.com/ihrwein/backoff/blob/587e2da8fb2dcfc65ca544cb9249022c51f1406e/src/future.rs#L189-L192

The future returned by the operation doesn't get polled until after the delay has elapsed, but simply invoking the operation function may be sufficient for the relevant operation (e.g., a DB query) to be initiated. In my case, I observed that a DB operation was completing prior to the backoff delay elapsing, when it shouldn't have even been initiated at that point.

Whether this causes a problem depends on the structure of the operation function. If the whole thing is wrapped in an async { ... } block, then it appears that the code doesn't get executed until the first poll, which is after the backoff delay. However, if the function executes some code and then returns a future, the operation will start immediately, in parallel with the backoff delay.

My suggestion is to defer the invocation of this.operation until after the backoff delay elapses, or at least to document this nuance :-)

ramosbugs avatar Aug 26 '22 21:08 ramosbugs

Here's a visual illustration of the issue from a Honeycomb trace: Screen Shot 2022-08-26 at 2 45 13 PM

Notice the delay of about 17s following the final attempt (which returned Error::Permanent). The timing bar at the top represents the span of the entire call to retry().

ramosbugs avatar Aug 26 '22 21:08 ramosbugs