zilencer: Log warning when a remote server hits rate limits.

We don't want this rate limit to affect legitimate users so it being hit
should be abnormal - thus worth logging so that we can spot if we're
rate limiting legitimate users and can know to increase the limit.
This commit is contained in:
Mateusz Mandera 2021-07-08 15:33:15 +02:00 committed by Tim Abbott
parent 85cbdc8904
commit 093ca7a574
2 changed files with 18 additions and 3 deletions

View File

@ -38,7 +38,7 @@ from zerver.lib.exceptions import (
UserDeactivatedError, UserDeactivatedError,
) )
from zerver.lib.queue import queue_json_publish from zerver.lib.queue import queue_json_publish
from zerver.lib.rate_limiter import RateLimitedIPAddr, RateLimitedUser from zerver.lib.rate_limiter import RateLimited, RateLimitedIPAddr, RateLimitedUser
from zerver.lib.request import REQ, has_request_variables from zerver.lib.request import REQ, has_request_variables
from zerver.lib.response import json_method_not_allowed, json_success, json_unauthorized from zerver.lib.response import json_method_not_allowed, json_success, json_unauthorized
from zerver.lib.subdomains import get_subdomain, user_matches_subdomain from zerver.lib.subdomains import get_subdomain, user_matches_subdomain
@ -54,6 +54,8 @@ if settings.ZILENCER_ENABLED:
get_remote_server_by_uuid, get_remote_server_by_uuid,
) )
rate_limiter_logger = logging.getLogger("zerver.lib.rate_limiter")
webhook_logger = logging.getLogger("zulip.zerver.webhooks") webhook_logger = logging.getLogger("zulip.zerver.webhooks")
webhook_unsupported_events_logger = logging.getLogger("zulip.zerver.webhooks.unsupported") webhook_unsupported_events_logger = logging.getLogger("zulip.zerver.webhooks.unsupported")
@ -858,7 +860,13 @@ def rate_limit_ip(request: HttpRequest, ip_addr: str, domain: str) -> None:
def rate_limit_remote_server( def rate_limit_remote_server(
request: HttpRequest, remote_server: "RemoteZulipServer", domain: str request: HttpRequest, remote_server: "RemoteZulipServer", domain: str
) -> None: ) -> None:
try:
RateLimitedRemoteZulipServer(remote_server, domain=domain).rate_limit_request(request) RateLimitedRemoteZulipServer(remote_server, domain=domain).rate_limit_request(request)
except RateLimited as e:
rate_limiter_logger.warning(
"Remote server %s exceeded rate limits on domain %s", remote_server, domain
)
raise e
def rate_limit() -> Callable[[ViewFuncT], ViewFuncT]: def rate_limit() -> Callable[[ViewFuncT], ViewFuncT]:

View File

@ -192,7 +192,14 @@ class RateLimitTests(ZulipTestCase):
self.DEFAULT_SUBDOMAIN = "" self.DEFAULT_SUBDOMAIN = ""
RateLimitedRemoteZulipServer(server).clear_history() RateLimitedRemoteZulipServer(server).clear_history()
with self.assertLogs("zerver.lib.rate_limiter", level="WARNING") as m:
self.do_test_hit_ratelimits(lambda: self.uuid_post(server_uuid, endpoint, payload)) self.do_test_hit_ratelimits(lambda: self.uuid_post(server_uuid, endpoint, payload))
self.assertEqual(
m.output,
[
"WARNING:zerver.lib.rate_limiter:Remote server <RemoteZulipServer demo.example.com 1234-abcd> exceeded rate limits on domain api_by_remote_server"
],
)
finally: finally:
self.DEFAULT_SUBDOMAIN = original_default_subdomain self.DEFAULT_SUBDOMAIN = original_default_subdomain
remove_ratelimit_rule(1, 5, domain="api_by_remote_server") remove_ratelimit_rule(1, 5, domain="api_by_remote_server")