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)
executions.update_execution(liveaction_db)
# 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
def _mark_inquiry_complete(self, inquiry_id, result):
"""Mark Inquiry as completed
This function updates the local LiveAction and Execution with a successful
status as well as call the "post_run" function for the Inquirer runner so that
the appropriate callback function is executed
:param inquiry: The Inquiry for which the response is given
:param requester_user: The user providing the response
:rtype: bool - True if requester_user is able to respond. False if not.
"""
# Update inquiry's execution result with a successful status and the validated response
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
runner_info=system_info.get_process_info(),
result=result,
liveaction_id=inquiry_id)
executions.update_execution(liveaction_db)
# Call Inquiry runner's post_run to trigger callback to workflow
runner_container = get_runner_container()
action_db = get_action_by_ref(liveaction_db.action)
runnertype_db = get_runnertype_by_name(action_db.runner_type['name'])
runner = runner_container._get_runner(runnertype_db, action_db, liveaction_db)
runner.post_run(status=action_constants.LIVEACTION_STATUS_SUCCEEDED, result=result)
return liveaction_db
def _update_status(self, liveaction_id, status, result, context):
try:
LOG.debug('Setting status: %s for liveaction: %s', status, liveaction_id)
liveaction_db, state_changed = self._update_live_action_db(
liveaction_id, status, result, context)
except Exception as e:
LOG.exception(
'Cannot update liveaction '
'(id: %s, status: %s, result: %s).' % (
liveaction_id, status, result)
)
raise e
try:
executions.update_execution(liveaction_db, publish=state_changed)
extra = {'liveaction_db': liveaction_db}
LOG.debug('Updated liveaction after run', extra=extra)
except Exception as e:
LOG.exception(
'Cannot update action execution for liveaction '
'(id: %s, status: %s, result: %s).' % (
liveaction_id, status, result)
)
raise e
return liveaction_db
def _run_action(self, liveaction_db):
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
return result
def _update_status(self, liveaction_id, status, result, context):
try:
LOG.debug('Setting status: %s for liveaction: %s', status, liveaction_id)
liveaction_db, state_changed = self._update_live_action_db(
liveaction_id, status, result, context)
except Exception as e:
LOG.exception(
'Cannot update liveaction '
'(id: %s, status: %s, result: %s).' % (
liveaction_id, status, result)
)
raise e
try:
executions.update_execution(liveaction_db, publish=state_changed)
extra = {'liveaction_db': liveaction_db}
LOG.debug('Updated liveaction after run', extra=extra)
except Exception as e:
LOG.exception(
'Cannot update action execution for liveaction '
'(id: %s, status: %s, result: %s).' % (
liveaction_id, status, result)
)
raise e
return liveaction_db
def respond(inquiry, response, requester=None):
# Set requester to system user is not provided.
if not requester:
requester = cfg.CONF.system_user.user
# Retrieve the liveaction from the database.
liveaction_db = lv_db_access.LiveAction.get_by_id(
inquiry.liveaction.get("id"))
# Resume the parent workflow first. If the action execution for the inquiry is updated first,
# it triggers handling of the action execution completion which will interact with the paused
# parent workflow. The resuming logic that is executed here will then race with the completion
# of the inquiry action execution, which will randomly result in the parent workflow stuck in
# paused state.
if liveaction_db.context.get("parent"):
LOG.debug('Resuming workflow parent(s) for inquiry "%s".' %
str(inquiry.id))
# For action execution under Action Chain workflows, request the entire
# workflow to resume. Orquesta handles resume differently and so does not require root
# to resume. Orquesta allows for specifc branches to resume while other is paused. When
# there is no other paused branches, the conductor will resume the rest of the workflow.
resume_target = (
action_service.get_parent_liveaction(liveaction_db)
if workflow_service.is_action_execution_under_workflow_context(
liveaction_db) else
action_service.get_root_liveaction(liveaction_db))
if resume_target.status in action_constants.LIVEACTION_PAUSE_STATES:
action_service.request_resume(resume_target, requester)
# Succeed the liveaction and update result with the inquiry response.
LOG.debug('Updating response for inquiry "%s".' % str(inquiry.id))
result = fast_deepcopy_dict(inquiry.result)
result["response"] = response
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
end_timestamp=date_utils.get_datetime_utc_now(),
runner_info=sys_info_utils.get_process_info(),
result=result,
liveaction_id=str(liveaction_db.id),
)
# Sync the liveaction with the corresponding action execution.
execution_service.update_execution(liveaction_db)
# Invoke inquiry post run to trigger a callback to parent workflow.
LOG.debug('Invoking post run for inquiry "%s".' % str(inquiry.id))
runner_container = container.get_runner_container()
action_db = action_utils.get_action_by_ref(liveaction_db.action)
runnertype_db = action_utils.get_runnertype_by_name(
action_db.runner_type["name"])
runner = runner_container._get_runner(runnertype_db, action_db,
liveaction_db)
runner.post_run(status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
result=result)
return liveaction_db
def _do_cancel(self, runner, runnertype_db, action_db, liveaction_db):
try:
extra = {'runner': runner}
LOG.debug('Performing cancel for runner: %s', (runner.runner_id),
extra=extra)
runner.cancel()
liveaction_db = update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_CANCELED,
end_timestamp=date_utils.get_datetime_utc_now(),
liveaction_db=liveaction_db)
executions.update_execution(liveaction_db)
LOG.debug('Performing post_run for runner: %s', runner.runner_id)
result = {'error': 'Execution canceled by user.'}
runner.post_run(status=liveaction_db.status, result=result)
runner.container_service = None
except:
_, ex, tb = sys.exc_info()
# include the error message and traceback to try and provide some hints.
result = {
'error': str(ex),
'traceback': ''.join(traceback.format_tb(tb, 20))
}
LOG.exception('Failed to cancel action %s.' % (liveaction_db.id),
extra=result)
finally:
# Always clean-up the auth_token
status = liveaction_db.status
self._clean_up_auth_token(runner=runner, status=status)
return liveaction_db
def _mark_inquiry_complete(self, inquiry_id, result):
"""Mark Inquiry as completed
This function updates the local LiveAction and Execution with a successful
status as well as call the "post_run" function for the Inquirer runner so that
the appropriate callback function is executed
:param inquiry: The Inquiry for which the response is given
:param requester_user: The user providing the response
:rtype: bool - True if requester_user is able to respond. False if not.
"""
# Update inquiry's execution result with a successful status and the validated response
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
runner_info=system_info.get_process_info(),
result=result,
liveaction_id=inquiry_id)
executions.update_execution(liveaction_db)
# Call Inquiry runner's post_run to trigger callback to workflow
runner_container = get_runner_container()
action_db = get_action_by_ref(liveaction_db.action)
runnertype_db = get_runnertype_by_name(action_db.runner_type['name'])
runner = runner_container._get_runner(runnertype_db, action_db,
liveaction_db)
runner.post_run(status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
result=result)
return liveaction_db
def _do_cancel(self, runner, runnertype_db, action_db, liveaction_db):
try:
extra = {'runner': runner}
LOG.debug('Performing cancel for runner: %s', (runner.runner_id),
extra=extra)
runner.cancel()
liveaction_db = update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_CANCELED,
end_timestamp=date_utils.get_datetime_utc_now(),
liveaction_db=liveaction_db)
executions.update_execution(liveaction_db)
except:
_, ex, tb = sys.exc_info()
# include the error message and traceback to try and provide some hints.
result = {
'error': str(ex),
'traceback': ''.join(traceback.format_tb(tb, 20))
}
LOG.exception('Failed to cancel action %s.' % (liveaction_db.id),
extra=result)
return liveaction_db
def _do_cancel(self, runner, runnertype_db, action_db, liveaction_db):
try:
extra = {"runner": runner}
LOG.debug("Performing cancel for runner: %s", (runner.runner_id), extra=extra)
runner.cancel()
liveaction_db = update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_CANCELED,
end_timestamp=date_utils.get_datetime_utc_now(),
liveaction_db=liveaction_db,
)
executions.update_execution(liveaction_db)
LOG.debug("Performing post_run for runner: %s", runner.runner_id)
result = {"error": "Execution canceled by user."}
runner.post_run(status=liveaction_db.status, result=result)
runner.container_service = None
except:
_, ex, tb = sys.exc_info()
# include the error message and traceback to try and provide some hints.
result = {"error": str(ex), "traceback": "".join(traceback.format_tb(tb, 20))}
LOG.exception("Failed to cancel action %s." % (liveaction_db.id), extra=result)
finally:
# Always clean-up the auth_token
status = liveaction_db.status
self._clean_up_auth_token(runner=runner, status=status)
return liveaction_db
def update_execution_records(wf_ex_db,
conductor,
update_lv_ac_on_states=None,
pub_wf_ex=False,
pub_lv_ac=True,
pub_ac_ex=True):
wf_ac_ex_id = wf_ex_db.action_execution
wf_old_status = wf_ex_db.status
# Update timestamp and output if workflow is completed.
if conductor.get_workflow_state() in states.COMPLETED_STATES:
wf_ex_db.end_timestamp = date_utils.get_datetime_utc_now()
wf_ex_db.output = conductor.get_workflow_output()
# Update workflow status and task flow and write changes to database.
wf_ex_db.status = conductor.get_workflow_state()
wf_ex_db.errors = copy.deepcopy(conductor.errors)
wf_ex_db.flow = conductor.flow.serialize()
wf_ex_db = wf_db_access.WorkflowExecution.update(wf_ex_db,
publish=pub_wf_ex)
# Add log entry if status changed.
if wf_old_status != wf_ex_db.status:
LOG.info('[%s] Updated workflow execution from state "%s" to "%s".',
wf_ac_ex_id, wf_old_status, wf_ex_db.status)
# Return if workflow execution status is not specified in update_lv_ac_on_states.
if isinstance(update_lv_ac_on_states,
list) and wf_ex_db.status not in update_lv_ac_on_states:
return
# Update the corresponding liveaction and action execution for the workflow.
wf_ac_ex_db = ex_db_access.ActionExecution.get_by_id(
wf_ex_db.action_execution)
wf_lv_ac_db = ac_db_util.get_liveaction_by_id(wf_ac_ex_db.liveaction['id'])
# Gather result for liveaction and action execution.
result = {'output': wf_ex_db.output or None}
if wf_ex_db.status in states.ABENDED_STATES:
result['errors'] = wf_ex_db.errors
for wf_ex_error in wf_ex_db.errors:
LOG.error('[%s] Workflow execution completed with errors.',
wf_ac_ex_id,
extra=wf_ex_error)
# Sync update with corresponding liveaction and action execution.
wf_lv_ac_db = ac_db_util.update_liveaction_status(
status=wf_ex_db.status,
result=result,
end_timestamp=wf_ex_db.end_timestamp,
liveaction_db=wf_lv_ac_db,
publish=pub_lv_ac)
ex_svc.update_execution(wf_lv_ac_db, publish=pub_ac_ex)
def _cleanup_policy_delayed(self):
"""
Clean up any action execution in the deprecated policy-delayed status. Associated
entries in the scheduling queue will be removed and the action execution will be
moved back into requested status.
"""
policy_delayed_liveaction_dbs = LiveAction.query(status="policy-delayed") or []
for liveaction_db in policy_delayed_liveaction_dbs:
ex_que_qry = {"liveaction_id": str(liveaction_db.id), "handling": False}
execution_queue_item_dbs = (
ActionExecutionSchedulingQueue.query(**ex_que_qry) or []
)
for execution_queue_item_db in execution_queue_item_dbs:
# Mark the entry in the scheduling queue for handling.
try:
execution_queue_item_db.handling = True
execution_queue_item_db = (
ActionExecutionSchedulingQueue.add_or_update(
execution_queue_item_db, publish=False
)
)
except db_exc.StackStormDBObjectWriteConflictError:
msg = (
'[%s] Item "%s" is currently being processed by another scheduler.'
% (
execution_queue_item_db.action_execution_id,
str(execution_queue_item_db.id),
)
)
LOG.error(msg)
raise Exception(msg)
# Delete the entry from the scheduling queue.
LOG.info(
'[%s] Removing policy-delayed entry "%s" from the scheduling queue.',
execution_queue_item_db.action_execution_id,
str(execution_queue_item_db.id),
)
ActionExecutionSchedulingQueue.delete(execution_queue_item_db)
# Update the status of the liveaction and execution to requested.
LOG.info(
'[%s] Removing policy-delayed entry "%s" from the scheduling queue.',
execution_queue_item_db.action_execution_id,
str(execution_queue_item_db.id),
)
liveaction_db = action_service.update_status(
liveaction_db, action_constants.LIVEACTION_STATUS_REQUESTED
)
execution_service.update_execution(liveaction_db)
def purge_inquiries(logger):
"""Purge Inquiries that have exceeded their configured TTL
At the moment, Inquiries do not have their own database model, so this function effectively
is another, more specialized GC for executions. It will look for executions with a 'pending'
status that use the 'inquirer' runner, which is the current definition for an Inquiry.
Then it will mark those that have a nonzero TTL have existed longer than their TTL as
"timed out". It will then request that the parent workflow(s) resume, where the failure
can be handled as the user desires.
"""
# Get all existing Inquiries
filters = {'runner__name': 'inquirer', 'status': action_constants.LIVEACTION_STATUS_PENDING}
inquiries = list(ActionExecution.query(**filters))
gc_count = 0
# Inspect each Inquiry, and determine if TTL is expired
for inquiry in inquiries:
ttl = int(inquiry.result.get('ttl'))
if ttl <= 0:
logger.debug("Inquiry %s has a TTL of %s. Skipping." % (inquiry.id, ttl))
continue
min_since_creation = int(
(get_datetime_utc_now() - inquiry.start_timestamp).total_seconds() / 60
)
logger.debug("Inquiry %s has a TTL of %s and was started %s minute(s) ago" % (
inquiry.id, ttl, min_since_creation))
if min_since_creation > ttl:
gc_count += 1
logger.info("TTL expired for Inquiry %s. Marking as timed out." % inquiry.id)
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_TIMED_OUT,
result=inquiry.result,
liveaction_id=inquiry.liveaction.get('id'))
executions.update_execution(liveaction_db)
# Call Inquiry runner's post_run to trigger callback to workflow
action_db = get_action_by_ref(liveaction_db.action)
invoke_post_run(liveaction_db=liveaction_db, action_db=action_db)
if liveaction_db.context.get("parent"):
# Request that root workflow resumes
root_liveaction = action_service.get_root_liveaction(liveaction_db)
action_service.request_resume(
root_liveaction,
UserDB(cfg.CONF.system_user.user)
)
logger.info('Marked %s ttl-expired Inquiries as "timed out".' % (gc_count))
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:
# 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 respond(inquiry, response, requester=None):
# Set requester to system user is not provided.
if not requester:
requester = cfg.CONF.system_user.user
# Retrieve the liveaction from the database.
liveaction_db = lv_db_access.LiveAction.get_by_id(inquiry.liveaction.get('id'))
# Resume the parent workflow first. If the action execution for the inquiry is updated first,
# it triggers handling of the action execution completion which will interact with the paused
# parent workflow. The resuming logic that is executed here will then race with the completion
# of the inquiry action execution, which will randomly result in the parent workflow stuck in
# paused state.
if liveaction_db.context.get('parent'):
LOG.debug('Resuming workflow parent(s) for inquiry "%s".' % str(inquiry.id))
# For action execution under Action Chain and Mistral workflows, request the entire
# workflow to resume. Orquesta handles resume differently and so does not require root
# to resume. Orquesta allows for specifc branches to resume while other is paused. When
# there is no other paused branches, the conductor will resume the rest of the workflow.
resume_target = (
action_service.get_parent_liveaction(liveaction_db)
if workflow_service.is_action_execution_under_workflow_context(liveaction_db)
else action_service.get_root_liveaction(liveaction_db)
)
if resume_target.status in action_constants.LIVEACTION_PAUSE_STATES:
action_service.request_resume(resume_target, requester)
# Succeed the liveaction and update result with the inquiry response.
LOG.debug('Updating response for inquiry "%s".' % str(inquiry.id))
result = copy.deepcopy(inquiry.result)
result['response'] = response
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_SUCCEEDED,
end_timestamp=date_utils.get_datetime_utc_now(),
runner_info=sys_info_utils.get_process_info(),
result=result,
liveaction_id=str(liveaction_db.id)
)
# Sync the liveaction with the corresponding action execution.
execution_service.update_execution(liveaction_db)
# Invoke inquiry post run to trigger a callback to parent workflow.
LOG.debug('Invoking post run for inquiry "%s".' % str(inquiry.id))
runner_container = container.get_runner_container()
action_db = action_utils.get_action_by_ref(liveaction_db.action)
runnertype_db = action_utils.get_runnertype_by_name(action_db.runner_type['name'])
runner = runner_container._get_runner(runnertype_db, action_db, liveaction_db)
runner.post_run(status=action_constants.LIVEACTION_STATUS_SUCCEEDED, result=result)
return liveaction_db
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:
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 != 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)
return self._run_action(liveaction_db)
def _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception('No DB model for liveaction_id: %s' % execution_id)
liveaction_db.result = results
liveaction_db.status = status
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db, publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
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 _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception('No DB model for liveaction_id: %s' % execution_id)
liveaction_db.result = results
liveaction_db.status = status
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db,
publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
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 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 test_execution_update(self):
liveaction = self.MODELS['liveactions']['liveaction1.yaml']
executions_util.create_execution_object(liveaction)
liveaction.status = 'running'
pre_update_timestamp = date_utils.get_datetime_utc_now()
executions_util.update_execution(liveaction)
post_update_timestamp = date_utils.get_datetime_utc_now()
execution = self._get_action_execution(liveaction__id=str(liveaction.id),
raise_exception=True)
self.assertEquals(len(execution.log), 2)
self.assertEquals(execution.log[1]['status'], liveaction.status)
self.assertGreater(execution.log[1]['timestamp'], pre_update_timestamp)
self.assertLess(execution.log[1]['timestamp'], post_update_timestamp)
def test_execution_update(self):
liveaction = self.MODELS['liveactions']['liveaction1.yaml']
executions_util.create_execution_object(liveaction)
liveaction.status = 'running'
pre_update_timestamp = date_utils.get_datetime_utc_now()
executions_util.update_execution(liveaction)
post_update_timestamp = date_utils.get_datetime_utc_now()
execution = self._get_action_execution(liveaction__id=str(liveaction.id),
raise_exception=True)
self.assertEqual(len(execution.log), 2)
self.assertEqual(execution.log[1]['status'], liveaction.status)
self.assertGreater(execution.log[1]['timestamp'], pre_update_timestamp)
self.assertLess(execution.log[1]['timestamp'], post_update_timestamp)
def test_skip_execution_update(self):
liveaction = self.MODELS["liveactions"]["successful_liveaction.yaml"]
executions_util.create_execution_object(liveaction)
pre_update_status = liveaction.status
liveaction.status = "running"
executions_util.update_execution(liveaction)
execution = self._get_action_execution(liveaction__id=str(
liveaction.id),
raise_exception=True)
self.assertEqual(len(execution.log), 1)
# Check status is not updated if it's already in completed state.
self.assertEqual(pre_update_status,
action_constants.LIVEACTION_STATUS_SUCCEEDED)
self.assertEqual(execution.log[0]["status"], pre_update_status)
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)
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
return result
def update_status(liveaction, new_status, publish=True):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
liveaction = action_utils.update_liveaction_status(
status=new_status, liveaction_id=liveaction.id, publish=False)
action_execution = executions.update_execution(liveaction)
msg = ('The status of action execution is changed from %s to %s. '
'<LiveAction.id=%s, ActionExecution.id=%s>' % (old_status,
new_status, liveaction.id, action_execution.id))
extra = {
'action_execution_db': action_execution,
'liveaction_db': liveaction
}
LOG.audit(msg, extra=extra)
LOG.info(msg)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def update_status(liveaction, new_status, result=None, publish=True):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
liveaction = action_utils.update_liveaction_status(
status=new_status,
result=result,
liveaction_id=liveaction.id,
publish=False)
action_execution = executions.update_execution(liveaction)
msg = ('The status of action execution is changed from %s to %s. '
'<LiveAction.id=%s, ActionExecution.id=%s>' %
(old_status, new_status, liveaction.id, action_execution.id))
extra = {
'action_execution_db': action_execution,
'liveaction_db': liveaction
}
LOG.audit(msg, extra=extra)
LOG.info(msg)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def update_status(liveaction, new_status, result=None, publish=True):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
liveaction = action_utils.update_liveaction_status(
status=new_status, result=result, liveaction_id=liveaction.id, publish=False
)
action_execution = executions.update_execution(liveaction)
msg = "The status of action execution is changed from %s to %s. " "<LiveAction.id=%s, ActionExecution.id=%s>" % (
old_status,
new_status,
liveaction.id,
action_execution.id,
)
extra = {"action_execution_db": action_execution, "liveaction_db": liveaction}
LOG.audit(msg, extra=extra)
LOG.info(msg)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def set_execution_status(self, lv_ac_db_id, status):
lv_ac_db = action_utils.update_liveaction_status(
status=status, liveaction_id=lv_ac_db_id, publish=False)
ac_ex_db = execution_service.update_execution(lv_ac_db, publish=False)
return lv_ac_db, ac_ex_db
def test_populate_action_execution_id(self):
self.reset()
liveaction_db = self._create_liveaction_db()
schedule_q_db = self.scheduler._create_execution_queue_item_db_from_liveaction(
liveaction_db)
# Manually unset the action_execution_id ot mock DB model of previous version.
schedule_q_db.action_execution_id = None
schedule_q_db = ActionExecutionSchedulingQueue.add_or_update(
schedule_q_db)
schedule_q_db = ActionExecutionSchedulingQueue.get_by_id(
str(schedule_q_db.id))
self.assertIsNone(schedule_q_db.action_execution_id)
# Run the clean up logic.
self.scheduling_queue._fix_missing_action_execution_id()
# Check that the action_execution_id is populated.
schedule_q_db = ActionExecutionSchedulingQueue.get_by_id(
str(schedule_q_db.id))
execution_db = execution_service.update_execution(liveaction_db)
self.assertEqual(schedule_q_db.action_execution_id,
str(execution_db.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 _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 delete(self, exec_id):
"""
Stops a single execution.
Handles requests:
DELETE /actionexecutions/<id>
"""
execution_api = self._get_one(id=exec_id)
if not execution_api:
abort(http_client.NOT_FOUND,
'Execution with id %s not found.' % exec_id)
return
liveaction_id = execution_api.liveaction['id']
if not liveaction_id:
abort(
http_client.INTERNAL_SERVER_ERROR,
'Execution object missing link to liveaction %s.' %
liveaction_id)
try:
liveaction_db = LiveAction.get_by_id(liveaction_id)
except:
abort(
http_client.INTERNAL_SERVER_ERROR,
'Execution object missing link to liveaction %s.' %
liveaction_id)
return
if liveaction_db.status == LIVEACTION_STATUS_CANCELED:
abort(http_client.OK, 'Action is already in "canceled" state.')
if liveaction_db.status not in CANCELABLE_STATES:
abort(
http_client.OK, 'Action cannot be canceled. State = %s.' %
liveaction_db.status)
return
liveaction_db.status = 'canceled'
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
liveaction_db.result = {'message': 'Action canceled by user.'}
try:
LiveAction.add_or_update(liveaction_db)
except:
LOG.exception(
'Failed updating status to canceled for liveaction %s.',
liveaction_db.id)
abort(http_client.INTERNAL_SERVER_ERROR,
'Failed canceling execution.')
return
execution_db = execution_service.update_execution(liveaction_db)
from_model_kwargs = self._get_from_model_kwargs_for_request(
request=pecan.request)
return ActionExecutionAPI.from_model(execution_db, from_model_kwargs)
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 _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception('No DB model for liveaction_id: %s' % execution_id)
liveaction_db.result = results
liveaction_db.status = status
done = status in DONE_STATES
if done and not liveaction_db.end_timestamp:
# Action has completed, record end_timestamp
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db, publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
def _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception('No DB model for liveaction_id: %s' % execution_id)
liveaction_db.result = results
liveaction_db.status = status
done = status in DONE_STATES
if done and not liveaction_db.end_timestamp:
# Action has completed, record end_timestamp
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db,
publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
def _run_action(self, liveaction_db):
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
return result
def _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception("No DB model for liveaction_id: %s" % execution_id)
if liveaction_db.status != action_constants.LIVEACTION_STATUS_CANCELED:
liveaction_db.status = status
liveaction_db.result = results
# Action has completed, record end_timestamp
if liveaction_db.status in action_constants.LIVEACTION_COMPLETED_STATES and not liveaction_db.end_timestamp:
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db, publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
def _do_cancel(self, runner, runnertype_db, action_db, liveaction_db):
try:
extra = {'runner': runner}
LOG.debug('Performing cancel for runner: %s', (runner.runner_id), extra=extra)
runner.cancel()
liveaction_db = update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_CANCELED,
end_timestamp=date_utils.get_datetime_utc_now(),
liveaction_db=liveaction_db)
executions.update_execution(liveaction_db)
except:
_, ex, tb = sys.exc_info()
# include the error message and traceback to try and provide some hints.
result = {'error': str(ex), 'traceback': ''.join(traceback.format_tb(tb, 20))}
LOG.exception('Failed to cancel action %s.' % (liveaction_db.id), extra=result)
return liveaction_db
def _update_action_results(self, execution_id, status, results):
liveaction_db = LiveAction.get_by_id(execution_id)
if not liveaction_db:
raise Exception('No DB model for liveaction_id: %s' % execution_id)
if liveaction_db.status != action_constants.LIVEACTION_STATUS_CANCELED:
liveaction_db.status = status
liveaction_db.result = results
# Action has completed, record end_timestamp
if (liveaction_db.status in action_constants.LIVEACTION_COMPLETED_STATES and
not liveaction_db.end_timestamp):
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
# update liveaction, update actionexecution and then publish update.
updated_liveaction = LiveAction.add_or_update(liveaction_db, publish=False)
executions.update_execution(updated_liveaction)
LiveAction.publish_update(updated_liveaction)
return updated_liveaction
def set_execution_status(self, lv_ac_db_id, status):
lv_ac_db = action_utils.update_liveaction_status(
status=status,
liveaction_id=lv_ac_db_id,
publish=False
)
ac_ex_db = execution_service.update_execution(
lv_ac_db,
publish=False
)
return lv_ac_db, ac_ex_db
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)
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
return result
def update_execution_records(wf_ex_db, conductor, update_lv_ac_on_states=None,
pub_wf_ex=False, pub_lv_ac=True, pub_ac_ex=True):
# Update timestamp and output if workflow is completed.
if conductor.get_workflow_state() in states.COMPLETED_STATES:
wf_ex_db.end_timestamp = date_utils.get_datetime_utc_now()
wf_ex_db.output = conductor.get_workflow_output()
# Update workflow status and task flow and write changes to database.
wf_ex_db.status = conductor.get_workflow_state()
wf_ex_db.errors = copy.deepcopy(conductor.errors)
wf_ex_db.flow = conductor.flow.serialize()
wf_ex_db = wf_db_access.WorkflowExecution.update(wf_ex_db, publish=pub_wf_ex)
# Return if workflow execution status is not specified in update_lv_ac_on_states.
if isinstance(update_lv_ac_on_states, list) and wf_ex_db.status not in update_lv_ac_on_states:
return
# Update the corresponding liveaction and action execution for the workflow.
wf_ac_ex_db = ex_db_access.ActionExecution.get_by_id(wf_ex_db.action_execution)
wf_lv_ac_db = ac_db_util.get_liveaction_by_id(wf_ac_ex_db.liveaction['id'])
# Gather result for liveaction and action execution.
result = {'output': wf_ex_db.output or None}
if wf_ex_db.status in states.ABENDED_STATES:
result['errors'] = wf_ex_db.errors
# Sync update with corresponding liveaction and action execution.
wf_lv_ac_db = ac_db_util.update_liveaction_status(
status=wf_ex_db.status,
result=result,
end_timestamp=wf_ex_db.end_timestamp,
liveaction_db=wf_lv_ac_db,
publish=pub_lv_ac)
ex_svc.update_execution(wf_lv_ac_db, publish=pub_ac_ex)
def delete(self, exec_id):
"""
Stops a single execution.
Handles requests:
DELETE /actionexecutions/<id>
"""
execution_api = self._get_one(id=exec_id)
if not execution_api:
abort(http_client.NOT_FOUND, 'Execution with id %s not found.' % exec_id)
return
liveaction_id = execution_api.liveaction['id']
if not liveaction_id:
abort(http_client.INTERNAL_SERVER_ERROR,
'Execution object missing link to liveaction %s.' % liveaction_id)
try:
liveaction_db = LiveAction.get_by_id(liveaction_id)
except:
abort(http_client.INTERNAL_SERVER_ERROR,
'Execution object missing link to liveaction %s.' % liveaction_id)
return
if liveaction_db.status == LIVEACTION_STATUS_CANCELED:
abort(http_client.OK,
'Action is already in "canceled" state.')
if liveaction_db.status not in CANCELABLE_STATES:
abort(http_client.OK,
'Action cannot be canceled. State = %s.' % liveaction_db.status)
return
liveaction_db.status = 'canceled'
liveaction_db.end_timestamp = date_utils.get_datetime_utc_now()
liveaction_db.result = {'message': 'Action canceled by user.'}
try:
LiveAction.add_or_update(liveaction_db)
except:
LOG.exception('Failed updating status to canceled for liveaction %s.',
liveaction_db.id)
abort(http_client.INTERNAL_SERVER_ERROR, 'Failed canceling execution.')
return
execution_db = execution_service.update_execution(liveaction_db)
from_model_kwargs = self._get_from_model_kwargs_for_request(request=pecan.request)
return ActionExecutionAPI.from_model(execution_db, from_model_kwargs)
def update_status(
liveaction,
new_status,
result=None,
publish=True,
set_result_size=False,
context=None,
):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
updates = {
"liveaction_id": liveaction.id,
"status": new_status,
"result": result,
"publish": False,
"context": context,
}
if new_status in action_constants.LIVEACTION_COMPLETED_STATES:
updates["end_timestamp"] = date_utils.get_datetime_utc_now()
liveaction = action_utils.update_liveaction_status(**updates)
action_execution = executions.update_execution(
liveaction, set_result_size=set_result_size)
msg = ("The status of action execution is changed from %s to %s. "
"<LiveAction.id=%s, ActionExecution.id=%s>" %
(old_status, new_status, liveaction.id, action_execution.id))
extra = {
"action_execution_db": action_execution,
"liveaction_db": liveaction
}
LOG.audit(msg, extra=extra)
LOG.info(msg)
# Invoke post run if liveaction status is completed or paused.
if (new_status in action_constants.LIVEACTION_COMPLETED_STATES
or new_status == action_constants.LIVEACTION_STATUS_PAUSED):
runners_utils.invoke_post_run(liveaction)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def execute_action(self, liveaction):
# Note: We only want to execute actions which haven't completed yet
if liveaction.status == LIVEACTION_STATUS_CANCELED:
LOG.info('Not executing liveaction %s. User canceled execution.', liveaction.id)
if not liveaction.result:
update_liveaction_status(status=LIVEACTION_STATUS_CANCELED,
result={'message': 'Action execution canceled by user.'},
liveaction_id=liveaction.id)
return
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 test_cleanup_policy_delayed(self):
self.reset()
liveaction_db = self._create_liveaction_db()
schedule_q_db = self.scheduler._create_execution_queue_item_db_from_liveaction(
liveaction_db
)
schedule_q_db = ActionExecutionSchedulingQueue.add_or_update(schedule_q_db)
# Manually update the liveaction to policy-delayed status.
# Using action_service.update_status will throw an exception on the
# deprecated action_constants.LIVEACTION_STATUS_POLICY_DELAYED.
liveaction_db.status = "policy-delayed"
liveaction_db = LiveAction.add_or_update(liveaction_db)
execution_db = execution_service.update_execution(liveaction_db)
# Check that the execution status is set to policy-delayed.
liveaction_db = LiveAction.get_by_id(str(liveaction_db.id))
self.assertEqual(liveaction_db.status, "policy-delayed")
execution_db = ActionExecution.get_by_id(str(execution_db.id))
self.assertEqual(execution_db.status, "policy-delayed")
# Run the clean up logic.
self.scheduling_queue._cleanup_policy_delayed()
# Check that the execution status is reset to requested.
liveaction_db = LiveAction.get_by_id(str(liveaction_db.id))
self.assertEqual(
liveaction_db.status, action_constants.LIVEACTION_STATUS_REQUESTED
)
execution_db = ActionExecution.get_by_id(str(execution_db.id))
self.assertEqual(
execution_db.status, action_constants.LIVEACTION_STATUS_REQUESTED
)
# The old entry should have been deleted. Since the execution is
# reset to requested, there should be a new scheduling entry.
new_schedule_q_db = self.scheduling_queue._get_next_execution()
self.assertIsNotNone(new_schedule_q_db)
self.assertNotEqual(str(schedule_q_db.id), str(new_schedule_q_db.id))
self.assertEqual(
schedule_q_db.action_execution_id, new_schedule_q_db.action_execution_id
)
self.assertEqual(schedule_q_db.liveaction_id, new_schedule_q_db.liveaction_id)
def test_cleanup_policy_delayed(self):
self.reset()
liveaction_db = self._create_liveaction_db()
schedule_q_db = self.scheduler._create_execution_queue_item_db_from_liveaction(
liveaction_db
)
schedule_q_db = ActionExecutionSchedulingQueue.add_or_update(schedule_q_db)
# Manually update the liveaction to policy-delayed status.
# Using action_service.update_status will throw an exception on the
# deprecated action_constants.LIVEACTION_STATUS_POLICY_DELAYED.
liveaction_db.status = 'policy-delayed'
liveaction_db = LiveAction.add_or_update(liveaction_db)
execution_db = execution_service.update_execution(liveaction_db)
# Check that the execution status is set to policy-delayed.
liveaction_db = LiveAction.get_by_id(str(liveaction_db.id))
self.assertEqual(liveaction_db.status, 'policy-delayed')
execution_db = ActionExecution.get_by_id(str(execution_db.id))
self.assertEqual(execution_db.status, 'policy-delayed')
# Run the clean up logic.
self.scheduling_queue._cleanup_policy_delayed()
# Check that the execution status is reset to requested.
liveaction_db = LiveAction.get_by_id(str(liveaction_db.id))
self.assertEqual(liveaction_db.status, action_constants.LIVEACTION_STATUS_REQUESTED)
execution_db = ActionExecution.get_by_id(str(execution_db.id))
self.assertEqual(execution_db.status, action_constants.LIVEACTION_STATUS_REQUESTED)
# The old entry should have been deleted. Since the execution is
# reset to requested, there should be a new scheduling entry.
new_schedule_q_db = self.scheduling_queue._get_next_execution()
self.assertIsNotNone(new_schedule_q_db)
self.assertNotEqual(str(schedule_q_db.id), str(new_schedule_q_db.id))
self.assertEqual(schedule_q_db.action_execution_id, new_schedule_q_db.action_execution_id)
self.assertEqual(schedule_q_db.liveaction_id, new_schedule_q_db.liveaction_id)
def process(self, request):
"""Schedules the LiveAction and publishes the request
to the appropriate action runner(s).
LiveAction in statuses other than "requested" are ignored.
:param request: Action execution request.
:type request: ``st2common.models.db.liveaction.LiveActionDB``
"""
if request.status != action_constants.LIVEACTION_STATUS_REQUESTED:
LOG.info('%s is ignoring %s (id=%s) with "%s" status.',
self.__class__.__name__, type(request), request.id, request.status)
return
try:
liveaction_db = action_utils.get_liveaction_by_id(request.id)
except StackStormDBObjectNotFoundError:
LOG.exception('Failed to find liveaction %s in the database.', request.id)
raise
# Update liveaction status to "scheduled"
liveaction_db = action_utils.update_liveaction_status(
status=action_constants.LIVEACTION_STATUS_SCHEDULED,
liveaction_id=liveaction_db.id,
publish=False)
action_execution_db = executions.update_execution(liveaction_db)
# Publish the "scheduled" status here manually. Otherwise, there could be a
# race condition with the update of the action_execution_db if the execution
# of the liveaction completes first.
LiveAction.publish_status(liveaction_db)
extra = {'action_execution_db': action_execution_db, 'liveaction_db': liveaction_db}
LOG.audit('Scheduled action execution.', extra=extra)
# the extra field will not be shown in non-audit logs so temporarily log at info.
LOG.info('Scheduled {~}action_execution: %s / {~}live_action: %s with "%s" status.',
action_execution_db.id, liveaction_db.id, request.status)
def update_status(liveaction, new_status, result=None, publish=True):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
updates = {
'liveaction_id': liveaction.id,
'status': new_status,
'result': result,
'publish': False
}
if new_status in action_constants.LIVEACTION_COMPLETED_STATES:
updates['end_timestamp'] = date_utils.get_datetime_utc_now()
liveaction = action_utils.update_liveaction_status(**updates)
action_execution = executions.update_execution(liveaction)
msg = ('The status of action execution is changed from %s to %s. '
'<LiveAction.id=%s, ActionExecution.id=%s>' %
(old_status, new_status, liveaction.id, action_execution.id))
extra = {
'action_execution_db': action_execution,
'liveaction_db': liveaction
}
LOG.audit(msg, extra=extra)
LOG.info(msg)
# Invoke post run if liveaction status is completed or paused.
if (new_status in action_constants.LIVEACTION_COMPLETED_STATES
or new_status == action_constants.LIVEACTION_STATUS_PAUSED):
runners_utils.invoke_post_run(liveaction)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def update_status(liveaction, new_status, result=None, publish=True):
if liveaction.status == new_status:
return liveaction
old_status = liveaction.status
updates = {
'liveaction_id': liveaction.id,
'status': new_status,
'result': result,
'publish': False
}
if new_status in action_constants.LIVEACTION_COMPLETED_STATES:
updates['end_timestamp'] = date_utils.get_datetime_utc_now()
liveaction = action_utils.update_liveaction_status(**updates)
action_execution = executions.update_execution(liveaction)
msg = ('The status of action execution is changed from %s to %s. '
'<LiveAction.id=%s, ActionExecution.id=%s>' % (old_status,
new_status, liveaction.id, action_execution.id))
extra = {
'action_execution_db': action_execution,
'liveaction_db': liveaction
}
LOG.audit(msg, extra=extra)
LOG.info(msg)
# Invoke post run if liveaction status is completed or paused.
if (new_status in action_constants.LIVEACTION_COMPLETED_STATES or
new_status == action_constants.LIVEACTION_STATUS_PAUSED):
runners_utils.invoke_post_run(liveaction)
if publish:
LiveAction.publish_status(liveaction)
return liveaction
def test_populate_action_execution_id(self):
self.reset()
liveaction_db = self._create_liveaction_db()
schedule_q_db = self.scheduler._create_execution_queue_item_db_from_liveaction(
liveaction_db
)
# Manually unset the action_execution_id ot mock DB model of previous version.
schedule_q_db.action_execution_id = None
schedule_q_db = ActionExecutionSchedulingQueue.add_or_update(schedule_q_db)
schedule_q_db = ActionExecutionSchedulingQueue.get_by_id(str(schedule_q_db.id))
self.assertIsNone(schedule_q_db.action_execution_id)
# Run the clean up logic.
self.scheduling_queue._fix_missing_action_execution_id()
# Check that the action_execution_id is populated.
schedule_q_db = ActionExecutionSchedulingQueue.get_by_id(str(schedule_q_db.id))
execution_db = execution_service.update_execution(liveaction_db)
self.assertEqual(schedule_q_db.action_execution_id, str(execution_db.id))
def _do_run(self, runner, runnertype_db, action_db, liveaction_db):
# Finalized parameters are resolved and then rendered.
runner_params, action_params = param_utils.get_finalized_params(
runnertype_db.runner_parameters, action_db.parameters, liveaction_db.parameters)
resolved_entry_point = self._get_entry_point_abs_path(action_db.pack,
action_db.entry_point)
runner.container_service = RunnerContainerService()
runner.action = action_db
runner.action_name = action_db.name
runner.liveaction_id = str(liveaction_db.id)
runner.entry_point = resolved_entry_point
runner.runner_parameters = runner_params
runner.context = getattr(liveaction_db, 'context', dict())
runner.callback = getattr(liveaction_db, 'callback', dict())
runner.libs_dir_path = self._get_action_libs_abs_path(action_db.pack,
action_db.entry_point)
runner.auth_token = self._create_auth_token(runner.context)
updated_liveaction_db = None
try:
# Finalized parameters are resolved and then rendered. This process could
# fail. Handle the exception and report the error correctly.
runner_params, action_params = param_utils.get_finalized_params(
runnertype_db.runner_parameters, action_db.parameters, liveaction_db.parameters)
runner.runner_parameters = runner_params
LOG.debug('Performing pre-run for runner: %s', runner)
runner.pre_run()
LOG.debug('Performing run for runner: %s', runner)
(status, result, context) = runner.run(action_params)
try:
result = json.loads(result)
except:
pass
if isinstance(runner, AsyncActionRunner) and status not in DONE_STATES:
self._setup_async_query(liveaction_db.id, runnertype_db, context)
except:
LOG.exception('Failed to run action.')
_, ex, tb = sys.exc_info()
# mark execution as failed.
status = LIVEACTION_STATUS_FAILED
# include the error message and traceback to try and provide some hints.
result = {'message': str(ex), 'traceback': ''.join(traceback.format_tb(tb, 20))}
context = None
finally:
# Always clean-up the auth_token
updated_liveaction_db = self._update_live_action_db(liveaction_db.id, status,
result, context)
executions.update_execution(updated_liveaction_db)
LOG.debug('Updated liveaction after run: %s', updated_liveaction_db)
try:
self._delete_auth_token(runner.auth_token)
except:
LOG.warn('Unable to clean-up auth_token.')
LOG.debug('Performing post_run for runner: %s', runner)
runner.post_run(status, result)
runner.container_service = None
return updated_liveaction_db
def test_rerun_with_missing_workflow_execution_id(self):
wf_meta = self.get_wf_fixture_meta_data(TEST_PACK_PATH,
'sequential.yaml')
wf_input = {'who': 'Thanos'}
lv_ac_db1 = lv_db_models.LiveActionDB(action=wf_meta['name'],
parameters=wf_input)
lv_ac_db1, ac_ex_db1 = action_service.request(lv_ac_db1)
wf_ex_db = wf_db_access.WorkflowExecution.query(
action_execution=str(ac_ex_db1.id))[0]
# Process task1.
query_filters = {
'workflow_execution': str(wf_ex_db.id),
'task_id': 'task1'
}
tk1_ex_db = wf_db_access.TaskExecution.query(**query_filters)[0]
tk1_ac_ex_db = ex_db_access.ActionExecution.query(
task_execution=str(tk1_ex_db.id))[0]
tk1_lv_ac_db = lv_db_access.LiveAction.get_by_id(
tk1_ac_ex_db.liveaction['id'])
self.assertEqual(tk1_lv_ac_db.status,
action_constants.LIVEACTION_STATUS_FAILED)
workflow_service.handle_action_execution_completion(tk1_ac_ex_db)
tk1_ex_db = wf_db_access.TaskExecution.get_by_id(tk1_ex_db.id)
self.assertEqual(tk1_ex_db.status, wf_statuses.FAILED)
# Assert workflow is completed.
wf_ex_db = wf_db_access.WorkflowExecution.get_by_id(wf_ex_db.id)
self.assertEqual(wf_ex_db.status, wf_statuses.FAILED)
lv_ac_db1 = lv_db_access.LiveAction.get_by_id(str(lv_ac_db1.id))
self.assertEqual(lv_ac_db1.status,
action_constants.LIVEACTION_STATUS_FAILED)
ac_ex_db1 = ex_db_access.ActionExecution.get_by_id(str(ac_ex_db1.id))
self.assertEqual(ac_ex_db1.status,
action_constants.LIVEACTION_STATUS_FAILED)
# Delete the workflow execution.
wf_db_access.WorkflowExecution.delete(wf_ex_db, publish=False)
# Manually delete the workflow_execution_id from context of the action execution.
lv_ac_db1.context.pop('workflow_execution')
lv_ac_db1 = lv_db_access.LiveAction.add_or_update(lv_ac_db1,
publish=False)
ac_ex_db1 = execution_service.update_execution(lv_ac_db1,
publish=False)
# Rerun the execution.
context = {'re-run': {'ref': str(ac_ex_db1.id), 'tasks': ['task1']}}
lv_ac_db2 = lv_db_models.LiveActionDB(action=wf_meta['name'],
context=context)
lv_ac_db2, ac_ex_db2 = action_service.request(lv_ac_db2)
expected_error = ('Unable to rerun workflow execution because '
'workflow_execution_id is not provided.')
# Assert the workflow rerrun fails.
lv_ac_db2 = lv_db_access.LiveAction.get_by_id(str(lv_ac_db2.id))
self.assertEqual(lv_ac_db2.status,
action_constants.LIVEACTION_STATUS_FAILED)
self.assertEqual(expected_error,
lv_ac_db2.result['errors'][0]['message'])
ac_ex_db2 = ex_db_access.ActionExecution.get_by_id(str(ac_ex_db2.id))
self.assertEqual(ac_ex_db2.status,
action_constants.LIVEACTION_STATUS_FAILED)
self.assertEqual(expected_error,
ac_ex_db2.result['errors'][0]['message'])
def _do_run(self, runner, runnertype_db, action_db, liveaction_db):
# Finalized parameters are resolved and then rendered.
runner_params, action_params = param_utils.get_finalized_params(
runnertype_db.runner_parameters, action_db.parameters,
liveaction_db.parameters)
resolved_entry_point = self._get_entry_point_abs_path(
action_db.pack, action_db.entry_point)
runner.container_service = RunnerContainerService()
runner.action = action_db
runner.action_name = action_db.name
runner.liveaction_id = str(liveaction_db.id)
runner.entry_point = resolved_entry_point
runner.runner_parameters = runner_params
runner.context = getattr(liveaction_db, 'context', dict())
runner.callback = getattr(liveaction_db, 'callback', dict())
runner.libs_dir_path = self._get_action_libs_abs_path(
action_db.pack, action_db.entry_point)
runner.auth_token = self._create_auth_token(runner.context)
updated_liveaction_db = None
try:
# Finalized parameters are resolved and then rendered. This process could
# fail. Handle the exception and report the error correctly.
runner_params, action_params = param_utils.get_finalized_params(
runnertype_db.runner_parameters, action_db.parameters,
liveaction_db.parameters)
runner.runner_parameters = runner_params
LOG.debug('Performing pre-run for runner: %s', runner)
runner.pre_run()
LOG.debug('Performing run for runner: %s', runner)
(status, result, context) = runner.run(action_params)
try:
result = json.loads(result)
except:
pass
if (isinstance(runner, AsyncActionRunner)
and status not in action_constants.COMPLETED_STATES):
self._setup_async_query(liveaction_db.id, runnertype_db,
context)
except:
LOG.exception('Failed to run action.')
_, ex, tb = sys.exc_info()
# mark execution as failed.
status = action_constants.LIVEACTION_STATUS_FAILED
# include the error message and traceback to try and provide some hints.
result = {
'message': str(ex),
'traceback': ''.join(traceback.format_tb(tb, 20))
}
context = None
finally:
# Always clean-up the auth_token
updated_liveaction_db = self._update_live_action_db(
liveaction_db.id, status, result, context)
executions.update_execution(updated_liveaction_db)
LOG.debug('Updated liveaction after run: %s',
updated_liveaction_db)
# Deletion of the runner generated auth token is delayed until the token expires.
# Async actions such as Mistral workflows uses the auth token to launch other
# actions in the workflow. If the auth token is deleted here, then the actions
# in the workflow will fail with unauthorized exception.
if (not isinstance(runner, AsyncActionRunner)
or (isinstance(runner, AsyncActionRunner)
and status in action_constants.COMPLETED_STATES)):
try:
self._delete_auth_token(runner.auth_token)
except:
LOG.warn('Unable to clean-up auth_token.')
LOG.debug('Performing post_run for runner: %s', runner)
runner.post_run(status, result)
runner.container_service = None
return updated_liveaction_db
def _do_run(self, runner, runnertype_db, action_db, liveaction_db):
# Create a temporary auth token which will be available
# for the duration of the action execution.
runner.auth_token = self._create_auth_token(runner.context)
updated_liveaction_db = None
try:
# Finalized parameters are resolved and then rendered. This process could
# fail. Handle the exception and report the error correctly.
runner_params, action_params = param_utils.get_finalized_params(
runnertype_db.runner_parameters, action_db.parameters, liveaction_db.parameters,
liveaction_db.context)
runner.runner_parameters = runner_params
LOG.debug('Performing pre-run for runner: %s', runner.runner_id)
runner.pre_run()
# Mask secret parameters in the log context
resolved_action_params = ResolvedActionParameters(action_db=action_db,
runner_type_db=runnertype_db,
runner_parameters=runner_params,
action_parameters=action_params)
extra = {'runner': runner, 'parameters': resolved_action_params}
LOG.debug('Performing run for runner: %s' % (runner.runner_id), extra=extra)
(status, result, context) = runner.run(action_params)
try:
result = json.loads(result)
except:
pass
action_completed = status in action_constants.LIVEACTION_COMPLETED_STATES
if isinstance(runner, AsyncActionRunner) and not action_completed:
self._setup_async_query(liveaction_db.id, runnertype_db, context)
except:
LOG.exception('Failed to run action.')
_, ex, tb = sys.exc_info()
# mark execution as failed.
status = action_constants.LIVEACTION_STATUS_FAILED
# include the error message and traceback to try and provide some hints.
result = {'error': str(ex), 'traceback': ''.join(traceback.format_tb(tb, 20))}
context = None
finally:
# Log action completion
extra = {'result': result, 'status': status}
LOG.debug('Action "%s" completed.' % (action_db.name), extra=extra)
# Always clean-up the auth_token
try:
LOG.debug('Setting status: %s for liveaction: %s', status, liveaction_db.id)
updated_liveaction_db = self._update_live_action_db(liveaction_db.id, status,
result, context)
except:
error = 'Cannot update LiveAction object for id: %s, status: %s, result: %s.' % (
liveaction_db.id, status, result)
LOG.exception(error)
raise
executions.update_execution(updated_liveaction_db)
extra = {'liveaction_db': updated_liveaction_db}
LOG.debug('Updated liveaction after run', extra=extra)
# Deletion of the runner generated auth token is delayed until the token expires.
# Async actions such as Mistral workflows uses the auth token to launch other
# actions in the workflow. If the auth token is deleted here, then the actions
# in the workflow will fail with unauthorized exception.
is_async_runner = isinstance(runner, AsyncActionRunner)
action_completed = status in action_constants.LIVEACTION_COMPLETED_STATES
if not is_async_runner or (is_async_runner and action_completed):
try:
self._delete_auth_token(runner.auth_token)
except:
LOG.exception('Unable to clean-up auth_token.')
LOG.debug('Performing post_run for runner: %s', runner.runner_id)
runner.post_run(status, result)
runner.container_service = None
LOG.debug('Runner do_run result', extra={'result': updated_liveaction_db.result})
LOG.audit('Liveaction completed', extra={'liveaction_db': updated_liveaction_db})
return updated_liveaction_db
def _do_run(self, runner, runnertype_db, action_db, liveaction_db):
# Create a temporary auth token which will be available
# for the duration of the action execution.
runner.auth_token = self._create_auth_token(runner.context)
updated_liveaction_db = None
try:
# Finalized parameters are resolved and then rendered. This process could
# fail. Handle the exception and report the error correctly.
try:
runner_params, action_params = param_utils.render_final_params(
runnertype_db.runner_parameters,
action_db.parameters,
liveaction_db.parameters,
liveaction_db.context,
)
runner.runner_parameters = runner_params
except ParamException as e:
raise actionrunner.ActionRunnerException(str(e))
LOG.debug("Performing pre-run for runner: %s", runner.runner_id)
runner.pre_run()
# Mask secret parameters in the log context
resolved_action_params = ResolvedActionParameters(
action_db=action_db,
runner_type_db=runnertype_db,
runner_parameters=runner_params,
action_parameters=action_params,
)
extra = {"runner": runner, "parameters": resolved_action_params}
LOG.debug("Performing run for runner: %s" % (runner.runner_id), extra=extra)
(status, result, context) = runner.run(action_params)
try:
result = json.loads(result)
except:
pass
action_completed = status in action_constants.LIVEACTION_COMPLETED_STATES
if isinstance(runner, AsyncActionRunner) and not action_completed:
self._setup_async_query(liveaction_db.id, runnertype_db, context)
except:
LOG.exception("Failed to run action.")
_, ex, tb = sys.exc_info()
# mark execution as failed.
status = action_constants.LIVEACTION_STATUS_FAILED
# include the error message and traceback to try and provide some hints.
result = {"error": str(ex), "traceback": "".join(traceback.format_tb(tb, 20))}
context = None
finally:
# Log action completion
extra = {"result": result, "status": status}
LOG.debug('Action "%s" completed.' % (action_db.name), extra=extra)
# Always clean-up the auth_token
try:
LOG.debug("Setting status: %s for liveaction: %s", status, liveaction_db.id)
updated_liveaction_db = self._update_live_action_db(liveaction_db.id, status, result, context)
except:
error = "Cannot update LiveAction object for id: %s, status: %s, result: %s." % (
liveaction_db.id,
status,
result,
)
LOG.exception(error)
raise
executions.update_execution(updated_liveaction_db)
extra = {"liveaction_db": updated_liveaction_db}
LOG.debug("Updated liveaction after run", extra=extra)
# Always clean-up the auth_token
self._clean_up_auth_token(runner=runner, status=status)
LOG.debug("Performing post_run for runner: %s", runner.runner_id)
runner.post_run(status=status, result=result)
runner.container_service = None
LOG.debug("Runner do_run result", extra={"result": updated_liveaction_db.result})
LOG.audit("Liveaction completed", extra={"liveaction_db": updated_liveaction_db})
return updated_liveaction_db
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
