Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Async operation invoked prior to backoff delay #58

Open
ramosbugs opened this issue Aug 26, 2022 · 1 comment
Open

Async operation invoked prior to backoff delay #58

ramosbugs opened this issue Aug 26, 2022 · 1 comment

Comments

@ramosbugs
Copy link

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:

backoff/src/future.rs

Lines 189 to 192 in 587e2da

this.delay.set(OptionPinned::Some {
inner: this.sleeper.sleep(duration),
});
this.fut.set((this.operation)());

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
Copy link
Author

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().

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant