diff --git a/src/deadline_worker_agent/sessions/session.py b/src/deadline_worker_agent/sessions/session.py index 43e4f548..20144fe0 100644 --- a/src/deadline_worker_agent/sessions/session.py +++ b/src/deadline_worker_agent/sessions/session.py @@ -997,6 +997,9 @@ def _action_updated_impl( # UpdateWorkerSchedule request if so. self._current_action = None + completed_status = OPENJD_ACTION_STATE_TO_DEADLINE_COMPLETED_STATUS.get( + action_status.state, None + ) self._report_action_update( SessionActionStatus( id=current_action.definition.id, @@ -1004,11 +1007,16 @@ def _action_updated_impl( start_time=current_action.start_time, end_time=now if action_status.state != ActionState.RUNNING else None, update_time=now if action_status.state == ActionState.RUNNING else None, - completed_status=OPENJD_ACTION_STATE_TO_DEADLINE_COMPLETED_STATUS.get( - action_status.state, None - ), + completed_status=completed_status, ) ) + logger.info( + "[%s] Action %s: %s completed as %s", + self.id, + current_action.definition.id, + current_action.definition.human_readable(), + completed_status, + ) def _sync_asset_outputs( self, diff --git a/test/unit/sessions/test_session.py b/test/unit/sessions/test_session.py index 78904756..9ea2581b 100644 --- a/test/unit/sessions/test_session.py +++ b/test/unit/sessions/test_session.py @@ -212,6 +212,34 @@ def failed_action_status(request: pytest.FixtureRequest) -> ActionStatus: return request.param +@pytest.fixture( + params=( + ActionStatus( + exit_code=1, + state=ActionState.CANCELED, + ), + ActionStatus( + exit_code=1, + state=ActionState.CANCELED, + fail_message="canceled message", + ), + ActionStatus( + exit_code=1, + state=ActionState.CANCELED, + progress=50, + ), + ), + ids=( + "no-fail-msg-progress", + "no-progress", + "no-fail-msg", + ), +) +def canceled_action_status(request: pytest.FixtureRequest) -> ActionStatus: + """A fixture providing a canceled Open Job Description ActionStatus""" + return request.param + + @pytest.fixture( params=( ActionStatus( @@ -1147,6 +1175,78 @@ def test_success_task_run_fail_output_sync( assert session._current_action is None, "Current session action emptied" mock_sync_asset_outputs.assert_called_once_with(current_action=current_action) + def test_logs_succeeded( + self, + action_complete_time: datetime, + current_action: CurrentAction, + mock_mod_logger: MagicMock, + session: Session, + succeess_action_status: ActionStatus, + ) -> None: + """Tests that succeeded actions are logged""" + # WHEN + session._action_updated_impl( + action_status=succeess_action_status, + now=action_complete_time, + ) + + # THEN + mock_mod_logger.info.assert_called_once_with( + "[%s] Action %s: %s completed as %s", + session.id, + current_action.definition.id, + current_action.definition.human_readable(), + "SUCCEEDED", + ) + + def test_logs_failed( + self, + action_complete_time: datetime, + current_action: CurrentAction, + mock_mod_logger: MagicMock, + session: Session, + failed_action_status: ActionStatus, + ) -> None: + """Tests that failed actions are logged""" + # WHEN + session._action_updated_impl( + action_status=failed_action_status, + now=action_complete_time, + ) + + # THEN + mock_mod_logger.info.assert_called_once_with( + "[%s] Action %s: %s completed as %s", + session.id, + current_action.definition.id, + current_action.definition.human_readable(), + "FAILED", + ) + + def test_logs_canceled( + self, + action_complete_time: datetime, + current_action: CurrentAction, + mock_mod_logger: MagicMock, + session: Session, + canceled_action_status: ActionStatus, + ) -> None: + """Tests that canceled actions are logged""" + # WHEN + session._action_updated_impl( + action_status=canceled_action_status, + now=action_complete_time, + ) + + # THEN + mock_mod_logger.info.assert_called_once_with( + "[%s] Action %s: %s completed as %s", + session.id, + current_action.definition.id, + current_action.definition.human_readable(), + "CANCELED", + ) + @pytest.mark.usefixtures("mock_openjd_session") class TestStartCancelingCurrentAction: