Handle new error message when challenging bots (lichess-bot-devs#1137)

* Handle new error message when challenging bots

Reference issue: lichess-bot-devs#1135

Detect when the rate limiting status code (429) is due to issuing more
than 100 challenges in a day. The change to matchmaking prevents adding
other bots to the block list in case the error is due to this rate
limit.

* Remove tracking of daily challenges

The purpose of tracking daily challenges was to slow down the issuing of
challenges when the rate limit of 400/day was being approached. However,
now that the number of games is limited to 100/day (whether the bot
issues or receives the challenge), this tracking is redundant.

The rate at which challenges are issued is now entirely controlled by
the matchmaking: challenge_timeout configuration, which specifies how
long after a game ends to issue a new challenge.

* Remove unneeded Timer attributes

Now that challenge times aren't recorded, there's no need for backdated
Timers or the recording of when a Timer was created.

* Delete unused type

* Put daily game limit info in user messages

Put the rate-limit timeout into the RateLimitedError exception so other parts of the program can use it.

Add a rate-limit Timer to the Matchmaking class so that the user's logs aren't fill with rate-limited messages. Also, change the format of the "Next challenge will be created after" message to include the date since the delay may last into the next day.

* Put back Matchmaking.min_wait_time

This serves as a general rate limit on challenges and is still useful.

* Undo unneeded parenthesis move

* Handle daily game limit on first failed challenge

Create a function to handle the daily game limit. Update types to
accomodate the response error message.

* Update wiki regarding daily bot game limits

Author: MarkZH

lib/lichess.py

@@ -61,6 +61,11 @@ def __init__(self) -> None:
 class RateLimitedError(RuntimeError):
     """Exception raised when we are rate limited (status code 429)."""
 
+    def __init__(self, message: str, timeout: datetime.timedelta) -> None:
+        """Create a rate-limited error with the time left until the rate limit expires."""
+        super().__init__(message)
+        self.timeout = timeout
+
 
 def is_new_rate_limit(response: requests.models.Response) -> bool:
     """Check if the status code is 429, which means that we are rate limited."""
@@ -236,7 +241,17 @@ def api_post(self,
         response = self.session.post(url, data=data, headers=headers, params=params, json=payload, timeout=2)
 
         if is_new_rate_limit(response):
-            self.set_rate_limit_delay(path_template, seconds(60))
+            delay = seconds(60)
+            try:
+                if endpoint_name == "challenge":
+                    body = response.json()
+                    rate_limit = body.get("ratelimit", {})
+                    key = rate_limit.get("key", "")
+                    if key == "bot.vsBot.day":
+                        delay = seconds(rate_limit["seconds"])
+            except requests.exceptions.JSONDecodeError:
+                pass
+            self.set_rate_limit_delay(path_template, delay)
 
         if raise_for_status:
             response.raise_for_status()
@@ -254,7 +269,8 @@ def get_path_template(self, endpoint_name: str) -> str:
         path_template = ENDPOINTS[endpoint_name]
         if self.is_rate_limited(path_template):
             raise RateLimitedError(f"{path_template} is rate-limited. "
-                                   f"Will retry in {sec_str(self.rate_limit_time_left(path_template))} seconds.")
+                                   f"Will retry in {sec_str(self.rate_limit_time_left(path_template))} seconds.",
+                                   self.rate_limit_time_left(path_template))
         return path_template
 
     def set_rate_limit_delay(self, path_template: str, delay_time: datetime.timedelta) -> None:

lib/lichess_types.py

@@ -188,6 +188,7 @@ class ChallengeType(TypedDict, total=False):
     declineReason: str
     declineReasonKey: str
     initialFen: str
+    error: dict[str, Union[str, dict[str, str]]]
 
 
 class EventType(TypedDict, total=False):

lib/matchmaking.py

@@ -4,40 +4,17 @@
 import datetime
 import contextlib
 from lib import model
-from lib.timer import Timer, seconds, minutes, days, years
+from lib.timer import Timer, seconds, minutes, years
 from collections import defaultdict
 from collections.abc import Sequence
-from lib.lichess import Lichess
+from lib.lichess import Lichess, RateLimitedError
 from lib.config import Configuration
-from typing import Optional, Union
-from lib.lichess_types import UserProfileType, PerfType, EventType, FilterType
+from typing import Optional, Union, cast
+from lib.lichess_types import UserProfileType, PerfType, EventType, FilterType, ChallengeType
 MULTIPROCESSING_LIST_TYPE = Sequence[model.Challenge]
-DAILY_TIMERS_TYPE = list[Timer]
 
 logger = logging.getLogger(__name__)
 
-daily_challenges_file_name = "daily_challenge_times.txt"
-timestamp_format = "%Y-%m-%d %H:%M:%S\n"
-
-
-def read_daily_challenges() -> DAILY_TIMERS_TYPE:
-    """Read the challenges we have created in the past 24 hours from a text file."""
-    timers: DAILY_TIMERS_TYPE = []
-    try:
-        with open(daily_challenges_file_name) as file:
-            for line in file:
-                timers.append(Timer(days(1), datetime.datetime.strptime(line, timestamp_format)))
-    except FileNotFoundError:
-        pass
-
-    return [timer for timer in timers if not timer.is_expired()]
-
-
-def write_daily_challenges(daily_challenges: DAILY_TIMERS_TYPE) -> None:
-    """Write the challenges we have created in the past 24 hours to a text file."""
-    with open(daily_challenges_file_name, "w") as file:
-        file.writelines(timer.starting_timestamp(timestamp_format) for timer in daily_challenges)
-
 
 class Matchmaking:
     """Challenge other bots."""
@@ -52,11 +29,11 @@ def __init__(self, li: Lichess, config: Configuration, user_profile: UserProfile
         self.last_game_ended_delay = Timer(minutes(self.matchmaking_cfg.challenge_timeout))
         self.last_user_profile_update_time = Timer(minutes(5))
         self.min_wait_time = seconds(60)  # Wait before new challenge to avoid api rate limits.
+        self.rate_limit_timer = Timer()
 
         # Maximum time between challenges, even if there are active games
         self.max_wait_time = minutes(10) if self.matchmaking_cfg.allow_during_games else years(10)
         self.challenge_id = ""
-        self.daily_challenges = read_daily_challenges()
 
         # (opponent name, game aspect) --> other bot is likely to accept challenge
         # game aspect is the one the challenged bot objects to and is one of:
@@ -73,7 +50,7 @@ def __init__(self, li: Lichess, config: Configuration, user_profile: UserProfile
     def should_create_challenge(self) -> bool:
         """Whether we should create a challenge."""
         matchmaking_enabled = self.matchmaking_cfg.allow_matchmaking
-        time_has_passed = self.last_game_ended_delay.is_expired()
+        time_has_passed = self.last_game_ended_delay.is_expired() and self.rate_limit_timer.is_expired()
         challenge_expired = self.last_challenge_created_delay.is_expired() and self.challenge_id
         min_wait_time_passed = self.last_challenge_created_delay.time_since_reset() > self.min_wait_time
         if challenge_expired:
@@ -99,35 +76,34 @@ def create_challenge(self, username: str, base_time: int, increment: int, days:
             return ""
 
         try:
-            self.update_daily_challenge_record()
             self.last_challenge_created_delay.reset()
             response = self.li.challenge(username, params)
             challenge_id = response.get("id", "")
             if not challenge_id:
-                logger.error(response)
-                self.add_to_block_list(username)
-                self.show_earliest_challenge_time()
+                self.handle_challenge_error_response(response, username)
             return challenge_id
+        except RateLimitedError as e:
+            logger.warning(e)
+            self.rate_limit_timer = Timer(e.timeout)
         except Exception as e:
-            logger.warning("Could not create challenge")
             logger.debug(e, exc_info=e)
-            self.show_earliest_challenge_time()
-            return ""
 
-    def update_daily_challenge_record(self) -> None:
-        """
-        Record timestamp of latest challenge and update minimum wait time.
+        logger.warning("Could not create challenge")
+        self.show_earliest_challenge_time()
+        return ""
+
+    def handle_challenge_error_response(self, response: ChallengeType, username: str) -> None:
+        """If a challenge fails, print the error and adjust the challenge requirements in response."""
+        logger.error(response)
+        if "error" in response:
+            rate_limit = cast(dict[str, str], response.get("ratelimit", {}))
+            key = rate_limit.get("key", "")
+            if key == "bot.vsBot.day":
+                self.rate_limit_timer = Timer(seconds(float(rate_limit["seconds"])))
+        else:
+            self.add_to_block_list(username)
+        self.show_earliest_challenge_time()
 
-        As the number of challenges in a day increase, the minimum wait time between challenges increases.
-        0   -  49 challenges --> 1 minute
-        50  -  99 challenges --> 2 minutes
-        100 - 149 challenges --> 3 minutes
-        etc.
-        """
-        self.daily_challenges = [timer for timer in self.daily_challenges if not timer.is_expired()]
-        self.daily_challenges.append(Timer(days(1)))
-        self.min_wait_time = seconds(60) * ((len(self.daily_challenges) // 50) + 1)
-        write_daily_challenges(self.daily_challenges)
 
     def perf(self) -> dict[str, PerfType]:
         """Get the bot's rating in every variant. Bullet, blitz, rapid etc. are considered different variants."""
@@ -280,11 +256,10 @@ def show_earliest_challenge_time(self) -> None:
         if self.matchmaking_cfg.allow_matchmaking:
             postgame_timeout = self.last_game_ended_delay.time_until_expiration()
             time_to_next_challenge = self.min_wait_time - self.last_challenge_created_delay.time_since_reset()
-            time_left = max(postgame_timeout, time_to_next_challenge)
+            rate_limit_delay = self.rate_limit_timer.time_until_expiration()
+            time_left = max(postgame_timeout, time_to_next_challenge, rate_limit_delay)
             earliest_challenge_time = datetime.datetime.now() + time_left
-            challenges = "challenge" + ("" if len(self.daily_challenges) == 1 else "s")
-            logger.info(f"Next challenge will be created after {earliest_challenge_time.strftime('%X')} "
-                        f"({len(self.daily_challenges)} {challenges} in last 24 hours)")
+            logger.info(f"Next challenge will be created after {earliest_challenge_time.strftime('%c')}")
 
     def add_to_block_list(self, username: str) -> None:
         """Add a bot to the blocklist."""

lib/timer.py

@@ -1,8 +1,7 @@
 """A timer for use in lichess-bot."""
 
-from datetime import datetime, timedelta
+from datetime import timedelta
 from time import perf_counter
-from typing import Optional
 
 
 def msec(time_in_msec: float) -> timedelta:
@@ -72,8 +71,7 @@ class Timer:
     the timer was created or since it was last reset.
     """
 
-    def __init__(self, duration: timedelta = zero_seconds,
-                 backdated_timestamp: Optional[datetime] = None) -> None:
+    def __init__(self, duration: timedelta = zero_seconds) -> None:
         """
         Start the timer.
 
@@ -83,9 +81,6 @@ def __init__(self, duration: timedelta = zero_seconds,
         self.duration = duration
         self.starting_time = perf_counter()
 
-        if backdated_timestamp:
-            self.starting_time -= to_seconds(datetime.now() - backdated_timestamp)
-
     def is_expired(self) -> bool:
         """Check if a timer is expired."""
         return self.time_since_reset() >= self.duration
@@ -101,7 +96,3 @@ def time_since_reset(self) -> timedelta:
     def time_until_expiration(self) -> timedelta:
         """How much time is left until it expires."""
         return max(seconds(0), self.duration - self.time_since_reset())
-
-    def starting_timestamp(self, timestamp_format: str) -> str:
-        """When the timer started."""
-        return (datetime.now() - self.time_since_reset()).strftime(timestamp_format)

test_bot/test_timer.py

@@ -1,6 +1,6 @@
 """Test functions dedicated to time measurement and conversion."""
 
-from datetime import datetime, timedelta
+from datetime import timedelta
 
 from lib import timer
 
@@ -40,10 +40,6 @@ def test_init() -> None:
     assert t.duration == duration
     assert t.starting_time is not None
 
-    backdated_timestamp = datetime.now() - timedelta(seconds=10)
-    t = timer.Timer(backdated_timestamp=backdated_timestamp)
-    assert t.starting_time is not None
-    assert t.time_since_reset() >= timedelta(seconds=10)
 
 def test_is_expired() -> None:
     """Test timer expiration."""
@@ -86,10 +82,3 @@ def test_time() -> None:
     t = timer.Timer(timedelta(seconds=10))
     t.starting_time -= 5
     assert timer.sec_str(t.time_until_expiration()) == timer.sec_str(timedelta(seconds=5))
-
-def test_starting_timestamp() -> None:
-    """Test timestamp conversion and integration."""
-    t = timer.Timer(timedelta(seconds=10))
-    timestamp_format = "%Y-%m-%d %H:%M:%S"
-    expected_timestamp = (datetime.now() - t.time_since_reset()).strftime(timestamp_format)
-    assert t.starting_timestamp(timestamp_format) == expected_timestamp

wiki/Configure-lichess-bot.md

@@ -242,6 +242,9 @@ will precede the `go` command to start thinking with `sd 5`. The other `go_comma
   - `allow_during_games`: Whether to issue new challenges while the bot is already playing games. If true, no more than 10 minutes will pass between matchmaking challenges.
   - `challenge_variant`: The variant for the challenges. If set to `random` a variant from the ones enabled in `challenge.variants` will be chosen at random.
   - `challenge_timeout`: The time (in minutes) the bot has to be idle before it creates a challenge.
+
+  Bots are limited to playing 100 games against other bots per day, so setting `challenge_timeout` to a small value will result in this limit being reached quickly. There is no limit to the number of games a bot can play against humans.
+
   - `challenge_initial_time`: A list of initial times (in seconds and to be chosen at random) for the challenges.
   - `challenge_increment`: A list of increments (in seconds and to be chosen at random) for the challenges.
   - `challenge_days`: A list of number of days for a correspondence challenge (to be chosen at random).