backoff icon indicating copy to clipboard operation
backoff copied to clipboard

Nesting multiple decorators breaks waiting times

Open martinvol opened this issue 4 years ago • 5 comments

Look at this simple example and notice the waiting times does not increase as expected:

In [23]: def backoff_hdlr(details):
    ...:     print ("Backing off {wait:0.1f} seconds afters {tries} tries "
    ...:            "calling function {target} with args {args} and kwargs "
    ...:            "{kwargs}".format(**details))
    ...:
    ...: @backoff.on_exception(backoff.expo, ValueError,on_backoff=backoff_hdlr)
    ...: @backoff.on_exception(backoff.expo, TypeError,on_backoff=backoff_hdlr)
    ...: def get_url(url):
    ...:     raise ValueError
    ...:
    ...: get_url("")
Backing off 0.8 seconds afters 1 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 1.3 seconds afters 2 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 3.2 seconds afters 3 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 0.5 seconds afters 4 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 2.6 seconds afters 5 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 3.7 seconds afters 6 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 2.3 seconds afters 7 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 90.7 seconds afters 8 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 175.3 seconds afters 9 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 146.8 seconds afters 10 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}
Backing off 479.5 seconds afters 11 tries calling function <function get_url at 0x10a7e2048> with args ('',) and kwargs {}

(see the 0.5 seconds in the 4th log)

If we just leave one exponential backoff now behaves as expected:

In [25]: def backoff_hdlr(details):
    ...:     print ("Backing off {wait:0.1f} seconds afters {tries} tries "
    ...:            "calling function {target} with args {args} and kwargs "
    ...:            "{kwargs}".format(**details))
    ...:
    ...: @backoff.on_exception(backoff.expo, ValueError,on_backoff=backoff_hdlr)
    ...: def get_url(url):
    ...:     raise ValueError
    ...:
    ...: get_url("")
Backing off 0.2 seconds afters 1 tries calling function <function get_url at 0x10a32d620> with args ('',) and kwargs {}
Backing off 0.2 seconds afters 2 tries calling function <function get_url at 0x10a32d620> with args ('',) and kwargs {}
Backing off 2.1 seconds afters 3 tries calling function <function get_url at 0x10a32d620> with args ('',) and kwargs {}
Backing off 4.8 seconds afters 4 tries calling function <function get_url at 0x10a32d620> with args ('',) and kwargs {}
Backing off 10.5 seconds afters 5 tries calling function <function get_url at 0x10a32d620> with args ('',) and kwargs {}

Tested with backoff ==1.8.1 and saw no relevant changes in the changelog since then.

martinvol avatar Jan 27 '20 14:01 martinvol

You are seeing the effect of the default jitter behavior backoff.full_jitter. See documentation here. You can read more here. If you don't want that behavior you can use a different jitter strategy, or pass jitter=None for no jitter at all.

bgreen-litl avatar Jan 27 '20 14:01 bgreen-litl

Thanks a lot for your answer! Should I submit a PR to update this section of the docs?

I find this behavior is not intuitive (at least for me).

martinvol avatar Jan 27 '20 14:01 martinvol

So I think your original report was correct, and I was confused because full_jitter was on. Full jitter can cause the value to go down from one retry to the next, but the behavior your were citing is real independent of jitter.

Here's an example with jitter disabled:

In [7]: @backoff.on_exception(backoff.expo, ValueError, jitter=None) ...: @backoff.on_exception(backoff.expo, KeyError, jitter=None) ...: def foo(calls=[ValueError(), KeyError(), ValueError(), KeyError(), Value ...: Error(), KeyError(), ValueError()]): ...: raise calls.pop() ...:

In [8]: foo() Backing off foo(...) for 1.0s (ValueError) Backing off foo(...) for 1.0s (KeyError) Backing off foo(...) for 2.0s (ValueError) Backing off foo(...) for 1.0s (KeyError) Backing off foo(...) for 4.0s (ValueError) Backing off foo(...) for 1.0s (KeyError) Backing off foo(...) for 8.0s (ValueError)

You can see that each exception type gets its own wait sequence. This is because each decorator defines and instantiates its own wait generator. I think this is probably unavoidable, and probably(?) desirable. Consider if you wanted to do exponential backoff for one type of exception and constant backoff for another.

I think you're right that at the least it could be documented better. At of curiosity, do you have a real world case where you wanted to define different behavior for different exceptions?

bgreen-litl avatar Jan 27 '20 15:01 bgreen-litl

Woah, I just looked at my own at example more carefully and it's weirder than that. The KeyError wait generator is getting reset each time. I think combining decorators doesn't work as neatly as was supposed. :/

bgreen-litl avatar Jan 27 '20 15:01 bgreen-litl

I think you're right that at the least it could be documented better. At of curiosity, do you have a real world case where you wanted to define different behavior for different exceptions?

Yes, just hitting an API and if I get an exception related with bad formatting I don't want to retry, but if I hit any other exception I want to back off exponentially.

martinvol avatar Jan 27 '20 15:01 martinvol