-
Notifications
You must be signed in to change notification settings - Fork 564
Fix flaky 3PID inhibit error unit tests #19913
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
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1 @@ | ||
| Fix a flake in 3PID inhibit error unit tests, causing occasional failures in CI. |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -325,7 +325,13 @@ def test_password_reset_bad_email_inhibit_error(self) -> None: | |
| email = "test@example.com" | ||
|
|
||
| client_secret = "foobar" | ||
| session_id = self._request_token(email, client_secret) | ||
| session_id = self._request_token( | ||
| email, | ||
| client_secret, | ||
| # The endpoint intentionally adds up to 1000ms of jitter to avoid | ||
| # leaking whether the email address is bound to an account. | ||
| timeout_ms=3000, | ||
| ) | ||
|
|
||
| self.assertIsNotNone(session_id) | ||
|
|
||
|
|
@@ -364,6 +370,7 @@ def _request_token( | |
| client_secret: str, | ||
| ip: str = "127.0.0.1", | ||
| next_link: str | None = None, | ||
| timeout_ms: int = 1000, | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. We can use the
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Why
Member
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The reasoning was that the jitter was an edge case that only applied to this endpoint, and thus these tests.
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
|
||
| ) -> str: | ||
| body = {"client_secret": client_secret, "email": email, "send_attempt": 1} | ||
| if next_link is not None: | ||
|
|
@@ -373,6 +380,7 @@ def _request_token( | |
| b"account/password/email/requestToken", | ||
| body, | ||
| client_ip=ip, | ||
| timeout_ms=timeout_ms, | ||
| ) | ||
|
|
||
| if channel.code != 200: | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -371,6 +371,7 @@ def make_request( | |
| await_result: bool = True, | ||
| custom_headers: Iterable[CustomHeaderType] | None = None, | ||
| client_ip: str = "127.0.0.1", | ||
| timeout_ms: int = 1000, | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Historically, we instead used this pattern: channel = self.make_request(
"GET",
f"/_matrix/media/r0/thumbnail/{self.media_id}{params}",
await_result=False,
)
channel.await_result(timeout_ms=1000)The new shortcut doesn't seem bad though. |
||
| ) -> FakeChannel: | ||
| """ | ||
| Make a web request using the given method, path and content, and render it | ||
|
|
@@ -399,6 +400,8 @@ def make_request( | |
| custom_headers: (name, value) pairs to add as request headers | ||
| client_ip: The IP to use as the requesting IP. Useful for testing | ||
| ratelimiting. | ||
| timeout_ms: if `await_result` is `True`, the amount of time to wait on | ||
| the request before timing out. Ignored otherwise. | ||
|
|
||
| Returns: | ||
| channel | ||
|
|
@@ -483,7 +486,7 @@ def make_request( | |
| req.requestReceived(method, path, b"1.1") | ||
|
|
||
| if await_result: | ||
| channel.await_result() | ||
| channel.await_result(timeout_ms=timeout_ms) | ||
|
|
||
| return channel | ||
|
|
||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not understanding the logic behind 3000ms?
Uh oh!
There was an error while loading. Please reload this page.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This should actually be fine with 1000ms (the default).
The only reason it's not is because
await_result(...)is a bit flaky. For example, the firstadvance(0.1)inawait_result(...)triggers any scheduled work (like databaseThreadPoolqueries as part of the request), then the 1000ms jitter sleep starts, butawait_result(...)can give up after another 0.9s (still 1s total but 0.1s short of the sleep finishing). This edge case happens when the floating point math satisfiesself._reactor.seconds() > end_timeone iteration early so it waits exactly 1s (10 iterations). The normal case (when everything passes) is because it gets an extraself._reactor.advance(0.1)iteration (11 iterations -> waits 1.1s).To make it more clear, here is how we could manually drive this to completion reliably:
(
test_request_token_existing_email_inhibit_errorintests/rest/client/test_register.py)Related to #19394 (comment) and #19734 (comment)
I think a better fix would be to update
await_result(...)toself._reactor.advance(0)before it starts its loop. This way, we don't burn any reactor advance time on things that are actually scheduled now (get rid of the foot-guns).I'm working on improving
FakeChannel.await_result(...)in #19879 so I'll include the fix there ⏩Overall, I think this PR should probably be reverted. We could still benefit from the comments pointing out the jitter here though.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for diving in deep here! That makes sense, I didn't consider that other work could be delaying the response before the jitter even started.
I noticed that the fix was included in #19879, and the PR has now merged. Nice!
I agree that we no longer need to mess with the timeout in tests if
await_resultacts as expected, and actually it may be a bad smell to encourage tests to do so (leading to overzealous delays in unit tests). Happy to revert this PR minus the jitter comments.It was just an arbitrarily higher value to get substantially far away from 1000ms.