fix(server): populate games_v2 metadata on game start

update_game_started (started_at, num_players, num_rounds, player_ids)
was defined in event_store but had zero callers. 289/289 staging games
had those fields NULL — queries that joined on them returned garbage,
and the denormalized player_ids GIN index was dead weight.

log_game_start now calls create_game THEN update_game_started in one
async task. If create fails, update is skipped (row doesn't exist).
handlers.py passes num_rounds and player_ids through at call time.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
adlee-was-taken
2026-04-18 00:41:58 -04:00
parent d5f8eef6b3
commit 8030a3c171
3 changed files with 142 additions and 36 deletions

View File

@@ -215,6 +215,8 @@ async def handle_start_game(data: dict, ctx: ConnectionContext, *, broadcast_gam
ctx.current_room.game_log_id = game_logger.log_game_start( ctx.current_room.game_log_id = game_logger.log_game_start(
room_code=ctx.current_room.code, room_code=ctx.current_room.code,
num_players=len(ctx.current_room.players), num_players=len(ctx.current_room.players),
num_rounds=num_rounds,
player_ids=[p.id for p in ctx.current_room.game.players],
options=options, options=options,
) )

View File

@@ -63,22 +63,20 @@ class GameLogger:
self, self,
room_code: str, room_code: str,
num_players: int, num_players: int,
num_rounds: int,
player_ids: list[str],
options: "GameOptions", options: "GameOptions",
game_id: Optional[str] = None,
) -> str: ) -> str:
""" """
Log game start, return game_id. Log game start. Writes the row via create_game and then populates
started_at/num_players/num_rounds/player_ids via update_game_started
so downstream queries don't see a half-initialized games_v2 row.
Creates a game record in games_v2 table. If create_game fails the update is skipped — the row doesn't exist.
Args:
room_code: Room code for the game.
num_players: Number of players.
options: Game options/house rules.
Returns:
Generated game UUID.
""" """
game_id = str(uuid.uuid4()) if game_id is None:
game_id = str(uuid.uuid4())
try: try:
await self.event_store.create_game( await self.event_store.create_game(
@@ -87,9 +85,20 @@ class GameLogger:
host_id="system", host_id="system",
options=self._options_to_dict(options), options=self._options_to_dict(options),
) )
except Exception as e:
log.error(f"Failed to log game start (create): {e}")
return game_id
try:
await self.event_store.update_game_started(
game_id,
num_players,
num_rounds,
player_ids,
)
log.debug(f"Logged game start: {game_id} room={room_code}") log.debug(f"Logged game start: {game_id} room={room_code}")
except Exception as e: except Exception as e:
log.error(f"Failed to log game start: {e}") log.error(f"Failed to log game start (update): {e}")
return game_id return game_id
@@ -97,6 +106,8 @@ class GameLogger:
self, self,
room_code: str, room_code: str,
num_players: int, num_players: int,
num_rounds: int,
player_ids: list[str],
options: "GameOptions", options: "GameOptions",
) -> str: ) -> str:
""" """
@@ -108,32 +119,29 @@ class GameLogger:
game_id = str(uuid.uuid4()) game_id = str(uuid.uuid4())
try: try:
loop = asyncio.get_running_loop() asyncio.get_running_loop()
# Already in async context - fire task, return ID immediately asyncio.create_task(
asyncio.create_task(self._log_game_start_with_id(game_id, room_code, num_players, options)) self.log_game_start_async(
room_code=room_code,
num_players=num_players,
num_rounds=num_rounds,
player_ids=player_ids,
options=options,
game_id=game_id,
)
)
return game_id return game_id
except RuntimeError: except RuntimeError:
# Not in async context - run synchronously return asyncio.run(
return asyncio.run(self.log_game_start_async(room_code, num_players, options)) self.log_game_start_async(
room_code=room_code,
async def _log_game_start_with_id( num_players=num_players,
self, num_rounds=num_rounds,
game_id: str, player_ids=player_ids,
room_code: str, options=options,
num_players: int, game_id=game_id,
options: "GameOptions", )
) -> None:
"""Helper to log game start with pre-generated ID."""
try:
await self.event_store.create_game(
game_id=game_id,
room_code=room_code,
host_id="system",
options=self._options_to_dict(options),
) )
log.debug(f"Logged game start: {game_id} room={room_code}")
except Exception as e:
log.error(f"Failed to log game start: {e}")
async def log_game_end_async(self, game_id: str) -> None: async def log_game_end_async(self, game_id: str) -> None:
""" """

View File

@@ -21,7 +21,7 @@ from unittest.mock import AsyncMock, MagicMock, patch
from game import GameOptions from game import GameOptions
from room import Room, RoomManager from room import Room, RoomManager
from services.game_logger import GameLogger from services.game_logger import GameLogger
from handlers import ConnectionContext, handle_end_game from handlers import ConnectionContext, handle_end_game, handle_start_game
from test_handlers import MockWebSocket, make_ctx from test_handlers import MockWebSocket, make_ctx
@@ -151,6 +151,102 @@ class TestHandleEndGameMarksAbandoned:
ctx = make_ctx(websocket=joiner_ws, player_id="joiner", room=room) ctx = make_ctx(websocket=joiner_ws, player_id="joiner", room=room)
with patch("handlers.get_logger", return_value=mock_logger):
await handle_end_game(
{},
ctx,
room_manager=rm,
cleanup_room_profiles=lambda _code: None,
)
mock_logger.log_game_abandoned.assert_not_called()
assert room.code in rm.rooms
class TestLogGameStartPopulatesMetadata:
"""
create_game only writes id/room_code/host_id/options. update_game_started
(which fills in started_at, num_players, num_rounds, player_ids) existed
but had zero callers — 100% of staging's 289 games had those fields NULL.
log_game_start must call both so the row is complete after start_game.
"""
@pytest.mark.asyncio
async def test_start_calls_create_and_update(self):
event_store = MagicMock()
event_store.create_game = AsyncMock()
event_store.update_game_started = AsyncMock()
logger = GameLogger(event_store)
options = GameOptions(initial_flips=0)
await logger.log_game_start_async(
room_code="ABCD",
num_players=3,
num_rounds=9,
player_ids=["p1", "p2", "p3"],
options=options,
)
event_store.create_game.assert_awaited_once()
event_store.update_game_started.assert_awaited_once()
call = event_store.update_game_started.await_args
assert call.kwargs.get("num_players", call.args[1] if len(call.args) > 1 else None) == 3
assert call.kwargs.get("num_rounds", call.args[2] if len(call.args) > 2 else None) == 9
assert call.kwargs.get("player_ids", call.args[3] if len(call.args) > 3 else None) == ["p1", "p2", "p3"]
@pytest.mark.asyncio
async def test_update_uses_same_game_id_as_create(self):
event_store = MagicMock()
event_store.create_game = AsyncMock()
event_store.update_game_started = AsyncMock()
logger = GameLogger(event_store)
await logger.log_game_start_async(
room_code="XYZW",
num_players=2,
num_rounds=1,
player_ids=["a", "b"],
options=GameOptions(initial_flips=0),
)
create_args = event_store.create_game.await_args
update_args = event_store.update_game_started.await_args
created_id = create_args.kwargs.get("game_id", create_args.args[0] if create_args.args else None)
updated_id = update_args.args[0] if update_args.args else update_args.kwargs.get("game_id")
assert created_id == updated_id
assert created_id # non-empty
@pytest.mark.asyncio
async def test_create_failure_skips_update(self):
"""If the row never landed, don't try to update a non-existent id."""
event_store = MagicMock()
event_store.create_game = AsyncMock(side_effect=Exception("db down"))
event_store.update_game_started = AsyncMock()
logger = GameLogger(event_store)
await logger.log_game_start_async(
room_code="ABCD",
num_players=2,
num_rounds=1,
player_ids=["a", "b"],
options=GameOptions(initial_flips=0),
)
event_store.update_game_started.assert_not_awaited()
"""Only the host ends games — non-host requests are rejected unchanged."""
rm = RoomManager()
room = rm.create_room()
room.add_player("host", "Host", MockWebSocket())
room.get_player("host").is_host = True
joiner_ws = MockWebSocket()
room.add_player("joiner", "Joiner", joiner_ws)
room.game_log_id = "game-uuid-untouchable"
mock_logger = MagicMock()
mock_logger.log_game_abandoned = MagicMock()
ctx = make_ctx(websocket=joiner_ws, player_id="joiner", room=room)
with patch("handlers.get_logger", return_value=mock_logger): with patch("handlers.get_logger", return_value=mock_logger):
await handle_end_game( await handle_end_game(
{}, {},