def recover_delayed_executions():
coordinator = coordination.get_coordinator()
dt_now = date_utils.get_datetime_utc_now()
dt_delta = datetime.timedelta(seconds=cfg.CONF.scheduler.delayed_execution_recovery)
dt_timeout = dt_now - dt_delta
with coordinator.get_lock('st2-rescheduling-delayed-executions'):
liveactions = LiveAction.query(status=action_constants.LIVEACTION_STATUS_DELAYED,
start_timestamp__lte=dt_timeout,
order_by=['start_timestamp'])
if not liveactions:
return
LOG.info('There are %d liveactions that have been delayed for longer than %d seconds.',
len(liveactions), cfg.CONF.scheduler.delayed_execution_recovery)
# Update status to requested and publish status for each liveactions.
rescheduled = 0
for instance in liveactions:
try:
action_service.update_status(instance,
action_constants.LIVEACTION_STATUS_REQUESTED,
publish=True)
rescheduled += 1
except:
LOG.exception('Unable to reschedule liveaction. <LiveAction.id=%s>', instance.id)
LOG.info('Rescheduled %d out of %d delayed liveactions.', len(liveactions), rescheduled)
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 recover_delayed_executions():
coordinator = coordination.get_coordinator()
dt_now = date_utils.get_datetime_utc_now()
dt_delta = datetime.timedelta(
seconds=cfg.CONF.scheduler.delayed_execution_recovery)
dt_timeout = dt_now - dt_delta
with coordinator.get_lock('st2-rescheduling-delayed-executions'):
liveactions = LiveAction.query(
status=action_constants.LIVEACTION_STATUS_DELAYED,
start_timestamp__lte=dt_timeout,
order_by=['start_timestamp'])
if not liveactions:
return
LOG.info(
'There are %d liveactions that have been delayed for longer than %d seconds.',
len(liveactions), cfg.CONF.scheduler.delayed_execution_recovery)
# Update status to requested and publish status for each liveactions.
rescheduled = 0
for instance in liveactions:
try:
action_service.update_status(
instance,
action_constants.LIVEACTION_STATUS_REQUESTED,
publish=True)
rescheduled += 1
except:
LOG.exception(
'Unable to reschedule liveaction. <LiveAction.id=%s>',
instance.id)
LOG.info('Rescheduled %d out of %d delayed liveactions.',
len(liveactions), rescheduled)
def test_migrate_executions(self):
ActionExecutionDB._meta["allow_inheritance"] = True
LiveActionDB._meta["allow_inheritance"] = True
class ActionExecutionDB_OldFieldType(ActionExecutionDB):
result = stormbase.EscapedDynamicField(default={})
class LiveActionDB_OldFieldType(LiveActionDB):
result = stormbase.EscapedDynamicField(default={})
execution_dbs = ActionExecution.query(
__raw__={"result": {
"$not": {
"$type": "binData",
},
}})
self.assertEqual(len(execution_dbs), 0)
execution_dbs = ActionExecution.query(__raw__={
"result": {
"$type": "object",
},
})
self.assertEqual(len(execution_dbs), 0)
# 1. Insert data in old format
liveaction_1_db = LiveActionDB_OldFieldType()
liveaction_1_db.action = "foo.bar"
liveaction_1_db.status = action_constants.LIVEACTION_STATUS_FAILED
liveaction_1_db.result = MOCK_RESULT_1
liveaction_1_db.start_timestamp = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc)
liveaction_1_db = LiveAction.add_or_update(liveaction_1_db,
publish=False)
execution_1_db = ActionExecutionDB_OldFieldType()
execution_1_db.action = {"a": 1}
execution_1_db.runner = {"a": 1}
execution_1_db.liveaction = {"id": liveaction_1_db.id}
execution_1_db.status = action_constants.LIVEACTION_STATUS_FAILED
execution_1_db.result = MOCK_RESULT_1
execution_1_db.start_timestamp = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc)
execution_1_db = ActionExecution.add_or_update(execution_1_db,
publish=False)
# This execution is not in a final state yet so it should not be migrated
liveaction_2_db = LiveActionDB_OldFieldType()
liveaction_2_db.action = "foo.bar2"
liveaction_2_db.status = action_constants.LIVEACTION_STATUS_RUNNING
liveaction_2_db.result = MOCK_RESULT_2
liveaction_2_db.start_timestamp = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc)
liveaction_2_db = LiveAction.add_or_update(liveaction_2_db,
publish=False)
execution_2_db = ActionExecutionDB_OldFieldType()
execution_2_db.action = {"a": 2}
execution_2_db.runner = {"a": 2}
execution_2_db.liveaction = {"id": liveaction_2_db.id}
execution_2_db.status = action_constants.LIVEACTION_STATUS_RUNNING
execution_2_db.result = MOCK_RESULT_2
execution_2_db.start_timestamp = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc)
execution_2_db = ActionExecution.add_or_update(execution_2_db,
publish=False)
# This object is older than the default threshold so it should not be migrated
execution_3_db = ActionExecutionDB_OldFieldType()
execution_3_db.action = {"a": 2}
execution_3_db.runner = {"a": 2}
execution_3_db.liveaction = {"id": liveaction_2_db.id}
execution_3_db.status = action_constants.LIVEACTION_STATUS_SUCCEEDED
execution_3_db.result = MOCK_RESULT_1
execution_3_db.start_timestamp = datetime.datetime.utcfromtimestamp(
0).replace(tzinfo=datetime.timezone.utc)
execution_3_db = ActionExecution.add_or_update(execution_3_db,
publish=False)
# Verify data has been inserted in old format
execution_dbs = ActionExecution.query(__raw__={
"result": {
"$type": "object",
},
})
self.assertEqual(len(execution_dbs), 3)
execution_dbs = ActionExecution.query(
__raw__={"result": {
"$not": {
"$type": "binData",
},
}})
self.assertEqual(len(execution_dbs), 3)
execution_dbs = ActionExecution.query(__raw__={
"result": {
"$type": "binData",
},
})
self.assertEqual(len(execution_dbs), 0)
liveaction_dbs = LiveAction.query(__raw__={
"result": {
"$type": "object",
},
})
self.assertEqual(len(liveaction_dbs), 2)
liveaction_dbs = LiveAction.query(
__raw__={"result": {
"$not": {
"$type": "binData",
},
}})
self.assertEqual(len(liveaction_dbs), 2)
liveaction_dbs = LiveAction.query(__raw__={
"result": {
"$type": "binData",
},
})
self.assertEqual(len(liveaction_dbs), 0)
# Update inserted documents and remove special _cls field added by mongoengine. We need to
# do that here due to how mongoengine works with subclasses.
ActionExecution.query(__raw__={
"result": {
"$type": "object",
},
}).update(set___cls="ActionExecutionDB")
LiveAction.query(__raw__={
"result": {
"$type": "object",
},
}).update(set___cls="LiveActionDB")
# 2. Run migration
start_dt = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc) - datetime.timedelta(hours=2)
end_dt = datetime.datetime.utcnow().replace(
tzinfo=datetime.timezone.utc)
migration_module.migrate_executions(start_dt=start_dt, end_dt=end_dt)
# 3. Verify data has been migrated - only 1 item should have been migrated since it's in a
# completed state
execution_dbs = ActionExecution.query(__raw__={
"result": {
"$type": "object",
},
})
self.assertEqual(len(execution_dbs), 2)
execution_dbs = ActionExecution.query(__raw__={
"result": {
"$type": "binData",
},
})
self.assertEqual(len(execution_dbs), 1)
execution_db_1_retrieved = ActionExecution.get_by_id(execution_1_db.id)
self.assertEqual(execution_db_1_retrieved.result, MOCK_RESULT_1)
execution_db_2_retrieved = ActionExecution.get_by_id(execution_2_db.id)
self.assertEqual(execution_db_2_retrieved.result, MOCK_RESULT_2)
liveaction_db_1_retrieved = LiveAction.get_by_id(liveaction_1_db.id)
self.assertEqual(liveaction_db_1_retrieved.result, MOCK_RESULT_1)
liveaction_db_2_retrieved = LiveAction.get_by_id(liveaction_2_db.id)
self.assertEqual(liveaction_db_2_retrieved.result, MOCK_RESULT_2)
def purge_executions(logger, timestamp, action_ref=None, purge_incomplete=False):
"""
Purge action executions and corresponding live action, execution output objects.
:param timestamp: Exections older than this timestamp will be deleted.
:type timestamp: ``datetime.datetime
:param action_ref: Only delete executions for the provided actions.
:type action_ref: ``str``
:param purge_incomplete: True to also delete executions which are not in a done state.
:type purge_incomplete: ``bool``
"""
if not timestamp:
raise ValueError('Specify a valid timestamp to purge.')
logger.info('Purging executions older than timestamp: %s' %
timestamp.strftime('%Y-%m-%dT%H:%M:%S.%fZ'))
filters = {}
if purge_incomplete:
filters['start_timestamp__lt'] = timestamp
else:
filters['end_timestamp__lt'] = timestamp
filters['start_timestamp__lt'] = timestamp
filters['status'] = {'$in': DONE_STATES}
exec_filters = copy.copy(filters)
if action_ref:
exec_filters['action__ref'] = action_ref
liveaction_filters = copy.deepcopy(filters)
if action_ref:
liveaction_filters['action'] = action_ref
to_delete_execution_dbs = []
# 1. Delete ActionExecutionDB objects
try:
# Note: We call list() on the query set object because it's lazyily evaluated otherwise
to_delete_execution_dbs = list(ActionExecution.query(only_fields=['id'],
no_dereference=True,
**exec_filters))
deleted_count = ActionExecution.delete_by_query(**exec_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution instances: %s'
'Please contact support.' % (exec_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of execution models failed for query with filters: %s.',
exec_filters)
else:
logger.info('Deleted %s action execution objects' % (deleted_count))
# 2. Delete LiveActionDB objects
try:
deleted_count = LiveAction.delete_by_query(**liveaction_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete liveaction instances: %s'
'Please contact support.' % (liveaction_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of liveaction models failed for query with filters: %s.',
liveaction_filters)
else:
logger.info('Deleted %s liveaction objects' % (deleted_count))
# 3. Delete ActionExecutionOutputDB objects
to_delete_exection_ids = [str(execution_db.id) for execution_db in to_delete_execution_dbs]
output_dbs_filters = {}
output_dbs_filters['execution_id'] = {'$in': to_delete_exection_ids}
try:
deleted_count = ActionExecutionOutput.delete_by_query(**output_dbs_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution output instances: %s'
'Please contact support.' % (output_dbs_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of execution output models failed for query with filters: %s.',
output_dbs_filters)
else:
logger.info('Deleted %s execution output objects' % (deleted_count))
zombie_execution_instances = len(ActionExecution.query(only_fields=['id'],
no_dereference=True,
**exec_filters))
zombie_liveaction_instances = len(LiveAction.query(only_fields=['id'],
no_dereference=True,
**liveaction_filters))
if (zombie_execution_instances > 0) or (zombie_liveaction_instances > 0):
logger.error('Zombie execution instances left: %d.', zombie_execution_instances)
logger.error('Zombie liveaction instances left: %s.', zombie_liveaction_instances)
# Print stats
logger.info('All execution models older than timestamp %s were deleted.', timestamp)
def purge_executions(logger, timestamp, action_ref=None, purge_incomplete=False):
"""
:param timestamp: Exections older than this timestamp will be deleted.
:type timestamp: ``datetime.datetime
:param action_ref: Only delete executions for the provided actions.
:type action_ref: ``str``
:param purge_incomplete: True to also delete executions which are not in a done state.
:type purge_incomplete: ``bool``
"""
if not timestamp:
raise ValueError('Specify a valid timestamp to purge.')
logger.info('Purging executions older than timestamp: %s' %
timestamp.strftime('%Y-%m-%dT%H:%M:%S.%fZ'))
filters = {}
if purge_incomplete:
filters['start_timestamp__lt'] = timestamp
else:
filters['end_timestamp__lt'] = timestamp
filters['start_timestamp__lt'] = timestamp
filters['status'] = {'$in': DONE_STATES}
exec_filters = copy.copy(filters)
if action_ref:
exec_filters['action__ref'] = action_ref
liveaction_filters = copy.deepcopy(filters)
if action_ref:
liveaction_filters['action'] = action_ref
# TODO: Update this code to return statistics on deleted objects once we
# upgrade to newer version of MongoDB where delete_by_query actually returns
# some data
try:
ActionExecution.delete_by_query(**exec_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution instances: %s'
'Please contact support.' % (exec_filters, str(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of execution models failed for query with filters: %s.',
exec_filters)
try:
LiveAction.delete_by_query(**liveaction_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete liveaction instances: %s'
'Please contact support.' % (liveaction_filters, str(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of liveaction models failed for query with filters: %s.',
liveaction_filters)
zombie_execution_instances = len(ActionExecution.query(**exec_filters))
zombie_liveaction_instances = len(LiveAction.query(**liveaction_filters))
if (zombie_execution_instances > 0) or (zombie_liveaction_instances > 0):
logger.error('Zombie execution instances left: %d.', zombie_execution_instances)
logger.error('Zombie liveaction instances left: %s.', zombie_liveaction_instances)
# Print stats
logger.info('All execution models older than timestamp %s were deleted.', timestamp)
def purge_executions(logger,
timestamp,
action_ref=None,
purge_incomplete=False):
"""
:param timestamp: Exections older than this timestamp will be deleted.
:type timestamp: ``datetime.datetime
:param action_ref: Only delete executions for the provided actions.
:type action_ref: ``str``
:param purge_incomplete: True to also delete executions which are not in a done state.
:type purge_incomplete: ``bool``
"""
if not timestamp:
raise ValueError('Specify a valid timestamp to purge.')
logger.info('Purging executions older than timestamp: %s' %
timestamp.strftime('%Y-%m-%dT%H:%M:%S.%fZ'))
filters = {}
if purge_incomplete:
filters['start_timestamp__lt'] = timestamp
else:
filters['end_timestamp__lt'] = timestamp
filters['start_timestamp__lt'] = timestamp
filters['status'] = {'$in': DONE_STATES}
exec_filters = copy.copy(filters)
if action_ref:
exec_filters['action__ref'] = action_ref
liveaction_filters = copy.deepcopy(filters)
if action_ref:
liveaction_filters['action'] = action_ref
try:
deleted_count = ActionExecution.delete_by_query(**exec_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution instances: %s'
'Please contact support.' % (exec_filters, str(e)))
raise InvalidQueryError(msg)
except:
logger.exception(
'Deletion of execution models failed for query with filters: %s.',
exec_filters)
else:
logger.info('Deleted %s action execution objects' % (deleted_count))
try:
deleted_count = LiveAction.delete_by_query(**liveaction_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete liveaction instances: %s'
'Please contact support.' % (liveaction_filters, str(e)))
raise InvalidQueryError(msg)
except:
logger.exception(
'Deletion of liveaction models failed for query with filters: %s.',
liveaction_filters)
else:
logger.info('Deleted %s liveaction objects' % (deleted_count))
zombie_execution_instances = len(ActionExecution.query(**exec_filters))
zombie_liveaction_instances = len(LiveAction.query(**liveaction_filters))
if (zombie_execution_instances > 0) or (zombie_liveaction_instances > 0):
logger.error('Zombie execution instances left: %d.',
zombie_execution_instances)
logger.error('Zombie liveaction instances left: %s.',
zombie_liveaction_instances)
# Print stats
logger.info('All execution models older than timestamp %s were deleted.',
timestamp)
def purge_executions(logger, timestamp, action_ref=None, purge_incomplete=False):
"""
:param timestamp: Exections older than this timestamp will be deleted.
:type timestamp: ``datetime.datetime
:param action_ref: Only delete executions for the provided actions.
:type action_ref: ``str``
:param purge_incomplete: True to also delete executions which are not in a done state.
:type purge_incomplete: ``bool``
"""
if not timestamp:
raise ValueError("Specify a valid timestamp to purge.")
logger.info("Purging executions older than timestamp: %s" % timestamp.strftime("%Y-%m-%dT%H:%M:%S.%fZ"))
filters = {}
if purge_incomplete:
filters["start_timestamp__lt"] = timestamp
else:
filters["end_timestamp__lt"] = timestamp
filters["start_timestamp__lt"] = timestamp
filters["status"] = {"$in": DONE_STATES}
exec_filters = copy.copy(filters)
if action_ref:
exec_filters["action__ref"] = action_ref
liveaction_filters = copy.deepcopy(filters)
if action_ref:
liveaction_filters["action"] = action_ref
try:
deleted_count = ActionExecution.delete_by_query(**exec_filters)
except InvalidQueryError as e:
msg = "Bad query (%s) used to delete execution instances: %s" "Please contact support." % (exec_filters, str(e))
raise InvalidQueryError(msg)
except:
logger.exception("Deletion of execution models failed for query with filters: %s.", exec_filters)
else:
logger.info("Deleted %s action execution objects" % (deleted_count))
try:
deleted_count = LiveAction.delete_by_query(**liveaction_filters)
except InvalidQueryError as e:
msg = "Bad query (%s) used to delete liveaction instances: %s" "Please contact support." % (
liveaction_filters,
str(e),
)
raise InvalidQueryError(msg)
except:
logger.exception("Deletion of liveaction models failed for query with filters: %s.", liveaction_filters)
else:
logger.info("Deleted %s liveaction objects" % (deleted_count))
zombie_execution_instances = len(ActionExecution.query(**exec_filters))
zombie_liveaction_instances = len(LiveAction.query(**liveaction_filters))
if (zombie_execution_instances > 0) or (zombie_liveaction_instances > 0):
logger.error("Zombie execution instances left: %d.", zombie_execution_instances)
logger.error("Zombie liveaction instances left: %s.", zombie_liveaction_instances)
# Print stats
logger.info("All execution models older than timestamp %s were deleted.", timestamp)
def purge_executions(logger, timestamp, action_ref=None, purge_incomplete=False):
"""
Purge action executions and corresponding live action, execution output objects.
:param timestamp: Exections older than this timestamp will be deleted.
:type timestamp: ``datetime.datetime
:param action_ref: Only delete executions for the provided actions.
:type action_ref: ``str``
:param purge_incomplete: True to also delete executions which are not in a done state.
:type purge_incomplete: ``bool``
"""
if not timestamp:
raise ValueError('Specify a valid timestamp to purge.')
logger.info('Purging executions older than timestamp: %s' %
timestamp.strftime('%Y-%m-%dT%H:%M:%S.%fZ'))
filters = {}
if purge_incomplete:
filters['start_timestamp__lt'] = timestamp
else:
filters['end_timestamp__lt'] = timestamp
filters['start_timestamp__lt'] = timestamp
filters['status'] = {'$in': DONE_STATES}
exec_filters = copy.copy(filters)
if action_ref:
exec_filters['action__ref'] = action_ref
liveaction_filters = copy.deepcopy(filters)
if action_ref:
liveaction_filters['action'] = action_ref
to_delete_execution_dbs = []
# 1. Delete ActionExecutionDB objects
try:
# Note: We call list() on the query set object because it's lazyily evaluated otherwise
to_delete_execution_dbs = list(ActionExecution.query(only_fields=['id'],
no_dereference=True,
**exec_filters))
deleted_count = ActionExecution.delete_by_query(**exec_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution instances: %s'
'Please contact support.' % (exec_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of execution models failed for query with filters: %s.',
exec_filters)
else:
logger.info('Deleted %s action execution objects' % (deleted_count))
# 2. Delete LiveActionDB objects
try:
deleted_count = LiveAction.delete_by_query(**liveaction_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete liveaction instances: %s'
'Please contact support.' % (liveaction_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of liveaction models failed for query with filters: %s.',
liveaction_filters)
else:
logger.info('Deleted %s liveaction objects' % (deleted_count))
# 3. Delete ActionExecutionOutputDB objects
to_delete_exection_ids = [str(execution_db.id) for execution_db in to_delete_execution_dbs]
output_dbs_filters = {}
output_dbs_filters['execution_id'] = {'$in': to_delete_exection_ids}
try:
deleted_count = ActionExecutionOutput.delete_by_query(**output_dbs_filters)
except InvalidQueryError as e:
msg = ('Bad query (%s) used to delete execution output instances: %s'
'Please contact support.' % (output_dbs_filters, six.text_type(e)))
raise InvalidQueryError(msg)
except:
logger.exception('Deletion of execution output models failed for query with filters: %s.',
output_dbs_filters)
else:
logger.info('Deleted %s execution output objects' % (deleted_count))
zombie_execution_instances = len(ActionExecution.query(only_fields=['id'],
no_dereference=True,
**exec_filters))
zombie_liveaction_instances = len(LiveAction.query(only_fields=['id'],
no_dereference=True,
**liveaction_filters))
if (zombie_execution_instances > 0) or (zombie_liveaction_instances > 0):
logger.error('Zombie execution instances left: %d.', zombie_execution_instances)
logger.error('Zombie liveaction instances left: %s.', zombie_liveaction_instances)
# Print stats
logger.info('All execution models older than timestamp %s were deleted.', timestamp)
