diff --git a/cogs/gameplay.py b/cogs/gameplay.py index 9370b2f..8094e4b 100644 --- a/cogs/gameplay.py +++ b/cogs/gameplay.py @@ -15,6 +15,7 @@ from sqlmodel import func, or_ from api_calls import db_get from command_logic.logic_gameplay import bunts, chaos, complete_game, defender_dropdown_view, doubles, flyballs, frame_checks, get_full_roster_from_sheets, checks_log_interaction, complete_play, get_scorebug_embed, groundballs, hit_by_pitch, homeruns, is_game_over, lineouts, manual_end_game, new_game_checks, new_game_conflicts, popouts, read_lineup, relief_pitcher_dropdown_view, select_ai_reliever, show_defense_cards, singles, starting_pitcher_dropdown_view, steals, strikeouts, sub_batter_dropdown_view, substitute_player, triples, undo_play, update_game_settings, walks, xchecks, activate_last_play +from play_lock import release_play_lock, safe_play_lock from dice import ab_roll from exceptions import * import gauntlets @@ -1147,7 +1148,7 @@ class Gameplay(commands.Cog): ) async def game_settings_command(self, interaction: discord.Interaction, roll_buttons: bool = None, auto_roll: bool = None): with Session(engine) as session: - this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='settings-ingame') + this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='settings-ingame', lock_play=False) await interaction.edit_original_response(content=None, embed=await update_game_settings( session, @@ -1163,15 +1164,16 @@ class Gameplay(commands.Cog): with Session(engine) as session: this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='end-game') - # await interaction.edit_original_response(content='Let\'s see, I didn\'t think this game was over...') - await manual_end_game(session, interaction, this_game, current_play=this_play) + with safe_play_lock(session, this_play): + # await interaction.edit_original_response(content='Let\'s see, I didn\'t think this game was over...') + await manual_end_game(session, interaction, this_game, current_play=this_play) group_substitution = app_commands.Group(name='substitute', description='Make a substitution in active game') @group_substitution.command(name='batter', description='Make a batter substitution') async def sub_batter_command(self, interaction: discord.Interaction, batting_order: Literal['this-spot', '1', '2', '3', '4', '5', '6', '7', '8', '9'] = 'this-spot'): with Session(engine) as session: - this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute batter') + this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute batter', lock_play=False) if batting_order == 'this-spot': if this_play.batter.team != owner_team: @@ -1190,7 +1192,7 @@ class Gameplay(commands.Cog): @group_substitution.command(name='pitcher', description='Make a pitching substitution') async def sub_pitcher_command(self, interaction: discord.Interaction, batting_order: Literal['dh-spot', '1', '2', '3', '4', '5', '6', '7', '8', '9', '10'] = '10'): with Session(engine) as session: - this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute batter') + this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute pitcher', lock_play=False) if owner_team != this_play.pitcher.team: logger.warning(f'User {interaction.user.name} ({owner_team.abbrev}) tried to run a sub for the {this_play.pitcher.team.lname}') @@ -1229,7 +1231,7 @@ class Gameplay(commands.Cog): @group_substitution.command(name='defense', description='Make a defensive substitution or move defenders between positions') async def sub_defense_command(self, interaction: discord.Interaction, new_position: DEFENSE_NO_PITCHER_LITERAL): with Session(engine) as session: - this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute defense') + this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='substitute defense', lock_play=False) defense_view = await defender_dropdown_view( session=session, @@ -1480,7 +1482,17 @@ class Gameplay(commands.Cog): @group_show.command(name='defense', description='Display a defender\'s player card') async def show_defense_command(self, interaction: discord.Interaction, position: DEFENSE_LITERAL): with Session(engine) as session: - this_game, owner_team, this_play = await checks_log_interaction(session, interaction, command_name='show-card defense') + # Read-only command - no play locking needed + await interaction.response.defer(thinking=True) + this_game = get_channel_game_or_none(session, interaction.channel_id) + if this_game is None: + await interaction.edit_original_response(content="I don't see an active game in this channel.") + return + + this_play = this_game.current_play_or_none(session) + if this_play is None: + await interaction.edit_original_response(content="No active play found.") + return logger.info(f'show-card defense - position: {position}') await show_defense_cards(session, interaction, this_play, position) diff --git a/command_logic/logic_gameplay.py b/command_logic/logic_gameplay.py index 7e9dfe6..dd763e4 100644 --- a/command_logic/logic_gameplay.py +++ b/command_logic/logic_gameplay.py @@ -12,6 +12,7 @@ from typing import Literal from api_calls import db_delete, db_get, db_post from dice import DTwentyRoll, d_twenty_roll, frame_plate_check, sa_fielding_roll from exceptions import * +from play_lock import release_play_lock, safe_play_lock from gauntlets import post_result from helpers import ( COLORS, @@ -1196,10 +1197,22 @@ async def get_full_roster_from_sheets( async def checks_log_interaction( - session: Session, interaction: discord.Interaction, command_name: str + session: Session, interaction: discord.Interaction, command_name: str, lock_play: bool = True ) -> tuple[Game, Team, Play]: """ - Commits this_play + Validates interaction permissions and optionally locks the current play for processing. + + Args: + session: Database session + interaction: Discord interaction + command_name: Name of the command being executed + lock_play: If True (default), locks the play. Set to False for read-only commands. + + IMPORTANT: If lock_play=True, the calling code MUST either: + 1. Call complete_play() which releases the lock on success, OR + 2. Use exception handling to call release_play_lock() on failure + + Commits this_play with locked=True (only if lock_play=True) """ logger.info( f"log interaction checks for {interaction.user.name} in channel {interaction.channel.name}" @@ -1247,22 +1260,24 @@ async def checks_log_interaction( ) this_play = activate_last_play(session, this_game) - if this_play.locked: - logger.warning( - f"{interaction.user.name} attempted {command_name} on locked play {this_play.id} " - f"in game {this_game.id}. Rejecting duplicate submission." - ) - from exceptions import PlayLockedException + if lock_play: + # Only check and set lock if this is a write command + if this_play.locked: + logger.warning( + f"{interaction.user.name} attempted {command_name} on locked play {this_play.id} " + f"in game {this_game.id}. Rejecting duplicate submission." + ) + from exceptions import PlayLockedException - raise PlayLockedException( - "This play is already being processed. Please wait for the current action to complete.\n\n" - "If this play appears stuck, wait 30 seconds and try again (auto-unlock will trigger)." - ) + raise PlayLockedException( + "This play is already being processed. Please wait for the current action to complete.\n\n" + "If this play appears stuck, go call dad." + ) - this_play.locked = True - session.add(this_play) - session.commit() - session.refresh(this_play) + this_play.locked = True + session.add(this_play) + session.commit() + session.refresh(this_play) return this_game, owner_team, this_play diff --git a/paperdynasty.py b/paperdynasty.py index c82b2c2..d7d9ea1 100644 --- a/paperdynasty.py +++ b/paperdynasty.py @@ -7,7 +7,8 @@ import os from discord.ext import commands -from in_game.gameplay_models import create_db_and_tables +from in_game.gameplay_models import create_db_and_tables, Session, engine +from in_game.gameplay_queries import get_channel_game_or_none from health_server import run_health_server from notify_restart import send_restart_notification @@ -79,17 +80,35 @@ async def on_ready(): async def on_app_command_error(interaction: discord.Interaction, error: discord.app_commands.AppCommandError): """Global error handler for all app commands (slash commands).""" logger.error(f'App command error in {interaction.command}: {error}', exc_info=error) - + + # CRITICAL: Release play lock if command failed during gameplay + # This prevents permanent user lockouts when exceptions occur + try: + with Session(engine) as session: + game = get_channel_game_or_none(session, interaction.channel_id) + if game: + current_play = game.current_play_or_none(session) + if current_play and current_play.locked and not current_play.complete: + logger.warning( + f"Releasing stuck play lock {current_play.id} in game {game.id} " + f"after command error: {error}" + ) + current_play.locked = False + session.add(current_play) + session.commit() + except Exception as lock_error: + logger.error(f'Failed to release play lock after error: {lock_error}', exc_info=lock_error) + # Try to respond to the user try: if not interaction.response.is_done(): await interaction.response.send_message( - f'❌ An error occurred: {str(error)}', + f'❌ An error occurred: {str(error)}', ephemeral=True ) else: await interaction.followup.send( - f'❌ An error occurred: {str(error)}', + f'❌ An error occurred: {str(error)}', ephemeral=True ) except Exception as e: diff --git a/play_lock.py b/play_lock.py new file mode 100644 index 0000000..c1d0872 --- /dev/null +++ b/play_lock.py @@ -0,0 +1,76 @@ +""" +Play locking utilities to prevent concurrent play modifications. + +This module is separate to avoid circular imports between logic_gameplay and utilities. +""" +import logging +from contextlib import contextmanager +from sqlmodel import Session + +logger = logging.getLogger("discord_app") + + +def release_play_lock(session: Session, play: "Play") -> None: + """ + Release a play lock and commit the change. + + This is a safety mechanism to ensure locks are always released, + even when exceptions occur during command processing. + """ + if play.locked: + logger.info(f"Releasing lock on play {play.id}") + play.locked = False + session.add(play) + session.commit() + + +@contextmanager +def safe_play_lock(session: Session, play: "Play"): + """ + Context manager for safely handling play locks. + + Ensures the lock is ALWAYS released even if an exception occurs during + command processing. This prevents permanent user lockouts. + + Usage: + with safe_play_lock(session, this_play): + # Do command processing + # Lock will be released automatically on exception or normal exit + pass + + Note: This only releases the lock on exception. On successful completion, + complete_play() should handle releasing the lock and marking the play complete. + """ + lock_released = False + try: + yield play + except Exception as e: + # Release lock on any exception + if play.locked and not play.complete: + logger.error( + f"Exception during play {play.id} processing, releasing lock. Error: {e}" + ) + play.locked = False + session.add(play) + try: + session.commit() + lock_released = True + except Exception as commit_error: + logger.error( + f"Failed to release lock on play {play.id}: {commit_error}" + ) + raise # Re-raise the original exception + finally: + # Final safety check + if not lock_released and play.locked and not play.complete: + logger.warning( + f"Play {play.id} still locked after processing, forcing unlock" + ) + play.locked = False + session.add(play) + try: + session.commit() + except Exception as commit_error: + logger.error( + f"Failed to force unlock play {play.id}: {commit_error}" + ) diff --git a/tests/test_play_locking.py b/tests/test_play_locking.py index 58db9c0..48e1dda 100644 --- a/tests/test_play_locking.py +++ b/tests/test_play_locking.py @@ -1,10 +1,16 @@ """ Test play locking idempotency guard. + +Tests the play locking system including: +- Lock acquisition and rejection of duplicate submissions +- Automatic lock release on exception via global error handler +- Manual lock release via release_play_lock() +- Context manager safe_play_lock() behavior """ import pytest from unittest.mock import MagicMock, AsyncMock, patch -from command_logic.logic_gameplay import checks_log_interaction +from command_logic.logic_gameplay import checks_log_interaction, release_play_lock, safe_play_lock from exceptions import PlayLockedException @@ -220,3 +226,92 @@ async def test_different_commands_racing_on_locked_play( # Verify exception message is consistent assert "already being processed" in str(exc_info.value) assert "wait" in str(exc_info.value).lower() + + +def test_release_play_lock_unlocks_locked_play(mock_session): + """ + Verify release_play_lock() releases a locked play. + + Tests that the release_play_lock helper function correctly: + - Sets play.locked = False + - Commits the change to the database + """ + mock_play = MagicMock() + mock_play.id = 400 + mock_play.locked = True + mock_play.complete = False + + release_play_lock(mock_session, mock_play) + + assert mock_play.locked is False + mock_session.add.assert_called_once_with(mock_play) + mock_session.commit.assert_called_once() + + +def test_release_play_lock_handles_unlocked_play(mock_session): + """ + Verify release_play_lock() safely handles already unlocked play. + + Tests that calling release_play_lock on an already unlocked play + is a no-op and doesn't cause errors. + """ + mock_play = MagicMock() + mock_play.id = 400 + mock_play.locked = False + mock_play.complete = True + + # Should not raise exception even if play is already unlocked + release_play_lock(mock_session, mock_play) + + # Should still be unlocked + assert mock_play.locked is False + + +def test_safe_play_lock_releases_on_exception(mock_session): + """ + Verify safe_play_lock context manager releases lock on exception. + + Tests that when an exception occurs within the context manager, + the play lock is automatically released before re-raising. + """ + mock_play = MagicMock() + mock_play.id = 500 + mock_play.locked = True + mock_play.complete = False + + with pytest.raises(ValueError): + with safe_play_lock(mock_session, mock_play): + # Simulate exception during command processing + raise ValueError("Test exception") + + # Lock should be released + assert mock_play.locked is False + mock_session.add.assert_called() + mock_session.commit.assert_called() + + +def test_safe_play_lock_allows_normal_completion(mock_session): + """ + Verify safe_play_lock doesn't interfere with normal completion. + + Tests that when no exception occurs, the context manager doesn't + prematurely release the lock (complete_play should handle that). + """ + mock_play = MagicMock() + mock_play.id = 600 + mock_play.locked = True + mock_play.complete = False + + with safe_play_lock(mock_session, mock_play): + # Normal processing + pass + + # Lock should remain (will be released by complete_play) + # Note: The finally block will force unlock, but this simulates + # the case where complete_play() is called within the context + mock_play.complete = True + + with safe_play_lock(mock_session, mock_play): + pass + + # Completed play should not be unlocked by context manager diff --git a/utilities/dropdown.py b/utilities/dropdown.py index 706b6d8..0dde48c 100644 --- a/utilities/dropdown.py +++ b/utilities/dropdown.py @@ -10,6 +10,7 @@ from sqlmodel import Session from api_calls import db_delete, db_get, db_post from exceptions import CardNotFoundException, LegalityCheckNotRequired, LineupsMissingException, PlayNotFoundException, PositionNotFoundException, log_exception, log_errors +from play_lock import release_play_lock, safe_play_lock from helpers import DEFENSE_NO_PITCHER_LITERAL, get_card_embeds, position_name_to_abbrev, random_insult from in_game.game_helpers import legal_check from in_game.gameplay_models import Game, Lineup, Play, Team @@ -220,46 +221,48 @@ class SelectReliefPitcher(discord.ui.Select): ) return - await get_position(self.session, human_rp_card, 'P') - if human_rp_card.pitcherscouting.pitchingcard.relief_rating < 2: - this_play.in_pow = True - - logger.info(f'De-activating the old pitcher') - this_play.pitcher.active = False - self.session.add(this_play.pitcher) + # Lock the play to prevent concurrent modifications + with safe_play_lock(self.session, this_play): + await get_position(self.session, human_rp_card, 'P') + if human_rp_card.pitcherscouting.pitchingcard.relief_rating < 2: + this_play.in_pow = True - logger.info(f'Checking for batting order != 10 ({self.batting_order})') - if self.batting_order != 10: - logger.info(f'Getting the player in the {self.batting_order} spot') - this_lineup = get_one_lineup(self.session, self.game, self.team, active=True, batting_order=self.batting_order) - logger.info(f'subbing lineup: {this_lineup.player.name_with_desc}') - # if this_lineup != this_play.pitcher: - this_lineup.active = False - self.session.add(this_lineup) + logger.info(f'De-activating the old pitcher') + this_play.pitcher.active = False + self.session.add(this_play.pitcher) - logger.info(f'Adding the RP lineup') - human_rp_lineup = Lineup( - team_id=self.team.id, - player_id=human_rp_card.player.id, - card_id=self.values[0], - position='P', - batting_order=self.batting_order, - is_fatigued=False, - game=self.game, - replacing_id=this_play.pitcher.id, - after_play=max(this_play.play_num - 1, 0) - ) - self.session.add(human_rp_lineup) + logger.info(f'Checking for batting order != 10 ({self.batting_order})') + if self.batting_order != 10: + logger.info(f'Getting the player in the {self.batting_order} spot') + this_lineup = get_one_lineup(self.session, self.game, self.team, active=True, batting_order=self.batting_order) + logger.info(f'subbing lineup: {this_lineup.player.name_with_desc}') + # if this_lineup != this_play.pitcher: + this_lineup.active = False + self.session.add(this_lineup) - logger.info(f'Setting new pitcher on current play') - this_play.pitcher = human_rp_lineup - self.session.add(this_play) + logger.info(f'Adding the RP lineup') + human_rp_lineup = Lineup( + team_id=self.team.id, + player_id=human_rp_card.player.id, + card_id=self.values[0], + position='P', + batting_order=self.batting_order, + is_fatigued=False, + game=self.game, + replacing_id=this_play.pitcher.id, + after_play=max(this_play.play_num - 1, 0) + ) + self.session.add(human_rp_lineup) - logger.info(f'Committing changes') - try: - self.session.commit() - except Exception as e: - log_exception(e, 'Couldn\'t commit database changes') + logger.info(f'Setting new pitcher on current play') + this_play.pitcher = human_rp_lineup + self.session.add(this_play) + + logger.info(f'Committing changes') + try: + self.session.commit() + except Exception as e: + log_exception(e, 'Couldn\'t commit database changes') try: logger.info(f'Responding to player') @@ -431,110 +434,112 @@ class SelectBatterSub(discord.ui.Select): if this_play is None: log_exception(PlayNotFoundException, 'Play not found during substitution') logger.info(f'this_play: {this_play}') - - last_lineup = get_one_lineup( - session=self.session, - this_game=self.game, - this_team=self.team, - active=True, - batting_order=self.batting_order - ) - same_position = await ask_confirm( - interaction, - question=f'Will **{human_batter_card.player.name}** replace {last_lineup.player.name} as the {last_lineup.position}?', - label_type='yes' - ) - - if same_position: - logger.info(f'same_position is True') - position = last_lineup.position - # pos_text = '' - # view = None - else: - logger.info(f'same_position is False') - position = await ask_position(interaction) - - if position == 'PH/PR': - if this_play.batter == last_lineup: - position = 'PH' - else: - position = 'PR' - - logger.info(f'Deactivating last_lineup') - try: - last_lineup.active = False - self.session.add(last_lineup) - self.session.flush() # Flush to ensure the change is applied - logger.info(f'Set lineup ID {last_lineup.id} as inactive') - except Exception as e: - log_exception(e) - - logger.info(f'new position: {position}') - if position not in ['DH', 'PR', 'PH']: - logger.info(f'go get position rating') - try: - pos_rating = await get_position(self.session, human_batter_card, position) - except PositionNotFoundException as e: - logger.error(f'Position check failed for {human_batter_card.player.name_with_desc} at {position}, rolling back session') - self.session.rollback() - await interaction.edit_original_response( - content=f'Uh oh, I cannot find {position} ratings for {human_batter_card.player.name_with_desc}. Please go double-check this sub and run again.', - view=None - ) - return - - logger.info(f'Creating new lineup record') - human_bat_lineup = Lineup( - team=self.team, - player=human_batter_card.player, - card=human_batter_card, - position=position, - batting_order=self.batting_order, - game=self.game, - after_play=max(this_play.play_num - 1, 0), - replacing_id=last_lineup.id - ) - logger.info(f'adding lineup to session: {human_bat_lineup}') - self.session.add(human_bat_lineup) - # self.session.commit() - - logger.info(f'Inserted player {human_batter_card.player_id} (card {human_batter_card.id}) in the {self.batting_order} spot') - is_pinch_runner = False - if this_play.batter == last_lineup: - logger.info(f'Setting new sub to current play batter') - this_play.batter = human_bat_lineup - this_play.batter_pos = position - elif this_play.on_first == last_lineup: - logger.info(f'Setting new sub to run at first - this is a pinch runner') - this_play.on_first = human_bat_lineup - is_pinch_runner = True - elif this_play.on_second == last_lineup: - logger.info(f'Setting new sub to run at second - this is a pinch runner') - this_play.on_second = human_bat_lineup - is_pinch_runner = True - elif this_play.on_third == last_lineup: - logger.info(f'Setting new sub to run at third - this is a pinch runner') - this_play.on_third = human_bat_lineup - is_pinch_runner = True - - logger.info(f'Adding play to session: {this_play}') - self.session.add(this_play) - self.session.commit() - - # If this is a pinch runner, create an entry Play record for them - if is_pinch_runner: - # Import inside function to avoid circular import - from command_logic.logic_gameplay import create_pinch_runner_entry_play - - logger.info(f'Creating pinch runner entry Play for {human_bat_lineup.player.name_with_desc}') - create_pinch_runner_entry_play( + # Lock the play to prevent concurrent modifications + with safe_play_lock(self.session, this_play): + last_lineup = get_one_lineup( session=self.session, - game=self.game, - current_play=this_play, - pinch_runner_lineup=human_bat_lineup + this_game=self.game, + this_team=self.team, + active=True, + batting_order=self.batting_order ) + same_position = await ask_confirm( + interaction, + question=f'Will **{human_batter_card.player.name}** replace {last_lineup.player.name} as the {last_lineup.position}?', + label_type='yes' + ) + + if same_position: + logger.info(f'same_position is True') + position = last_lineup.position + # pos_text = '' + # view = None + else: + logger.info(f'same_position is False') + position = await ask_position(interaction) + + if position == 'PH/PR': + if this_play.batter == last_lineup: + position = 'PH' + else: + position = 'PR' + + logger.info(f'Deactivating last_lineup') + try: + last_lineup.active = False + self.session.add(last_lineup) + self.session.flush() # Flush to ensure the change is applied + logger.info(f'Set lineup ID {last_lineup.id} as inactive') + except Exception as e: + log_exception(e) + + logger.info(f'new position: {position}') + if position not in ['DH', 'PR', 'PH']: + logger.info(f'go get position rating') + try: + pos_rating = await get_position(self.session, human_batter_card, position) + except PositionNotFoundException as e: + logger.error(f'Position check failed for {human_batter_card.player.name_with_desc} at {position}, rolling back session') + self.session.rollback() + await interaction.edit_original_response( + content=f'Uh oh, I cannot find {position} ratings for {human_batter_card.player.name_with_desc}. Please go double-check this sub and run again.', + view=None + ) + return + + logger.info(f'Creating new lineup record') + human_bat_lineup = Lineup( + team=self.team, + player=human_batter_card.player, + card=human_batter_card, + position=position, + batting_order=self.batting_order, + game=self.game, + after_play=max(this_play.play_num - 1, 0), + replacing_id=last_lineup.id + ) + logger.info(f'adding lineup to session: {human_bat_lineup}') + self.session.add(human_bat_lineup) + # self.session.commit() + + logger.info(f'Inserted player {human_batter_card.player_id} (card {human_batter_card.id}) in the {self.batting_order} spot') + is_pinch_runner = False + if this_play.batter == last_lineup: + logger.info(f'Setting new sub to current play batter') + this_play.batter = human_bat_lineup + this_play.batter_pos = position + elif this_play.on_first == last_lineup: + logger.info(f'Setting new sub to run at first - this is a pinch runner') + this_play.on_first = human_bat_lineup + is_pinch_runner = True + elif this_play.on_second == last_lineup: + logger.info(f'Setting new sub to run at second - this is a pinch runner') + this_play.on_second = human_bat_lineup + is_pinch_runner = True + elif this_play.on_third == last_lineup: + logger.info(f'Setting new sub to run at third - this is a pinch runner') + this_play.on_third = human_bat_lineup + is_pinch_runner = True + + logger.info(f'Adding play to session: {this_play}') + self.session.add(this_play) + self.session.commit() + + # If this is a pinch runner, create an entry Play record for them + if is_pinch_runner: + # Import inside function to avoid circular import + from command_logic.logic_gameplay import create_pinch_runner_entry_play + + logger.info(f'Creating pinch runner entry Play for {human_bat_lineup.player.name_with_desc}') + create_pinch_runner_entry_play( + session=self.session, + game=self.game, + current_play=this_play, + pinch_runner_lineup=human_bat_lineup + ) + # if not same_position: # pos_dict_list = { # 'Pinch Hitter': 'PH',