Hotfix 9.30: Fix avatars and py client matchmaking (#436)

* Fix player service query to look at selected avatars only

* Switch game connection logging to TRACE level

* Allow faction to be passed as int again

* Don't crash if icon is null

* Add handler for automatic teamkill reporting, and ignore AI teamkills

* Improved the inform_player test to verify functionality after logging out

* Separate teamkillreport and teamkillhappened

* Refactor test to not use mock, but send the correct message to signal hosted game

.gitignore

@@ -16,4 +16,4 @@ develop_venv/
 .mypy_cache
 .pytest_cache
 .venv
-test-data.sql
+/test-data.sql

server/gameconnection.py

@@ -4,6 +4,7 @@
 from sqlalchemy import text, select
 
 from .abc.base_game import GameConnectionState
+from .config import TRACE
 from .decorators import with_logger
 from .game_service import GameService
 from .games.game import Game, GameState, ValidityState, Victory
@@ -72,7 +73,7 @@ def player(self, val: Player):
     def send_message(self, message):
         message['target'] = "game"
 
-        self._logger.debug(">>: %s", message)
+        self._logger.log(TRACE, ">>: %s", message)
         self.protocol.send_message(message)
 
     async def _handle_idle_state(self):
@@ -298,6 +299,8 @@ async def handle_enforce_rating(self):
 
     async def handle_teamkill_report(self, gametime, reporter_id, reporter_name, teamkiller_id, teamkiller_name):
         """
+            Sent when a player is teamkilled and clicks the 'Report' button.
+
             :param gametime: seconds of gametime when kill happened
             :param reporter_id: reporter id
             :param reporter_name: reporter nickname
@@ -364,6 +367,31 @@ async def handle_teamkill_report(self, gametime, reporter_id, reporter_name, tea
             )
 
 
+    async def handle_teamkill_happened(self, gametime, victim_id, victim_name, teamkiller_id, teamkiller_name):
+        """
+            Send automatically by the game whenever a teamkill happens. Takes
+            the same parameters as TeamkillReport.
+
+            :param gametime: seconds of gametime when kill happened
+            :param victim_id: victim id
+            :param victim_name: victim nickname (for debug purpose only)
+            :param teamkiller_id: teamkiller id
+            :param teamkiller_name: teamkiller nickname (for debug purpose only)
+        """
+        victim_id = int(victim_id)
+        teamkiller_id = int(teamkiller_id)
+
+        if 0 in (victim_id, teamkiller_id):
+            self._logger.debug("Ignoring teamkill for AI player")
+            return
+
+        async with db.engine.acquire() as conn:
+            await conn.execute(
+                """ INSERT INTO `teamkills` (`teamkiller`, `victim`, `game_id`, `gametime`)
+                    VALUES (%s, %s, %s, %s)""",
+                (teamkiller_id, victim_id, self.game.id, gametime)
+            )
+
     async def handle_ice_message(self, receiver_id, ice_msg):
         receiver_id = int(receiver_id)
         peer = self.player_service.get_player(receiver_id)
@@ -538,6 +566,7 @@ def __str__(self):
     "JsonStats":            GameConnection.handle_json_stats,
     "EnforceRating":        GameConnection.handle_enforce_rating,
     "TeamkillReport":       GameConnection.handle_teamkill_report,
+    "TeamkillHappened":     GameConnection.handle_teamkill_happened,
     "GameEnded":            GameConnection.handle_game_ended,
     "Rehost":               GameConnection.handle_rehost,
     "Bottleneck":           GameConnection.handle_bottleneck,

server/lobbyconnection.py

@@ -741,7 +741,8 @@ async def command_game_matchmaking(self, message):
 
         if state == "start":
             assert self.player is not None
-            self.player.faction = str(message['faction'])
+            # Faction can be either the name (e.g. 'uef') or the enum value (e.g. 1)
+            self.player.faction = message['faction']
 
             if mod == "ladder1v1":
                 search = Search([self.player])
@@ -853,7 +854,7 @@ async def command_modvault(self, message):
                 uid, name, version, author, ui, date, downloads, likes, played, description, filename, icon, likerList = (row[i] for i in range(13))
                 link = urllib.parse.urljoin(config.CONTENT_URL, "faf/vault/" + filename)
                 thumbstr = ""
-                if icon != "":
+                if icon:
                     thumbstr = urllib.parse.urljoin(config.CONTENT_URL, "faf/vault/mods_thumbs/" + urllib.parse.quote(icon))
 
                 out = dict(command="modvault_info", thumbnail=thumbstr, link=link, bugreports=[],

server/player_service.py

@@ -6,7 +6,7 @@
 import server.db as db
 from server.decorators import with_logger
 from server.players import Player
-from sqlalchemy import select
+from sqlalchemy import and_, select
 
 from .db.models import (avatars, avatars_list, clan, clan_membership,
                         global_rating, ladder1v1_rating, login)
@@ -66,7 +66,10 @@ async def fetch_player_data(self, player):
                 .join(ladder1v1_rating)
                 .outerjoin(clan_membership)
                 .outerjoin(clan)
-                .outerjoin(avatars)
+                .outerjoin(avatars, onclause=and_(
+                    avatars.c.idUser == login.c.id,
+                    avatars.c.selected == 1
+                ))
                 .outerjoin(avatars_list)
             ).where(login.c.id == player.id)
 

tests/data/test-data.sql

@@ -1,5 +1,7 @@
 insert into login (id, login, email, password, create_time) values
-    (50,  'player_service', '[email protected]', SHA2('player_service', 256), '2000-01-01 00:00:00'),
+    (50,  'player_service1', '[email protected]', SHA2('player_service1', 256), '2000-01-01 00:00:00'),
+    (51,  'player_service2', '[email protected]', SHA2('player_service2', 256), '2000-01-01 00:00:00'),
+    (52,  'player_service3', '[email protected]', SHA2('player_service3', 256), '2000-01-01 00:00:00'),
     (100, 'ladder1', '[email protected]', SHA2('ladder1', 256), '2000-01-01 00:00:00'),
     (101, 'ladder2', '[email protected]', SHA2('ladder2', 256), '2000-01-01 00:00:00'),
     (102, 'ladder_ban', '[email protected]', SHA2('ladder_ban', 256), '2000-01-01 00:00:00'),
@@ -12,20 +14,28 @@ insert into clan_membership (clan_id, player_id) values
 
 insert into global_rating (id, mean, deviation, numGames, is_active) values
     (50,  1200, 250, 42, 1),
+    (51,  1200, 250, 42, 1),
+    (52,  1200, 250, 42, 1),
     (100, 1500, 500, 0, 1),
     (101, 1500, 500, 0, 1),
     (102, 1500, 500, 0, 1)
 ;
 
 insert into ladder1v1_rating (id, mean, deviation, numGames, is_active) values
     (50,  1300, 400, 12, 1),
+    (51,  1300, 400, 12, 1),
+    (52,  1300, 400, 12, 1),
     (100, 1500, 500, 0, 1),
     (101, 1500, 500, 0, 1),
     (102, 1500, 500, 0, 1)
 ;
 
 insert into avatars (idUser, idAvatar, selected) values
-    (50, 2, 1);
+    (50, 2, 1),
+    (51, 1, 0),
+    (51, 2, 1),
+    (52, 1, 1),
+    (52, 2, 0);
 
 delete from matchmaker_ban where id = 102 and userid = 102;
 insert into matchmaker_ban (id, userid) values (102, 102);

tests/integration_tests/conftest.py

@@ -80,6 +80,10 @@ async def read_until(proto, pred):
             pass
 
 
+async def read_until_command(proto, command):
+    return await read_until(proto, lambda msg: msg.get('command') == command)
+
+
 async def get_session(proto):
     proto.send_message({'command': 'ask_session', 'user_agent': 'faf-client', 'version': '0.11.16'})
     await proto.drain()

tests/integration_tests/test_matchmaker.py

@@ -1,19 +1,7 @@
-import asyncio
-
-from tests import CoroMock
-
-from .conftest import connect_and_sign_in, read_until
-from .testclient import ClientTest
-
-# Need to save the old sleep here otherwise the mocker recursively patches it
-aiosleep = asyncio.sleep
-
-
-async def test_game_matchmaking(loop, lobby_server, mocker):
-    mocker.patch('server.ladder_service.asyncio.sleep', side_effect=lambda _: aiosleep(0.1))
-    mocker.patch('server.games.game.Game.await_hosted', CoroMock())
+from .conftest import connect_and_sign_in, read_until_command
 
 
+async def queue_players_for_matchmaking(lobby_server):
     _, _, proto1 = await connect_and_sign_in(
         ('ladder1', 'ladder1'),
         lobby_server
@@ -23,32 +11,45 @@ async def test_game_matchmaking(loop, lobby_server, mocker):
         lobby_server
     )
 
-    await read_until(proto1, lambda msg: msg['command'] == 'game_info')
-    await read_until(proto2, lambda msg: msg['command'] == 'game_info')
+    await read_until_command(proto1, 'game_info')
+    await read_until_command(proto2, 'game_info')
+
+    proto1.send_message({
+        'command': 'game_matchmaking',
+        'state': 'start',
+        'faction': 'uef'
+    })
+    await proto1.drain()
+
+    proto2.send_message({
+        'command': 'game_matchmaking',
+        'state': 'start',
+        'faction': 1  # Python client sends factions as numbers
+    })
+    await proto2.drain()
+
+    # If the players did not match, this will fail due to a timeout error
+    await read_until_command(proto1, 'match_found')
+    await read_until_command(proto2, 'match_found')
+
+    return proto1, proto2
 
-    with ClientTest(loop=loop, process_nat_packets=True, proto=proto1) as client1:
-        with ClientTest(loop=loop, process_nat_packets=True, proto=proto2) as client2:
-            proto1.send_message({
-                'command': 'game_matchmaking',
-                'state': 'start',
-                'faction': 'uef'
-            })
-            await proto1.drain()
 
-            proto2.send_message({
-                'command': 'game_matchmaking',
-                'state': 'start',
-                'faction': 'uef'
-            })
-            await proto2.drain()
+async def test_game_matchmaking(loop, lobby_server):
+    proto1, proto2 = await queue_players_for_matchmaking(lobby_server)
 
-            # If the players did not match, this test will fail due to a timeout error
-            msg1 = await read_until(proto1, lambda msg: msg['command'] == 'game_launch')
-            msg2 = await read_until(proto2, lambda msg: msg['command'] == 'game_launch')
+    # The player that queued last will be the host
+    msg2 = await read_until_command(proto2, 'game_launch')
+    proto2.send_message({
+        'command': 'GameState',
+        'target': 'game',
+        'args': ['Lobby']
+    })
+    msg1 = await read_until_command(proto1, 'game_launch')
 
-            assert msg1['uid'] == msg2['uid']
-            assert msg1['mod'] == 'ladder1v1'
-            assert msg2['mod'] == 'ladder1v1'
+    assert msg1['uid'] == msg2['uid']
+    assert msg1['mod'] == 'ladder1v1'
+    assert msg2['mod'] == 'ladder1v1'
 
 
 async def test_game_matchmaking_ban(loop, lobby_server, db_engine):
@@ -57,21 +58,20 @@ async def test_game_matchmaking_ban(loop, lobby_server, db_engine):
         lobby_server
     )
 
-    await read_until(proto, lambda msg: msg['command'] == 'game_info')
+    await read_until_command(proto, 'game_info')
 
-    with ClientTest(loop=loop, process_nat_packets=True, proto=proto) as client1:
-        proto.send_message({
-            'command': 'game_matchmaking',
-            'state': 'start',
-            'faction': 'uef'
-        })
-        await proto.drain()
+    proto.send_message({
+        'command': 'game_matchmaking',
+        'state': 'start',
+        'faction': 'uef'
+    })
+    await proto.drain()
 
-        # This may fail due to a timeout error
-        msg = await read_until(proto, lambda msg: msg['command'] == 'notice')
+    # This may fail due to a timeout error
+    msg = await read_until_command(proto, 'notice')
 
-        assert msg == {
-            'command': 'notice',
-            'style': 'error',
-            'text': 'You are banned from the matchmaker. Contact an admin to have the reason.'
-        }
+    assert msg == {
+        'command': 'notice',
+        'style': 'error',
+        'text': 'You are banned from the matchmaker. Contact an admin to have the reason.'
+    }

tests/unit_tests/test_gameconnection.py

@@ -271,6 +271,23 @@ async def test_handle_action_TeamkillReport_invalid_offender_id_and_name(game: G
         assert report is None
 
 
+async def test_handle_action_TeamkillHappened(game: Game, game_connection: GameConnection, db_engine):
+    game.launch = CoroMock()
+    await game_connection.handle_action('TeamkillHappened', ['200', '2', 'Dostya', '3', 'Rhiza'])
+
+    async with db_engine.acquire() as conn:
+        result = await conn.execute("select game_id from teamkills where victim=2 and teamkiller=3 and game_id=%s and gametime=200", (game.id))
+        row = await result.fetchone()
+        assert game.id == row[0]
+
+
+async def test_handle_action_TeamkillHappened_AI(game: Game, game_connection: GameConnection, db_engine):
+    # Should fail with a sql constraint error if this isn't handled correctly
+    game_connection.abort = mock.Mock()
+    await game_connection.handle_action('TeamkillHappened', ['200', 0, 'Dostya', '0', 'Rhiza'])
+    game_connection.abort.assert_not_called()
+
+
 async def test_handle_action_GameResult_victory_ends_sim(
     game: Game,
     game_connection: GameConnection

tests/unit_tests/test_ladder.py

@@ -47,7 +47,17 @@ def test_inform_player(ladder_service: LadderService):
 
     ladder_service.inform_player(p1)
 
-    assert p1.lobby_connection.sendJSON.called
+    # Message is sent after the first call
+    p1.lobby_connection.sendJSON.assert_called_once()
+    ladder_service.inform_player(p1)
+    p1.lobby_connection.sendJSON.reset_mock()
+    # But not after the second
+    p1.lobby_connection.sendJSON.assert_not_called()
+    ladder_service.on_connection_lost(p1)
+    ladder_service.inform_player(p1)
+
+    # But it is called if the player relogs
+    p1.lobby_connection.sendJSON.assert_called_once()
 
 
 async def test_start_and_cancel_search(ladder_service: LadderService):

tests/unit_tests/test_player_service.py

@@ -13,6 +13,19 @@ async def test_fetch_player_data(player_service):
     assert player.avatar == {'url': 'http://content.faforever.com/faf/avatars/UEF.png', 'tooltip': 'UEF'}
 
 
+async def test_fetch_player_data_multiple_avatar(player_service):
+    player1 = Mock()
+    player1.id = 51
+    player2 = Mock()
+    player2.id = 52
+
+    await player_service.fetch_player_data(player1)
+    assert player1.avatar == {'url': 'http://content.faforever.com/faf/avatars/UEF.png', 'tooltip': 'UEF'}
+
+    await player_service.fetch_player_data(player2)
+    assert player2.avatar == {'url': 'http://content.faforever.com/faf/avatars/qai2.png', 'tooltip': 'QAI'}
+
+
 async def test_fetch_player_data_no_avatar_or_clan(player_service):
     player = Mock()
     player.id = 100