Debug Ladder: Add some additional logging statements (#439)

* Add some additional log spam for starting ladder games

* Add test to explicitly run boundary calculations

* Add test for search matching with wrong type of object

* Add logging when client errors occur

server/ladder_service.py

@@ -95,6 +95,7 @@ async def handle_queue_matches(self):
             asyncio.ensure_future(self.start_game(p1, p2))
 
     async def start_game(self, host: Player, guest: Player):
+        self._logger.debug("Starting ladder game between %s and %s", host, guest)
         host.state = PlayerState.HOSTING
         guest.state = PlayerState.JOINING
 
@@ -126,6 +127,7 @@ async def start_game(self, host: Player, guest: Player):
 
         mapname = map_path[5:-4]  # FIXME: Database filenames contain the maps/ prefix and .zip suffix.
                                   # Really in the future, just send a better description
+        self._logger.debug("Starting ladder game: %s", game)
         host.lobby_connection.launch_game(game, is_host=True, use_map=mapname)
         try:
             hosted = await game.await_hosted()
@@ -140,8 +142,10 @@ async def start_game(self, host: Player, guest: Player):
             # searching for ladder, even though the server has already removed it
             # from the queue.
             # return
+            self._logger.debug("Ladder game failed to launch due to a timeout")
 
         guest.lobby_connection.launch_game(game, is_host=False, use_map=mapname)
+        self._logger.debug("Ladder game launched successfully")
 
     async def choose_map(self, players: [Player]) -> MapDescription:
         maps = self.game_service.ladder_maps

server/lobbyconnection.py

@@ -150,6 +150,7 @@ async def on_message_received(self, message):
                  'text': ex.message}
             )
         except ClientError as ex:
+            self._logger.warning("Client error: %s", ex.message)
             self.protocol.send_message(
                 {'command': 'notice',
                  'style': 'error',

tests/unit_tests/test_matchmaker_queue.py

@@ -82,6 +82,21 @@ async def test_search_no_match(mocker, loop, matchmaker_players):
     assert not s1.matches_with(s2)
 
 
+def test_search_no_match_wrong_type(matchmaker_players):
+    p1, _, _, _, _, _ = matchmaker_players
+    s1 = Search([p1])
+    assert not s1.matches_with(42)
+
+
+def test_search_boundaries(matchmaker_players):
+    p1, _, _, _, _, _ = matchmaker_players
+    s1 = Search([p1])
+    assert p1.ladder_rating[0] > s1.boundary_80[0]
+    assert p1.ladder_rating[0] < s1.boundary_80[1]
+    assert p1.ladder_rating[0] > s1.boundary_75[0]
+    assert p1.ladder_rating[0] < s1.boundary_75[1]
+
+
 async def test_search_await(mocker, loop, matchmaker_players):
     p1, p2, _, _, _, _ = matchmaker_players
     s1, s2 = Search([p1]), Search([p2])