class Worker(ConsumerMixin): def __init__(self, connection): self.connection = connection self.container = RunnerContainer() self._dispatcher = BufferedDispatcher() def shutdown(self): self._dispatcher.shutdown() def get_consumers(self, Consumer, channel): consumer = Consumer(queues=[ACTIONRUNNER_WORK_Q], accept=['pickle'], callbacks=[self.process_task]) # use prefetch_count=1 for fair dispatch. This way workers that finish an item get the next # task and the work does not get queued behind any single large item. consumer.qos(prefetch_count=1) return [consumer] def process_task(self, body, message): # LOG.debug('process_task') # LOG.debug(' body: %s', body) # LOG.debug(' message.properties: %s', message.properties) # LOG.debug(' message.delivery_info: %s', message.delivery_info) try: self._dispatcher.dispatch(self._do_process_task, body) finally: message.ack() def _do_process_task(self, body): try: self.execute_action(body) except Exception: LOG.exception('execute_action failed. Message body : %s', body) def execute_action(self, liveaction): try: liveaction_db = get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise # Update liveaction status to "running" liveaction_db = update_liveaction_status(status=LIVEACTION_STATUS_RUNNING, liveaction_id=liveaction_db.id) # Launch action LOG.audit('Launching action execution.', extra={'liveaction': liveaction_db.to_serializable_dict()}) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) except Exception: liveaction_db = update_liveaction_status(status=LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id) raise if not result: raise ActionRunnerException('Failed to execute action.') return result
class Worker(ConsumerMixin): def __init__(self, connection): self.connection = connection self.container = RunnerContainer() self._dispatcher = BufferedDispatcher() def shutdown(self): self._dispatcher.shutdown() def get_consumers(self, Consumer, channel): consumer = Consumer(queues=[ACTIONRUNNER_WORK_Q], accept=['pickle'], callbacks=[self.process_task]) # use prefetch_count=1 for fair dispatch. This way workers that finish an item get the next # task and the work does not get queued behind any single large item. consumer.qos(prefetch_count=1) return [consumer] def process_task(self, body, message): # LOG.debug('process_task') # LOG.debug(' body: %s', body) # LOG.debug(' message.properties: %s', message.properties) # LOG.debug(' message.delivery_info: %s', message.delivery_info) try: self._dispatcher.dispatch(self._do_process_task, body) finally: message.ack() def _do_process_task(self, body): try: self.execute_action(body) except: LOG.exception('execute_action failed. Message body : %s', body) def execute_action(self, actionexecution): try: actionexec_db = get_actionexec_by_id(actionexecution.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find ActionExecution %s in the database.', actionexecution.id) raise # Update ActionExecution status to "running" actionexec_db = update_actionexecution_status(ACTIONEXEC_STATUS_RUNNING, actionexec_db.id) # Launch action LOG.audit('Launching action execution.', extra={'actionexec': actionexec_db.to_serializable_dict()}) try: result = self.container.dispatch(actionexec_db) LOG.debug('Runner dispatch produced result: %s', result) except Exception: actionexec_db = update_actionexecution_status(ACTIONEXEC_STATUS_FAILED, actionexec_db.id) raise if not result: raise ActionRunnerException('Failed to execute action.') return result
class ActionExecutionDispatcher(consumers.MessageHandler): message_type = LiveActionDB def __init__(self, connection, queues): super(ActionExecutionDispatcher, self).__init__(connection, queues) self.container = RunnerContainer() def process(self, liveaction): """Dispatches the LiveAction to appropriate action runner. LiveAction in statuses other than "scheduled" are ignored. If LiveAction is already canceled and result is empty, the LiveAction is updated with a generic exception message. :param liveaction: Scheduled action execution request. :type liveaction: ``st2common.models.db.liveaction.LiveActionDB`` :rtype: ``dict`` """ if liveaction.status == action_constants.LIVEACTION_STATUS_CANCELED: LOG.info('%s is not executing %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) if not liveaction.result: action_utils.update_liveaction_status( status=liveaction.status, result={'message': 'Action execution canceled by user.'}, liveaction_id=liveaction.id) return if liveaction.status != action_constants.LIVEACTION_STATUS_SCHEDULED: LOG.info('%s is not executing %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) return try: liveaction_db = action_utils.get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Launching action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction.status) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) if not result: raise ActionRunnerException('Failed to execute action.') except Exception as e: extra['error'] = str(e) LOG.info('Action "%s" failed: %s' % (liveaction_db.action, str(e)), extra=extra) liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id) raise return result
class ActionExecutionDispatcher(MessageHandler): message_type = LiveActionDB def __init__(self, connection, queues): super(ActionExecutionDispatcher, self).__init__(connection, queues) self.container = RunnerContainer() self._running_liveactions = set() def get_queue_consumer(self, connection, queues): # We want to use a special ActionsQueueConsumer which uses 2 dispatcher pools return ActionsQueueConsumer(connection=connection, queues=queues, handler=self) def process(self, liveaction): """Dispatches the LiveAction to appropriate action runner. LiveAction in statuses other than "scheduled" and "canceling" are ignored. If LiveAction is already canceled and result is empty, the LiveAction is updated with a generic exception message. :param liveaction: Action execution request. :type liveaction: ``st2common.models.db.liveaction.LiveActionDB`` :rtype: ``dict`` """ if liveaction.status == action_constants.LIVEACTION_STATUS_CANCELED: LOG.info('%s is not executing %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) if not liveaction.result: updated_liveaction = action_utils.update_liveaction_status( status=liveaction.status, result={'message': 'Action execution canceled by user.'}, liveaction_id=liveaction.id) executions.update_execution(updated_liveaction) return if liveaction.status not in ACTIONRUNNER_DISPATCHABLE_STATES: LOG.info('%s is not dispatching %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) return try: liveaction_db = action_utils.get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise if liveaction.status != liveaction_db.status: LOG.warning( 'The status of liveaction %s has changed from %s to %s ' 'while in the queue waiting for processing.', liveaction.id, liveaction.status, liveaction_db.status ) dispatchers = { action_constants.LIVEACTION_STATUS_SCHEDULED: self._run_action, action_constants.LIVEACTION_STATUS_CANCELING: self._cancel_action, action_constants.LIVEACTION_STATUS_PAUSING: self._pause_action, action_constants.LIVEACTION_STATUS_RESUMING: self._resume_action } return dispatchers[liveaction.status](liveaction) def shutdown(self): super(ActionExecutionDispatcher, self).shutdown() # Abandon running executions if incomplete while self._running_liveactions: liveaction_id = self._running_liveactions.pop() try: executions.abandon_execution_if_incomplete(liveaction_id=liveaction_id) except: LOG.exception('Failed to abandon liveaction %s.', liveaction_id) def _run_action(self, liveaction_db): # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id) self._running_liveactions.add(liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Launching action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) extra = {'liveaction_db': liveaction_db} try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) if not result and not liveaction_db.action_is_workflow: raise ActionRunnerException('Failed to execute action.') except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Action "%s" failed: %s' % (liveaction_db.action, str(ex)), extra=extra) liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id, result={'error': str(ex), 'traceback': ''.join(traceback.format_tb(tb, 20))}) executions.update_execution(liveaction_db) raise finally: # In the case of worker shutdown, the items are removed from _running_liveactions. # As the subprocesses for action executions are terminated, this finally block # will be executed. Set remove will result in KeyError if item no longer exists. # Use set discard to not raise the KeyError. self._running_liveactions.discard(liveaction_db.id) return result def _cancel_action(self, liveaction_db): action_execution_db = ActionExecution.get(liveaction__id=str(liveaction_db.id)) extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Canceling action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Failed to cancel action execution %s.' % (liveaction_db.id), extra=extra) raise return result def _pause_action(self, liveaction_db): action_execution_db = ActionExecution.get(liveaction__id=str(liveaction_db.id)) extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Pausing action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Failed to pause action execution %s.' % (liveaction_db.id), extra=extra) raise return result def _resume_action(self, liveaction_db): action_execution_db = ActionExecution.get(liveaction__id=str(liveaction_db.id)) extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Resuming action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Failed to resume action execution %s.' % (liveaction_db.id), extra=extra) raise # Cascade the resume upstream if action execution is child of an orquesta workflow. # The action service request_resume function is not used here because we do not want # other peer subworkflows to be resumed. if 'orquesta' in action_execution_db.context and 'parent' in action_execution_db.context: wf_svc.handle_action_execution_resume(action_execution_db) return result
class Worker(ConsumerMixin): def __init__(self, connection): self.connection = connection self.container = RunnerContainer() self._dispatcher = BufferedDispatcher() def shutdown(self): self._dispatcher.shutdown() def get_consumers(self, Consumer, channel): consumer = Consumer(queues=[ACTIONRUNNER_WORK_Q], accept=['pickle'], callbacks=[self.process_task]) # use prefetch_count=1 for fair dispatch. This way workers that finish an item get the next # task and the work does not get queued behind any single large item. consumer.qos(prefetch_count=1) return [consumer] def process_task(self, body, message): # LOG.debug('process_task') # LOG.debug(' body: %s', body) # LOG.debug(' message.properties: %s', message.properties) # LOG.debug(' message.delivery_info: %s', message.delivery_info) try: self._dispatcher.dispatch(self._do_process_task, body) finally: message.ack() def _do_process_task(self, body): try: self.execute_action(body) except Exception: LOG.exception('execute_action failed. Message body : %s', body) def execute_action(self, liveaction): # Note: We only want to execute actions which haven't completed yet if liveaction.status in [LIVEACTION_STATUS_SUCCEEDED, LIVEACTION_STATUS_FAILED]: LOG.info('Ignoring liveaction %s which has already finished', liveaction.id) return try: liveaction_db = get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = update_liveaction_status(status=LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db} LOG.audit('Launching action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('{~}action_execution: %s / {~}live_action: %s', action_execution_db.id, liveaction_db.id) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) if not result: raise ActionRunnerException('Failed to execute action.') except Exception: liveaction_db = update_liveaction_status(status=LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id) raise return result
class ActionExecutionDispatcher(consumers.MessageHandler): message_type = LiveActionDB def __init__(self, connection, queues): super(ActionExecutionDispatcher, self).__init__(connection, queues) self.container = RunnerContainer() self._running_liveactions = set() def process(self, liveaction): """Dispatches the LiveAction to appropriate action runner. LiveAction in statuses other than "scheduled" and "canceling" are ignored. If LiveAction is already canceled and result is empty, the LiveAction is updated with a generic exception message. :param liveaction: Action execution request. :type liveaction: ``st2common.models.db.liveaction.LiveActionDB`` :rtype: ``dict`` """ if liveaction.status == action_constants.LIVEACTION_STATUS_CANCELED: LOG.info('%s is not executing %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) if not liveaction.result: updated_liveaction = action_utils.update_liveaction_status( status=liveaction.status, result={'message': 'Action execution canceled by user.'}, liveaction_id=liveaction.id) executions.update_execution(updated_liveaction) return if liveaction.status not in [ action_constants.LIVEACTION_STATUS_SCHEDULED, action_constants.LIVEACTION_STATUS_CANCELING ]: LOG.info('%s is not dispatching %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status) return try: liveaction_db = action_utils.get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise return (self._run_action(liveaction_db) if liveaction.status == action_constants.LIVEACTION_STATUS_SCHEDULED else self._cancel_action(liveaction_db)) def shutdown(self): super(ActionExecutionDispatcher, self).shutdown() # Abandon running executions if incomplete while self._running_liveactions: liveaction_id = self._running_liveactions.pop() try: executions.abandon_execution_if_incomplete( liveaction_id=liveaction_id) except: LOG.exception('Failed to abandon liveaction %s.', liveaction_id) def _run_action(self, liveaction_db): # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id) self._running_liveactions.add(liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = { 'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db } LOG.audit('Launching action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info( 'Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) extra = {'liveaction_db': liveaction_db} try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) if not result: raise ActionRunnerException('Failed to execute action.') except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Action "%s" failed: %s' % (liveaction_db.action, str(ex)), extra=extra) liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id, result={ 'error': str(ex), 'traceback': ''.join(traceback.format_tb(tb, 20)) }) executions.update_execution(liveaction_db) raise finally: self._running_liveactions.remove(liveaction_db.id) return result def _cancel_action(self, liveaction_db): action_execution_db = ActionExecution.get( liveaction__id=str(liveaction_db.id)) extra = { 'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db } LOG.audit('Canceling action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info( 'Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) except: _, ex, tb = sys.exc_info() extra['error'] = str(ex) LOG.info('Failed to cancel action execution %s.' % (liveaction_db.id), extra=extra) raise return result
class Worker(ConsumerMixin): def __init__(self, connection): self.connection = connection self.container = RunnerContainer() self._dispatcher = BufferedDispatcher() def shutdown(self): self._dispatcher.shutdown() def get_consumers(self, Consumer, channel): consumer = Consumer(queues=[ACTIONRUNNER_WORK_Q], accept=['pickle'], callbacks=[self.process_task]) # use prefetch_count=1 for fair dispatch. This way workers that finish an item get the next # task and the work does not get queued behind any single large item. consumer.qos(prefetch_count=1) return [consumer] def process_task(self, body, message): # LOG.debug('process_task') # LOG.debug(' body: %s', body) # LOG.debug(' message.properties: %s', message.properties) # LOG.debug(' message.delivery_info: %s', message.delivery_info) try: self._dispatcher.dispatch(self._do_process_task, body) finally: message.ack() def _do_process_task(self, body): try: self.execute_action(body) except Exception: LOG.exception('execute_action failed. Message body : %s', body) def execute_action(self, liveaction): # Note: We only want to execute actions which haven't completed yet if liveaction.status in [ LIVEACTION_STATUS_SUCCEEDED, LIVEACTION_STATUS_FAILED ]: LOG.info('Ignoring liveaction %s which has already finished', liveaction.id) return try: liveaction_db = get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception('Failed to find liveaction %s in the database.', liveaction.id) raise # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = update_liveaction_status( status=LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = { 'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db } LOG.audit('Launching action execution.', extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info('{~}action_execution: %s / {~}live_action: %s', action_execution_db.id, liveaction_db.id) try: result = self.container.dispatch(liveaction_db) LOG.debug('Runner dispatch produced result: %s', result) if not result: raise ActionRunnerException('Failed to execute action.') except Exception: liveaction_db = update_liveaction_status( status=LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id) raise return result
class ActionExecutionDispatcher(MessageHandler): message_type = LiveActionDB def __init__(self, connection, queues): super(ActionExecutionDispatcher, self).__init__(connection, queues) self.container = RunnerContainer() self._running_liveactions = set() def get_queue_consumer(self, connection, queues): # We want to use a special ActionsQueueConsumer which uses 2 dispatcher pools return ActionsQueueConsumer(connection=connection, queues=queues, handler=self) def process(self, liveaction): """Dispatches the LiveAction to appropriate action runner. LiveAction in statuses other than "scheduled" and "canceling" are ignored. If LiveAction is already canceled and result is empty, the LiveAction is updated with a generic exception message. :param liveaction: Action execution request. :type liveaction: ``st2common.models.db.liveaction.LiveActionDB`` :rtype: ``dict`` """ if liveaction.status == action_constants.LIVEACTION_STATUS_CANCELED: LOG.info( '%s is not executing %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status, ) if not liveaction.result: updated_liveaction = action_utils.update_liveaction_status( status=liveaction.status, result={"message": "Action execution canceled by user."}, liveaction_id=liveaction.id, ) executions.update_execution(updated_liveaction) return if liveaction.status not in [ action_constants.LIVEACTION_STATUS_SCHEDULED, action_constants.LIVEACTION_STATUS_CANCELING, ]: LOG.info( '%s is not dispatching %s (id=%s) with "%s" status.', self.__class__.__name__, type(liveaction), liveaction.id, liveaction.status, ) return try: liveaction_db = action_utils.get_liveaction_by_id(liveaction.id) except StackStormDBObjectNotFoundError: LOG.exception("Failed to find liveaction %s in the database.", liveaction.id) raise return ( self._run_action(liveaction_db) if liveaction.status == action_constants.LIVEACTION_STATUS_SCHEDULED else self._cancel_action(liveaction_db) ) def shutdown(self): super(ActionExecutionDispatcher, self).shutdown() # Abandon running executions if incomplete while self._running_liveactions: liveaction_id = self._running_liveactions.pop() try: executions.abandon_execution_if_incomplete(liveaction_id=liveaction_id) except: LOG.exception("Failed to abandon liveaction %s.", liveaction_id) def _run_action(self, liveaction_db): # stamp liveaction with process_info runner_info = system_info.get_process_info() # Update liveaction status to "running" liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_RUNNING, runner_info=runner_info, liveaction_id=liveaction_db.id ) self._running_liveactions.add(liveaction_db.id) action_execution_db = executions.update_execution(liveaction_db) # Launch action extra = {"action_execution_db": action_execution_db, "liveaction_db": liveaction_db} LOG.audit("Launching action execution.", extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info( 'Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status, ) extra = {"liveaction_db": liveaction_db} try: result = self.container.dispatch(liveaction_db) LOG.debug("Runner dispatch produced result: %s", result) if not result: raise ActionRunnerException("Failed to execute action.") except: _, ex, tb = sys.exc_info() extra["error"] = str(ex) LOG.info('Action "%s" failed: %s' % (liveaction_db.action, str(ex)), extra=extra) liveaction_db = action_utils.update_liveaction_status( status=action_constants.LIVEACTION_STATUS_FAILED, liveaction_id=liveaction_db.id, result={"error": str(ex), "traceback": "".join(traceback.format_tb(tb, 20))}, ) executions.update_execution(liveaction_db) raise finally: self._running_liveactions.remove(liveaction_db.id) return result def _cancel_action(self, liveaction_db): action_execution_db = ActionExecution.get(liveaction__id=str(liveaction_db.id)) extra = {"action_execution_db": action_execution_db, "liveaction_db": liveaction_db} LOG.audit("Canceling action execution.", extra=extra) # the extra field will not be shown in non-audit logs so temporarily log at info. LOG.info( 'Dispatched {~}action_execution: %s / {~}live_action: %s with "%s" status.', action_execution_db.id, liveaction_db.id, liveaction_db.status, ) try: result = self.container.dispatch(liveaction_db) LOG.debug("Runner dispatch produced result: %s", result) except: _, ex, tb = sys.exc_info() extra["error"] = str(ex) LOG.info("Failed to cancel action execution %s." % (liveaction_db.id), extra=extra) raise return result