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)