Flaky failures in tests/test_context_decorator.py::test_ratelimit__delay_synchronous
Closed this issue · 7 comments
Thanks for your work in #99! In 2.9.1, I still see some flaky test failures in tests/test_context_decorator.py::test_ratelimit__delay_synchronous. Sometimes the tests all pass, but in one run I got:
=================================== FAILURES ===================================
________________ test_ratelimit__delay_synchronous[monotonic0] _________________
[gw4] linux -- Python 3.11.2 /usr/bin/python3
time_function = <built-in function monotonic>
def test_ratelimit__delay_synchronous(time_function):
"""Test ratelimit decorator with automatic delays - synchronous version"""
limiter = Limiter(RequestRate(10, Duration.SECOND), time_function=time_function)
@limiter.ratelimit(uuid4(), delay=True)
def limited_function():
pass
# This should insert appropriate delays to stay within the rate limit
start = time()
for _ in range(22):
limited_function()
# Exact time will depend on the test environment, but it should be slightly more than 2 seconds
elapsed = time() - start
> assert 2 < elapsed <= 3
E assert 2 < 1.9996354579925537
tests/test_context_decorator.py:55: AssertionError
___________________ test_ratelimit__delay_synchronous[time0] ___________________
[gw4] linux -- Python 3.11.2 /usr/bin/python3
time_function = <built-in function time>
def test_ratelimit__delay_synchronous(time_function):
"""Test ratelimit decorator with automatic delays - synchronous version"""
limiter = Limiter(RequestRate(10, Duration.SECOND), time_function=time_function)
@limiter.ratelimit(uuid4(), delay=True)
def limited_function():
pass
# This should insert appropriate delays to stay within the rate limit
start = time()
for _ in range(22):
limited_function()
# Exact time will depend on the test environment, but it should be slightly more than 2 seconds
elapsed = time() - start
> assert 2 < elapsed <= 3
E assert 2 < 1.9997384548187256
tests/test_context_decorator.py:55: AssertionError
=========================== short test summary info ============================
FAILED tests/test_context_decorator.py::test_ratelimit__delay_synchronous[monotonic0]
FAILED tests/test_context_decorator.py::test_ratelimit__delay_synchronous[time0]
======================== 2 failed, 92 passed in 49.51s =========================
…and in another:
=================================== FAILURES ===================================
_________________ test_ratelimit__delay_synchronous[<lambda>1] _________________
[gw7] linux -- Python 3.11.2 /usr/bin/python3
time_function = <function <lambda> at 0x7f922b5d8540>
def test_ratelimit__delay_synchronous(time_function):
"""Test ratelimit decorator with automatic delays - synchronous version"""
limiter = Limiter(RequestRate(10, Duration.SECOND), time_function=time_function)
@limiter.ratelimit(uuid4(), delay=True)
def limited_function():
pass
# This should insert appropriate delays to stay within the rate limit
start = time()
for _ in range(22):
limited_function()
# Exact time will depend on the test environment, but it should be slightly more than 2 seconds
elapsed = time() - start
> assert 2 < elapsed <= 3
E assert 2 < 1.9994311332702637
tests/test_context_decorator.py:55: AssertionError
=========================== short test summary info ============================
FAILED tests/test_context_decorator.py::test_ratelimit__delay_synchronous[<lambda>1]
======================== 1 failed, 93 passed in 29.77s =========================
The discrepancies are tiny, but something is still not quite right.
@musicinmybrain That's quite strange since I got a very stable test result, running like few tens of time already. Anyway, can you try change this line
to below and rerun the test?
delay_time = err.meta_info["remaining_time"]I have run the tests 100+ times already and nothing happened, so for now let's leave this issue open until we have more people reporting this matter and I will go back to it
@musicinmybrain That's quite strange since I got a very stable test result, running like few tens of time already. Anyway, can you try change this line to below and rerun the test?
delay_time = err.meta_info["remaining_time"]
On the first attempt:
=================================== FAILURES ===================================
___________________ test_ratelimit__delay_synchronous[None0] ___________________
[gw15] linux -- Python 3.11.2 /usr/bin/python3
time_function = None
def test_ratelimit__delay_synchronous(time_function):
"""Test ratelimit decorator with automatic delays - synchronous version"""
limiter = Limiter(RequestRate(10, Duration.SECOND), time_function=time_function)
@limiter.ratelimit(uuid4(), delay=True)
def limited_function():
pass
# This should insert appropriate delays to stay within the rate limit
start = time()
for _ in range(22):
limited_function()
# Exact time will depend on the test environment, but it should be slightly more than 2 seconds
elapsed = time() - start
> assert 2 < elapsed <= 3
E assert 2 < 1.999417781829834
tests/test_context_decorator.py:55: AssertionError
___________________ test_ratelimit__delay_synchronous[None1] ___________________
[gw6] linux -- Python 3.11.2 /usr/bin/python3
time_function = None
def test_ratelimit__delay_synchronous(time_function):
"""Test ratelimit decorator with automatic delays - synchronous version"""
limiter = Limiter(RequestRate(10, Duration.SECOND), time_function=time_function)
@limiter.ratelimit(uuid4(), delay=True)
def limited_function():
pass
# This should insert appropriate delays to stay within the rate limit
start = time()
for _ in range(22):
limited_function()
# Exact time will depend on the test environment, but it should be slightly more than 2 seconds
elapsed = time() - start
> assert 2 < elapsed <= 3
E assert 2 < 1.9994351863861084
tests/test_context_decorator.py:55: AssertionError
=========================== short test summary info ============================
FAILED tests/test_context_decorator.py::test_ratelimit__delay_synchronous[None0]
FAILED tests/test_context_decorator.py::test_ratelimit__delay_synchronous[None1]
======================== 2 failed, 92 passed in 29.77s =========================
For now, we’re just skipping this test in Fedora Linux.
I have run the tests 100+ times already and nothing happened, so for now let's leave this issue open until we have more people reporting this matter and I will go back to it
I suppose there is something platform-dependent going on here.
At least the discrepancy is tiny; the test failure is an annoyance, but it looks like the library is working correctly enough in practice.
Seems this failure happens because of this line in Limiter.try_acquire:
now = round(self.time_function(), 3)
So if the test happens to start at 0.000999 (for example), Limiter actually thinks that it started at 0.000000 exactly, thus sneaking in an extra millisecond. (your machine also needs to be fast enough to run through all the code in less than a millisecond)
I think that we can safely reduce lower limit on the test to 1.999. Tested for 512 times on my machine - never fails (previously was failing every ~10 times)
Or, alternatively, we can do round(time(), 3) in the test as well.
I'm working on the next major release with a lot of improvements so there wont be more update to the current version.
Close as this is outdated