Merge pull request #44 from a-luna:improve-rate-limit-log-messages_20…

…240423

Improve log messages for rate limit decisions

app/core/rate_limit.py

@@ -1,6 +1,6 @@
 import logging
 import re
-from dataclasses import dataclass
+from dataclasses import dataclass, field
 from datetime import timedelta
 
 from fastapi import Request
@@ -25,26 +25,26 @@ class RateLimitDecision:
     arrived_at: float
     allowed_at: float
     new_tat: float
+    logger: logging.Logger = field(init=False)
 
-    def log(self) -> None:
-        decision = (
-            "RATE LIMIT DECISION:  "
-            f"(IP: {self.ip})  "
-            f"(Allowed: {self.arrived_at >= self.allowed_at})  "
-            f"(Arrived At: {get_time_portion(self.arrived_at)})  "
-            f"(Allowed At: {get_time_portion(self.allowed_at)})  "
-        )
-        if self.arrived_at < self.allowed_at:
-            limit_duration = get_duration_between_timestamps(self.arrived_at, self.allowed_at)
-            decision += f"({format_timedelta_str(limit_duration, precise=True)} Until Next Request Allowed)"
+    def __post_init__(self):
+        self.logger = logging.getLogger("app.api")
 
+    def log(self) -> None:
+        allowed = self.arrived_at >= self.allowed_at
+        self.logger.info(f'##### {"REQUEST ALLOWED" if allowed else "REQUEST DENIED"} #####')
+        self.logger.info(f"Request From...: {self.ip}")
+        self.logger.info(f"Arrived At.....: {get_time_portion(self.arrived_at)}")
+        self.logger.info(f"Allowed At.....: {get_time_portion(self.allowed_at)}")
+        if allowed:
+            new_tat = get_time_portion(self.new_tat)
+            dur_until_limit = get_duration_between_timestamps(self.allowed_at, self.arrived_at)
+            time_until_limit = format_timedelta_str(dur_until_limit, precise=True)
+            self.logger.info(f"New TAT........: {new_tat}, ({time_until_limit} from now)")
         else:
-            time_until_limit = get_duration_between_timestamps(self.allowed_at, self.arrived_at)
-            decision += (
-                f"(New TAT: {get_time_portion(self.new_tat)}, "
-                f"{format_timedelta_str(time_until_limit, precise=True)} from now)"
-            )
-        logging.getLogger("app.api").info(decision)
+            dur_limit_remaining = get_duration_between_timestamps(self.arrived_at, self.allowed_at)
+            time_limit_remaining = format_timedelta_str(dur_limit_remaining, precise=True)
+            self.logger.info(f"Limit Expires..: {time_limit_remaining}")
 
 
 class RateLimit:
@@ -96,7 +96,7 @@ def is_exceeded(self, request: Request) -> Result[None]:
                 new_tat = self.get_new_tat(tat, arrived_at)
                 RateLimitDecision(client_ip, arrived_at, allowed_at, new_tat).log()
                 self.redis.set(client_ip, new_tat)
-                return self.request_allowed(client_ip)
+                return Result.Ok()
         except LockError:  # pragma: no cover
             return self.lock_error(client_ip)
 
@@ -114,17 +114,13 @@ def get_new_tat(self, tat: float, arrived_at: float) -> float:
     def rate_limit_exceeded(self, client, allowed_at: float) -> Result[None]:
         limit_duration = get_time_until_timestamp(allowed_at)
         burst = f" (+{self.burst} request burst allowance)" if self.burst > 1 else ""
-        error = (
+        detail = (
             f"API rate limit of {self.rate} requests{burst} in {round(self.period_seconds, 1)} "
-            f"second{'s' if self.period_seconds > 1 else ''} exceeded for IP {client}, "
+            f"second{s(self.period_seconds)} exceeded for IP {client}, "
             f"{format_timedelta_str(limit_duration, precise=True)} until limit is removed"
         )
-        self.logger.info(error)
-        return Result.Fail(error)
-
-    def request_allowed(self, client) -> Result[None]:
-        self.logger.info(f"Request allowed for IP: {client}")
-        return Result.Ok()
+        self.logger.debug(detail)
+        return Result.Fail(detail)
 
     def lock_error(self, client) -> Result[None]:  # pragma: no cover
         error = (
@@ -153,12 +149,18 @@ def request_origin_is_external(request: Request) -> bool:  # pragma: no cover
     return True
 
 
-def requested_route_is_rate_limited(request: Request):  # pragma: no cover
-    return RATE_LIMIT_ROUTE_REGEX.search(request.url.path)
+def requested_route_is_rate_limited(request: Request) -> bool:  # pragma: no cover
+    return bool(RATE_LIMIT_ROUTE_REGEX.search(request.url.path))
 
 
 def get_time_portion(ts: float) -> str:
     return dtaware_fromtimestamp(ts).time().strftime("%I:%M:%S.%f %p")
 
 
+def s(x: list | int | float) -> str:
+    if isinstance(x, list):
+        return "s" if len(x) > 1 else ""
+    return "s" if x > 1 else ""
+
+
 rate_limit = RateLimit(redis)

app/data/scripts/sync_req_files.py

@@ -15,7 +15,7 @@ def sync_requirements_files(project_dir: Path):
 
     if (req_base := project_dir.joinpath("requirements.txt")).exists():
         update_req_file(req_base, pinned_versions)
-    if (req_dev := project_dir.joinpath("requirements.txt")).exists():
+    if (req_dev := project_dir.joinpath("requirements-dev.txt")).exists():
         update_req_file(req_dev, pinned_versions)
     return Result.Ok()
 
@@ -37,10 +37,10 @@ def create_lock_file(project_dir: Path) -> Result[Path]:
 
 
 def parse_lock_file(req_file: Path) -> dict[str, str]:
-    return dict(parsed for s in req_file.read_text().splitlines() if (parsed := parse_installed_package(s)))
+    return dict(pkg for line in req_file.read_text().splitlines() if (pkg := parse_lock_file_entry(line)))
 
 
-def parse_installed_package(req: str) -> tuple[str, str] | None:
+def parse_lock_file_entry(req: str) -> tuple[str, str] | None:
     match = REQ_REGEX.match(req)
     if not match:
         return None

requirements-dev.txt

@@ -1,19 +1,19 @@
-black==24.2.0
-coverage==7.4.1
-ipython==8.22.2
+black==24.4.0
+coverage==7.4.4
+ipython==8.23.0
 isort==5.13.2
-mypy==1.8.0
+mypy==1.9.0
 pip-upgrader==1.4.15
-pytest==8.0.0
+pytest==8.1.1
 pytest-black==0.3.12
 pytest-clarity==1.0.1
-pytest-cov==4.1.0
+pytest-cov==5.0.0
 pytest-dotenv==0.5.2
-pytest-mock==3.12.0
+pytest-mock==3.14.0
 pytest-random-order==1.1.1
 pytest-sugar==1.0.0
-pyupgrade==3.15.0
-ruff==0.2.1
+pyupgrade==3.15.2
+ruff==0.4.1
 snoop==0.4.3
-tox==4.12.1
+tox==4.14.2
 trogon==0.5.0

requirements-lock.txt

@@ -1,112 +1,112 @@
-aiohttp==3.9.3
+aiohttp==3.9.5
 aiosignal==1.3.1
 annotated-types==0.6.0
-anyio==4.2.0
+anyio==4.3.0
 appnope==0.1.4
 asttokens==2.4.1
 async-timeout==4.0.3
 attrs==23.2.0
 backcall==0.2.0
-black==24.2.0
-cachetools==5.3.2
+black==24.4.0
+cachetools==5.3.3
 certifi==2024.2.2
 chardet==5.2.0
 charset-normalizer==3.3.2
 cheap-repr==0.5.1
 click==8.1.7
 colorama==0.4.6
 colorclass==2.2.2
-coverage==7.4.1
+coverage==7.4.4
 decorator==5.1.1
 distlib==0.3.8
 docopt==0.6.2
-exceptiongroup==1.2.0
+exceptiongroup==1.2.1
 executing==2.0.1
-fakeredis==2.21.1
-fastapi==0.109.2
-filelock==3.13.3
+fakeredis==2.22.0
+fastapi==0.110.2
+filelock==3.13.4
 frozenlist==1.4.1
 h11==0.14.0
 halo==0.0.31
-httpcore==1.0.3
-httpx==0.26.0
-idna==3.6
-importlib-metadata==7.0.1
+httpcore==1.0.5
+httpx==0.27.0
+idna==3.7
+importlib_metadata==7.1.0
 iniconfig==2.0.0
-ipython==8.19.0
+ipython==8.23.0
 isort==5.13.2
 jedi==0.19.1
 linkify-it-py==2.0.3
 log-symbols==0.0.14
 lupa==2.1
-lxml==5.1.0
+lxml==5.2.1
 markdown-it-py==3.0.0
-matplotlib-inline==0.1.6
+matplotlib-inline==0.1.7
 mdit-py-plugins==0.4.0
 mdurl==0.1.2
 multidict==6.0.5
-mypy==1.8.0
+mypy==1.9.0
 mypy-extensions==1.0.0
-packaging==23.2
-parso==0.8.3
+packaging==24.0
+parso==0.8.4
 pathspec==0.12.1
 pexpect==4.9.0
 pickleshare==0.7.5
 pip-upgrader==1.4.15
 platformdirs==4.2.0
-pluggy==1.4.0
+pluggy==1.5.0
 pprintpp==0.4.0
 prompt-toolkit==3.0.43
 ptyprocess==0.7.0
 pure-eval==0.2.2
-pydantic==2.6.1
-pydantic_core==2.16.2
+pydantic==2.7.0
+pydantic_core==2.18.1
 Pygments==2.17.2
 pyproject-api==1.6.1
-pytest==8.0.0
+pytest==8.1.1
 pytest-black==0.3.12
 pytest-clarity==1.0.1
 pytest-cov==5.0.0
 pytest-dotenv==0.5.2
-pytest-mock==3.12.0
+pytest-mock==3.14.0
 pytest-random-order==1.1.1
 pytest-sugar==1.0.0
-python-dateutil==2.8.2
+python-dateutil==2.9.0
 python-dotenv==1.0.1
 pyupgrade==3.15.2
-rapidfuzz==3.7.0
-redis==5.0.1
+rapidfuzz==3.8.1
+redis==5.0.3
 requests==2.31.0
-rich==13.7.0
-ruff==0.2.1
+rich==13.7.1
+ruff==0.4.1
 six==1.16.0
-sniffio==1.3.0
+sniffio==1.3.1
 snoop==0.4.3
 sortedcontainers==2.4.0
 spinners==0.0.24
 SQLAlchemy==2.0.29
 SQLAlchemy-Utils==0.41.2
 sqlalchemy2-stubs==0.0.2a37
-sqlmodel==0.0.14
+sqlmodel==0.0.16
 stack-data==0.6.3
-starlette==0.36.3
+starlette==0.37.2
 termcolor==2.4.0
 terminaltables==3.1.10
-textual==0.51.0
+textual==0.57.1
 tokenize-rt==5.2.0
 toml==0.10.2
 tomli==2.0.1
-tox==4.12.1
-traitlets==5.14.1
-tree-sitter==0.20.4
+tox==4.14.2
+traitlets==5.14.3
+tree-sitter==0.21.3
 tree-sitter-languages==1.10.2
 trogon==0.5.0
-typing_extensions==4.9.0
+typing_extensions==4.11.0
 uc-micro-py==1.0.3
-urllib3==2.2.0
-uvicorn==0.27.1
-virtualenv==20.25.0
+urllib3==2.2.1
+uvicorn==0.29.0
+virtualenv==20.25.3
 watchfiles==0.21.0
 wcwidth==0.2.13
 yarl==1.9.4
-zipp==3.17.0
+zipp==3.18.1

requirements.txt

@@ -1,17 +1,17 @@
 click==8.1.7
-fakeredis==2.21.1
-fastapi==0.109.2
+fakeredis==2.22.0
+fastapi==0.110.2
 halo==0.0.31
-httpx==0.26.0
+httpx==0.27.0
 lupa==2.1
-lxml==5.1.0
-pydantic==2.6.1
-python-dateutil==2.8.2
-rapidfuzz==3.7.0
-redis==5.0.1
+lxml==5.2.1
+pydantic==2.7.0
+python-dateutil==2.9.0
+rapidfuzz==3.8.1
+redis==5.0.3
 requests==2.31.0
 SQLAlchemy==2.0.29
 SQLAlchemy-Utils==0.41.2
-sqlmodel==0.0.14
-uvicorn==0.27.1
+sqlmodel==0.0.16
+uvicorn==0.29.0
 watchfiles==0.21.0