def _get_mock_runner_obj_from_container(self, pack, user, sandbox=None):
container = RunnerContainer()
runnertype_db = mock.Mock()
runnertype_db.name = "python-script"
runnertype_db.runner_package = "python_runner"
runnertype_db.runner_module = "python_runner"
action_db = mock.Mock()
action_db.pack = pack
action_db.entry_point = "foo.py"
liveaction_db = mock.Mock()
liveaction_db.id = "123"
liveaction_db.context = {"user": user}
runner = container._get_runner(
runner_type_db=runnertype_db,
action_db=action_db,
liveaction_db=liveaction_db,
)
runner.execution = MOCK_EXECUTION
runner.action = action_db
runner.runner_parameters = {}
if sandbox is not None:
runner._sandbox = sandbox
return runner
def test_get_runner_module_fail(self):
runnertype_db = RunnerTypeDB()
runnertype_db.runner_module = 'absent.module'
runner_container = RunnerContainer()
runner = None
try:
runner = runner_container._get_runner(runnertype_db)
except ActionRunnerCreateError:
pass
self.assertFalse(runner, 'TestRunner must be valid.')
def test_get_runner_module_fail(self):
runnertype_db = RunnerTypeDB()
runnertype_db.runner_module = 'absent.module'
runner_container = RunnerContainer()
runner = None
try:
runner = runner_container._get_runner(runnertype_db)
except ActionRunnerCreateError:
pass
self.assertFalse(runner, 'TestRunner must be valid.')
def setUpClass(cls):
super(TestActionExecutionService, cls).setUpClass()
cls.runner = RunnerTypeAPI(**RUNNER)
cls.runnerdb = RunnerType.add_or_update(RunnerTypeAPI.to_model(cls.runner))
cls.action = ActionAPI(**ACTION)
cls.actiondb = Action.add_or_update(ActionAPI.to_model(cls.action))
cls.container = RunnerContainer()
def setUpClass(cls):
super(TestActionExecutionService, cls).setUpClass()
cls.runner = RunnerTypeAPI(**RUNNER)
cls.runnerdb = RunnerType.add_or_update(
RunnerTypeAPI.to_model(cls.runner))
runner_api = RunnerTypeAPI(**RUNNER_ACTION_CHAIN)
RunnerType.add_or_update(RunnerTypeAPI.to_model(runner_api))
cls.actions = {
ACTION['name']:
ActionAPI(**ACTION),
ACTION_WORKFLOW['name']:
ActionAPI(**ACTION_WORKFLOW),
ACTION_OVR_PARAM['name']:
ActionAPI(**ACTION_OVR_PARAM),
ACTION_OVR_PARAM_MUTABLE['name']:
ActionAPI(**ACTION_OVR_PARAM_MUTABLE),
ACTION_OVR_PARAM_IMMUTABLE['name']:
ActionAPI(**ACTION_OVR_PARAM_IMMUTABLE),
ACTION_OVR_PARAM_BAD_ATTR['name']:
ActionAPI(**ACTION_OVR_PARAM_BAD_ATTR),
ACTION_OVR_PARAM_BAD_ATTR_NOOP['name']:
ActionAPI(**ACTION_OVR_PARAM_BAD_ATTR_NOOP)
}
cls.actiondbs = {
name: Action.add_or_update(ActionAPI.to_model(action))
for name, action in six.iteritems(cls.actions)
}
cls.container = RunnerContainer()
def _get_mock_runner_obj_from_container(self, pack, user):
container = RunnerContainer()
runnertype_db = mock.Mock()
runnertype_db.runner_module = 'python_runner'
action_db = mock.Mock()
action_db.pack = pack
action_db.entry_point = 'foo.py'
liveaction_db = mock.Mock()
liveaction_db.id = '123'
liveaction_db.context = {'user': user}
runner = container._get_runner(runnertype_db=runnertype_db,
action_db=action_db,
liveaction_db=liveaction_db)
runner.execution = MOCK_EXECUTION
runner.action = self._get_mock_action_obj()
runner.runner_parameters = {}
return runner
def _get_mock_runner_obj_from_container(self, pack, user, sandbox=None):
container = RunnerContainer()
runnertype_db = mock.Mock()
runnertype_db.runner_package = 'python_runner'
runnertype_db.runner_module = 'python_runner'
action_db = mock.Mock()
action_db.pack = pack
action_db.entry_point = 'foo.py'
liveaction_db = mock.Mock()
liveaction_db.id = '123'
liveaction_db.context = {'user': user}
runner = container._get_runner(runner_type_db=runnertype_db, action_db=action_db,
liveaction_db=liveaction_db)
runner.execution = MOCK_EXECUTION
runner.action = action_db
runner.runner_parameters = {}
if sandbox is not None:
runner._sandbox = sandbox
return runner
def __init__(self, connection, queues):
super(ActionExecutionDispatcher, self).__init__(connection, queues)
self.container = RunnerContainer()
self._running_liveactions = set()
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
def test_get_runner_module(self):
runnertype_db = RunnerContainerTest.runnertype_db
runner_container = RunnerContainer()
runner = runner_container._get_runner(runnertype_db)
self.assertTrue(runner is not None, 'TestRunner must be valid.')
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
def __init__(self, connection, queues):
super(ActionExecutionDispatcher, self).__init__(connection, queues)
self.container = RunnerContainer()
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(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):
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 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
def __init__(self, connection, queues):
super(ActionExecutionDispatcher, self).__init__(connection, queues)
self.container = RunnerContainer()
self._running_liveactions = set()
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
def __init__(self, connection):
self.connection = connection
self.container = RunnerContainer()
self._dispatcher = BufferedDispatcher()
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
def __init__(self, connection):
self.connection = connection
self.container = RunnerContainer()
self._dispatcher = BufferedDispatcher()
def test_get_runner_module(self):
runnertype_db = RunnerContainerTest.runnertype_db
runner_container = RunnerContainer()
runner = runner_container._get_runner(runnertype_db)
self.assertTrue(runner is not None, 'TestRunner must be valid.')
